[asterisk-users] users can not hear the audio playback sometimes

Kumar Shantanu shantanu at techblue.co.uk
Wed Sep 25 03:54:49 CDT 2013


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


More information about the asterisk-users mailing list