Kumar Shantanu
2013-Sep-25 08:54 UTC
[asterisk-users] users can not hear the audio playback sometimes
Hello everyone, I am facing a strange problem on my asterisk box (using isdn lines with pri card installed on it). Normal incoming/outgoing calls are working perfectly fine. When a user dial a wrong/out-of-service number they don't hear back any such message like "The number is wrong or user is switched off" in some cases, and it's just a silence for the user. Now while troubleshooting we set recording to ON for the extension so we can see what's there in the recording file(.gsm). When I am listing to the recording files it contains everything which users should be listening actually, like "the number you are dialling is not correct." So the question is why user is not able to listen to this while asterisk itself is getting the message perfectly fine from the provider ? Am I missing something my dahdhi.conf ? Or anybody having any idea about this can please put me through the right direction. I am attaching small log snippet from asterisk logs. Thanks Shantanu -------------- next part -------------- [2013-09-25 13:57:33] VERBOSE[1380] netsock2.c: == Using SIP RTP TOS bits 184 [2013-09-25 13:57:33] VERBOSE[1380] netsock2.c: == Using SIP RTP CoS mark 5 [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [09999999999 at from-internal:1] Macro("SIP/1002-00000292", "user-callerid,LIMIT,") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:1] Set("SIP/1002-00000292", "AMPUSER=1002") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:2] GotoIf("SIP/1002-00000292", "0?report") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:3] ExecIf("SIP/1002-00000292", "1?Set(REALCALLERIDNUM=1002)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:4] Set("SIP/1002-00000292", "AMPUSER=1002") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:5] Set("SIP/1002-00000292", "AMPUSERCIDNAME=Shantanu") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:6] GotoIf("SIP/1002-00000292", "0?report") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:7] Set("SIP/1002-00000292", "AMPUSERCID=1002") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:8] Set("SIP/1002-00000292", "CALLERID(all)="Shantanu" <1002>") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:9] GotoIf("SIP/1002-00000292", "0?limit") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:10] ExecIf("SIP/1002-00000292", "1?Set(GROUP(concurrency_limit)=1002)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:11] GotoIf("SIP/1002-00000292", "1?continue") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (macro-user-callerid,s,24) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:24] Set("SIP/1002-00000292", "CALLERID(number)=1002") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:25] Set("SIP/1002-00000292", "CALLERID(name)=Shantanu") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-user-callerid:26] Set("SIP/1002-00000292", "CHANNEL(language)=en") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [09999999999 at from-internal:2] Set("SIP/1002-00000292", "MOHCLASS=default") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [09999999999 at from-internal:3] Set("SIP/1002-00000292", "_NODEST=") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [09999999999 at from-internal:4] Gosub("SIP/1002-00000292", "sub-record-check,s,1(out,09999999999,)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:1] GotoIf("SIP/1002-00000292", "1?check") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (sub-record-check,s,6) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:6] Set("SIP/1002-00000292", "__MON_FMT=gsm") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:7] GotoIf("SIP/1002-00000292", "1?next") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (sub-record-check,s,10) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:10] ExecIf("SIP/1002-00000292", "0?Return()") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:11] GotoIf("SIP/1002-00000292", "0?out,1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:12] Set("SIP/1002-00000292", "__REC_STATUS=INITIALIZED") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:13] ExecIf("SIP/1002-00000292", "0?Set(__REC_POLICY_MODE=)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:14] Set("SIP/1002-00000292", "NOW=1380097653") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:15] Set("SIP/1002-00000292", "__DAY=25") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:16] Set("SIP/1002-00000292", "__MONTH=09") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:17] Set("SIP/1002-00000292", "__YEAR=2013") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:18] Set("SIP/1002-00000292", "__TIMESTR=20130925-135733") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:19] Set("SIP/1002-00000292", "__FROMEXTEN=1002") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:20] Set("SIP/1002-00000292", "__CALLFILENAME=out-09999999999-1002-20130925-135733-1380097653.1271") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-record-check:21] Goto("SIP/1002-00000292", "out,1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (sub-record-check,out,1) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [out at sub-record-check:1] ExecIf("SIP/1002-00000292", "1?Set(__REC_POLICY_MODE=always)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [out at sub-record-check:2] GosubIf("SIP/1002-00000292", "1?record,1(exten,09999999999,1002)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [record at sub-record-check:1] Set("SIP/1002-00000292", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [record at sub-record-check:2] MixMonitor("SIP/1002-00000292", "2013/09/25/out-09999999999-1002-20130925-135733-1380097653.1271.gsm,,") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [record at sub-record-check:3] Set("SIP/1002-00000292", "__REC_STATUS=RECORDING") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [record at sub-record-check:4] Set("SIP/1002-00000292", "CDR(recordingfile)=out-09999999999-1002-20130925-135733-1380097653.1271.gsm") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [record at sub-record-check:5] Return("SIP/1002-00000292", "") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [out at sub-record-check:3] Return("SIP/1002-00000292", "") in new stack [2013-09-25 13:57:33] VERBOSE[9746] app_mixmonitor.c: == Begin MixMonitor Recording SIP/1002-00000292 [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [09999999999 at from-internal:5] Macro("SIP/1002-00000292", "dialout-trunk,1,9999999999,") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:1] Set("SIP/1002-00000292", "DIAL_TRUNK=1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:2] GosubIf("SIP/1002-00000292", "0?sub-pincheck,s,1()") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:3] GotoIf("SIP/1002-00000292", "0?disabletrunk,1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:4] Set("SIP/1002-00000292", "DIAL_NUMBER=9999999999") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:5] Set("SIP/1002-00000292", "DIAL_TRUNK_OPTIONS=trwW") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:6] Set("SIP/1002-00000292", "OUTBOUND_GROUP=OUT_1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:7] GotoIf("SIP/1002-00000292", "0?nomax") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:8] GotoIf("SIP/1002-00000292", "0?chanfull") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:9] GotoIf("SIP/1002-00000292", "0?skipoutcid") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:10] Set("SIP/1002-00000292", "DIAL_TRUNK_OPTIONS=wW") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:11] Macro("SIP/1002-00000292", "outbound-callerid,1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:1] ExecIf("SIP/1002-00000292", "0?Set(CALLERPRES()=)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:2] ExecIf("SIP/1002-00000292", "0?Set(REALCALLERIDNUM=1002)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:3] GotoIf("SIP/1002-00000292", "1?normcid") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:6] Set("SIP/1002-00000292", "USEROUTCID=") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:7] Set("SIP/1002-00000292", "EMERGENCYCID=") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:8] Set("SIP/1002-00000292", "TRUNKOUTCID=1244548383") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:9] GotoIf("SIP/1002-00000292", "1?trunkcid") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:12] ExecIf("SIP/1002-00000292", "1?Set(CALLERID(all)=1244548383)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:13] ExecIf("SIP/1002-00000292", "0?Set(CALLERID(all)=)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:14] ExecIf("SIP/1002-00000292", "0?Set(CALLERID(all)=)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-outbound-callerid:15] ExecIf("SIP/1002-00000292", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:12] GosubIf("SIP/1002-00000292", "1?sub-flp-1,s,1()") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-flp-1:1] ExecIf("SIP/1002-00000292", "0?Return()") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at sub-flp-1:2] Return("SIP/1002-00000292", "") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:13] Set("SIP/1002-00000292", "OUTNUM=9999999999") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:14] Set("SIP/1002-00000292", "custom=DAHDI/g1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:15] ExecIf("SIP/1002-00000292", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)wW)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:16] ExecIf("SIP/1002-00000292", "0?Set(DIAL_TRUNK_OPTIONS=wWM(confirm))") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:17] Macro("SIP/1002-00000292", "dialout-trunk-predial-hook,") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk-predial-hook:1] MacroExit("SIP/1002-00000292", "") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:18] GotoIf("SIP/1002-00000292", "0?bypass,1") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:19] ExecIf("SIP/1002-00000292", "1?Set(CONNECTEDLINE(num,i)=9999999999)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:20] ExecIf("SIP/1002-00000292", "1?Set(CONNECTEDLINE(name,i)=CID:1244548383)") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:21] GotoIf("SIP/1002-00000292", "0?customtrunk") in new stack [2013-09-25 13:57:33] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:22] Dial("SIP/1002-00000292", "DAHDI/g1/9999999999,300,wW") in new stack [2013-09-25 13:57:33] DEBUG[9745] sig_pri.c: sig_pri_request 1 [2013-09-25 13:57:33] DEBUG[9745] sig_pri.c: CALLER NAME: NUM: 1244548383 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 -- Making new call for cref 33092 [2013-09-25 13:57:33] VERBOSE[9745] sig_pri.c: -- Requested transfer capability: 0x00 - SPEECH [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=43 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent from originator) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Message Type: SETUP (5) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=38, window is open V(A)=38 K=7 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=43 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent from originator) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Message Type: SETUP (5) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [04 03 80 90 a3] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Bearer Capability (len= 5) [ Ext: 1 Coding-Std: 0 Info transfer capability: Speech (0) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > User information layer 1: A-Law (35) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [18 03 a1 83 81] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > ChanSel: As indicated in following octets [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Ext: 1 Channel: 1 Type: CPE] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [6c 0c 21 80 31 32 34 34 35 34 38 33 38 33] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Presentation: Presentation permitted, user number not screened (0) '1244548383' ] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [70 0b 80 39 39 39 39 39 39 39 39 39 39] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Called Number (len=13) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) '9999999999' ] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [a1] [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Sending Complete (len= 1) [2013-09-25 13:57:33] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 q931.c:6036 q931_setup: Call 33092 enters state 1 (Call Initiated). Hold state: Idle [2013-09-25 13:57:33] VERBOSE[9745] app_dial.c: -- Called DAHDI/g1/9999999999 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=10 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent to originator) [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Message Type: CALL PROCEEDING (2) [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < [18 03 a9 83 81] [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < ChanSel: As indicated in following octets [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Ext: 1 Coding: 0 Number Specified Channel Type: 3 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Ext: 1 Channel: 1 Type: CPE] [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fdaa81eb890 on link 0x2713620 TEI/SAPI 0/0 [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 -- Processing IE 24 (cs0, Channel Identification) [2013-09-25 13:57:33] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 q931.c:8454 post_handle_q931_message: Call 33092 enters state 3 (Outgoing Call Proceeding). Hold state: Idle [2013-09-25 13:57:33] VERBOSE[1381] sig_pri.c: Span 1: Processing event PRI_EVENT_PROCEEDING [2013-09-25 13:57:33] VERBOSE[9745] app_dial.c: -- DAHDI/i1/9999999999-258 is proceeding passing it to SIP/1002-00000292 [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=13 [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent to originator) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Message Type: DISCONNECT (69) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < [08 02 80 90] [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: User (0) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < [1e 02 82 88] [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fdaa81eb890 on link 0x2713620 TEI/SAPI 0/0 [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 -- Processing IE 8 (cs0, Cause) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 -- Processing IE 30 (cs0, Progress Indicator) [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 -- Found active call: 0x7fdaa81eb890 cref:33092 [2013-09-25 13:57:53] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 q931.c:8707 post_handle_q931_message: Call 33092 enters state 12 (Disconnect Indication). Hold state: Idle [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=9 [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent to originator) [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Message Type: RELEASE (77) [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < [08 02 80 90] [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: User (0) [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 < Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fdaa81eb890 on link 0x2713620 TEI/SAPI 0/0 [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 -- Processing IE 8 (cs0, Cause) [2013-09-25 13:58:23] VERBOSE[1381] chan_dahdi.c: PRI Span: 1 q931.c:8620 post_handle_q931_message: Call 33092 enters state 0 (Null). Hold state: Idle [2013-09-25 13:58:23] VERBOSE[1381] sig_pri.c: Span 1: Processing event PRI_EVENT_HANGUP [2013-09-25 13:58:23] VERBOSE[1381] sig_pri.c: -- Span 1: Channel 0/1 got hangup, cause 16 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 q931.c:6837 q931_hangup: Hangup other cref:33092 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 q931.c:6594 __q931_hangup: ourstate Null, peerstate Release Request, hold-state Idle [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent from originator) [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE COMPLETE (90) [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=39, window is open V(A)=39 K=7 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 324/0x144) (Sent from originator) [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE COMPLETE (90) [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > [08 02 81 90] [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 q931.c:6837 q931_hangup: Hangup other cref:33092 [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 q931.c:6594 __q931_hangup: ourstate Null, peerstate Null, hold-state Idle [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: PRI Span: 1 Destroying call 0x7fdaa81eb890, ourstate Null, peerstate Null, hold-state Idle [2013-09-25 13:58:23] VERBOSE[9745] chan_dahdi.c: -- Hungup 'DAHDI/i1/9999999999-258' [2013-09-25 13:58:23] VERBOSE[9745] app_dial.c: -- No one is available to answer at this time (1:0/0/0) [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:23] NoOp("SIP/1002-00000292", "Dial failed for some reason with DIALSTATUS = NOANSWER and HANGUPCAUSE = 16") in new stack [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Executing [s at macro-dialout-trunk:24] Goto("SIP/1002-00000292", "s-NOANSWER,1") in new stack [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Goto (macro-dialout-trunk,s-NOANSWER,1) [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Executing [s-NOANSWER at macro-dialout-trunk:1] NoOp("SIP/1002-00000292", "Dial failed due to trunk reporting NOANSWER - giving up") in new stack [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Executing [s-NOANSWER at macro-dialout-trunk:2] Progress("SIP/1002-00000292", "") in new stack [2013-09-25 13:58:23] VERBOSE[9745] pbx.c: -- Executing [s-NOANSWER at macro-dialout-trunk:3] Playback("SIP/1002-00000292", "number-not-answering,noanswer") in new stack [2013-09-25 13:58:23] VERBOSE[9745] file.c: -- <SIP/1002-00000292> Playing 'number-not-answering.slin' (language 'en') [2013-09-25 13:58:24] VERBOSE[9745] pbx.c: -- Executing [s-NOANSWER at macro-dialout-trunk:4] Congestion("SIP/1002-00000292", "20") in new stack [2013-09-25 13:58:24] VERBOSE[9745] app_macro.c: == Spawn extension (macro-dialout-trunk, s-NOANSWER, 4) exited non-zero on 'SIP/1002-00000292' in macro 'dialout-trunk' [2013-09-25 13:58:24] VERBOSE[9745] pbx.c: == Spawn extension (from-internal, 09999999999, 5) exited non-zero on 'SIP/1002-00000292' [2013-09-25 13:58:24] VERBOSE[9745] pbx.c: -- Executing [h at from-internal:1] Hangup("SIP/1002-00000292", "") in new stack [2013-09-25 13:58:24] VERBOSE[9745] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/1002-00000292' [2013-09-25 13:58:24] VERBOSE[9746] app_mixmonitor.c: == MixMonitor close filestream [2013-09-25 13:58:24] VERBOSE[9746] app_mixmonitor.c: == End MixMonitor Recording SIP/1002-00000292 [2013-09-25 13:58:31] WARNING[1380] chan_sip.c: Retransmission timeout reached on transmission 1aghl9fein for seqno 665 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions Packet timed out after 6400ms with no response [2013-09-25 14:04:24] VERBOSE[32430] asterisk.c: -- Remote UNIX connection disconnected [2013-09-25 14:04:29] VERBOSE[1355] asterisk.c: -- Remote UNIX connection [2013-09-25 14:04:55] VERBOSE[1380] netsock2.c: == Using SIP RTP TOS bits 184 [2013-09-25 14:04:55] VERBOSE[1380] netsock2.c: == Using SIP RTP CoS mark 5
It would be easier to comment if you would copy the relevant part of the dialplan. The only dial cmd I see is Dial("SIP/1002-00000292", "DAHDI/g1/9999999999,300,wW") At least where I live, 9999999999 can be part of a valid telephone number. You could increase the verbosity and see what Dial() is actually doing. jg
Gareth Blades
2013-Sep-25 09:55 UTC
[asterisk-users] users can not hear the audio playback sometimes
On 25/09/13 09:54, Kumar Shantanu wrote:> I am facing a strange problem on my asterisk box (using isdn lines > with pri card installed on it). Normal incoming/outgoing calls are > working perfectly fine. > > When a user dial a wrong/out-of-service number they don't hear back > any such message like "The number is wrong or user is switched off" in > some cases, and it's just a silence for the user. > > Now while troubleshooting we set recording to ON for the extension so > we can see what's there in the recording file(.gsm). When I am listing > to the recording files it contains everything which users should be > listening actually, like "the number you are dialling is not correct." > > So the question is why user is not able to listen to this while > asterisk itself is getting the message perfectly fine from the > provider ? Am I missing something my dahdhi.conf ? > > Or anybody having any idea about this can please put me through the > right direction.Try calling Progress() just before the dial command. Without this Asterisk wont send the SIP/183 Session Progress and send the inband audio until the call is answered.