[2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=40 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent from originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Message Type: SETUP (5) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [a1] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Sending Complete (len= 1) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [04 03 90 90 a3] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Bearer Capability (len= 5) [ Ext: 1 Coding-Std: 0 Info transfer capability: 3.1kHz audio (16) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < User information layer 1: A-Law (35) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [18 03 a1 83 81] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < ChanSel: As indicated in following octets [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Ext: 1 Coding: 0 Number Specified Channel Type: 3 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Ext: 1 Channel: 1 Type: CPE] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [1e 02 84 83] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the remote user (4) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [6c 0c 21 83 31 35 34 32 38 33 33 33 30 36] [2015-10-25 12:50:09] VERBOSE[4831] 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) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Presentation: Presentation allowed of network provided number (3) '7xxxxxxxxxx' ] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < [70 04 81 39 35 34] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Called Number (len= 6) [ Ext: 1 TON: Unknown Number Type (0) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '954' ] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Making new call for cref 118 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 Received message for call 0x7f43f4005660 on link 0x164cb10 TEI/SAPI 0/0 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing Q.931 Call Setup [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 161 (cs0, Sending Complete) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 4 (cs0, Bearer Capability) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 24 (cs0, Channel Identification) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 30 (cs0, Progress Indicator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 108 (cs0, Calling Party Number) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 -- Processing IE 112 (cs0, Called Party Number) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:8281 post_handle_q931_message: Call 118 enters state 6 (Call Present). Hold state: Idle [2015-10-25 12:50:09] VERBOSE[4831] sig_pri.c: Span 1: Processing event PRI_EVENT_RING(5) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:5477 q931_call_proceeding: Call 118 enters state 9 (Incoming Call Proceeding). Hold state: Idle [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=10 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Message Type: CALL PROCEEDING (2) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=6, window is open V(A)=6 K=7 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=10 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Message Type: CALL PROCEEDING (2) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > [18 03 a9 83 81] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > ChanSel: As indicated in following octets [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Ext: 1 Channel: 1 Type: CPE] [2015-10-25 12:50:09] VERBOSE[4831][C-00000d12] sig_pri.c: -- Accepting call from '07xxxxxxxxx' to '954' on channel 0/1, span 1 [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-zaptel:1] Set("DAHDI/i1/07xxxxxxxxx-83", "DID=954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-zaptel:2] Goto("DAHDI/i1/07xxxxxxxxx-83", "s,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (from-zaptel,s,1) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:1] NoOp("DAHDI/i1/07xxxxxxxxx-83", "Entering from-dahdi with DID == 954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:2] Ringing("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 q931.c:5509 q931_alerting: Call 118 enters state 7 (Call Received). Hold state: Idle [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Message Type: ALERTING (1) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=7, window is open V(A)=6 K=7 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Message Type: ALERTING (1) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > [1e 02 81 88] [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:3] Set("DAHDI/i1/07xxxxxxxxx-83", "DID=954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:4] NoOp("DAHDI/i1/07xxxxxxxxx-83", "DID is now 954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:5] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?dahdiok:checkzap") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (from-zaptel,s,9) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:9] NoOp("DAHDI/i1/07xxxxxxxxx-83", "Is a DAHDi Channel") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:10] Set("DAHDI/i1/07xxxxxxxxx-83", "CHAN=i1/07xxxxxxxxx-83") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:11] Set("DAHDI/i1/07xxxxxxxxx-83", "CHAN=i1/07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:12] Macro("DAHDI/i1/07xxxxxxxxx-83", "from-dahdi-i1/07xxxxxxxxx,954,1") in new stack [2015-10-25 12:50:09] WARNING[19249][C-00000d12] app_macro.c: No such context 'macro-from-dahdi-i1/07xxxxxxxxx' for macro 'from-dahdi-i1/07xxxxxxxxx'. Was called by s@from-zaptel [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:13] NoOp("DAHDI/i1/07xxxxxxxxx-83", "Returned from Macro from-dahdi-i1/07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@from-zaptel:14] Goto("DAHDI/i1/07xxxxxxxxx-83", "from-pstn,954,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (from-pstn,954,1) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:1] Set("DAHDI/i1/07xxxxxxxxx-83", "__FROM_DID=954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:2] Gosub("DAHDI/i1/07xxxxxxxxx-83", "app-blacklist-check,s,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?blacklisted") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@app-blacklist-check:2] Set("DAHDI/i1/07xxxxxxxxx-83", "CALLED_BLACKLIST=1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@app-blacklist-check:3] Return("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:3] Set("DAHDI/i1/07xxxxxxxxx-83", "CDR(did)=954") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:4] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "1 ?Set(CALLERID(name)=07xxxxxxxxx)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:5] Set("DAHDI/i1/07xxxxxxxxx-83", "CHANNEL(musicclass)=default") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:6] Set("DAHDI/i1/07xxxxxxxxx-83", "__MOHCLASS=default") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:7] Set("DAHDI/i1/07xxxxxxxxx-83", "__CALLINGPRES_SV=allowed") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:8] Set("DAHDI/i1/07xxxxxxxxx-83", "CALLERPRES()=allowed_not_screened") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [954@from-pstn:9] Goto("DAHDI/i1/07xxxxxxxxx-83", "from-did-direct,5024,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (from-did-direct,5024,1) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [5024@from-did-direct:1] Set("DAHDI/i1/07xxxxxxxxx-83", "__RINGTIMER=15") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [5024@from-did-direct:2] Macro("DAHDI/i1/07xxxxxxxxx-83", "exten-vm,novm,5024,0,0,0") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("DAHDI/i1/07xxxxxxxxx-83", "user-callerid,") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:1] Set("DAHDI/i1/07xxxxxxxxx-83", "TOUCH_MONITOR=1445777409.6658") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:2] Set("DAHDI/i1/07xxxxxxxxx-83", "AMPUSER=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?report") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "1?Set(REALCALLERIDNUM=07xxxxxxxxx)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:5] Set("DAHDI/i1/07xxxxxxxxx-83", "AMPUSER=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?limit") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:7] Set("DAHDI/i1/07xxxxxxxxx-83", "AMPUSERCIDNAME=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?report") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-user-callerid,s,16) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?continue") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:17] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:18] Set("DAHDI/i1/07xxxxxxxxx-83", "__TTL=64") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:19] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?continue") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-user-callerid,s,30) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:30] Set("DAHDI/i1/07xxxxxxxxx-83", "CALLERID(number)=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:31] Set("DAHDI/i1/07xxxxxxxxx-83", "CALLERID(name)=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:32] Set("DAHDI/i1/07xxxxxxxxx-83", "CDR(cnum)=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:33] Set("DAHDI/i1/07xxxxxxxxx-83", "CDR(cnam)=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-user-callerid:34] Set("DAHDI/i1/07xxxxxxxxx-83", "CHANNEL(language)=en") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:2] Set("DAHDI/i1/07xxxxxxxxx-83", "RingGroupMethod=none") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:3] Set("DAHDI/i1/07xxxxxxxxx-83", "__EXTTOCALL=5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:4] Set("DAHDI/i1/07xxxxxxxxx-83", "__PICKUPMARK=5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:5] Set("DAHDI/i1/07xxxxxxxxx-83", "RT=") in new stack [2015-10-25 12:50:09] WARNING[19249][C-00000d12] chan_sip.c: This function can only be used on SIP channels. [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:6] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack [2015-10-25 12:50:09] WARNING[19249][C-00000d12] chan_sip.c: This function can only be used on SIP channels. [2015-10-25 12:50:09] WARNING[19249][C-00000d12] chan_sip.c: This function can only be used on SIP channels. [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:7] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?MacroExit()") in new stack [2015-10-25 12:50:09] WARNING[19249][C-00000d12] chan_sip.c: This function can only be used on SIP channels. [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:8] Gosub("DAHDI/i1/07xxxxxxxxx-83", "sub-record-check,s,1(exten,5024,)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:1] Set("DAHDI/i1/07xxxxxxxxx-83", "REC_POLICY_MODE_SAVE=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:2] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?check") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (sub-record-check,s,7) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:7] Set("DAHDI/i1/07xxxxxxxxx-83", "__MON_FMT=wav") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:8] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?next") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (sub-record-check,s,11) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Return()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:12] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Set(__REC_POLICY_MODE=)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:13] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?exten,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:14] Set("DAHDI/i1/07xxxxxxxxx-83", "__REC_STATUS=INITIALIZED") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:15] Set("DAHDI/i1/07xxxxxxxxx-83", "NOW=1445777409") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:16] Set("DAHDI/i1/07xxxxxxxxx-83", "__DAY=25") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:17] Set("DAHDI/i1/07xxxxxxxxx-83", "__MONTH=10") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:18] Set("DAHDI/i1/07xxxxxxxxx-83", "__YEAR=2015") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:19] Set("DAHDI/i1/07xxxxxxxxx-83", "__TIMESTR=20151025-125009") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:20] Set("DAHDI/i1/07xxxxxxxxx-83", "__FROMEXTEN=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:21] Set("DAHDI/i1/07xxxxxxxxx-83", "__CALLFILENAME=exten-5024-07xxxxxxxxx-20151025-125009-1445777409.6658") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@sub-record-check:22] Goto("DAHDI/i1/07xxxxxxxxx-83", "exten,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (sub-record-check,exten,1) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:1] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?callee") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:2] Set("DAHDI/i1/07xxxxxxxxx-83", "__REC_POLICY_MODE=dontcare") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:3] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?caller") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (sub-record-check,exten,10) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:10] Set("DAHDI/i1/07xxxxxxxxx-83", "__REC_POLICY_MODE=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:11] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?record,1(exten,5024,07xxxxxxxxx)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [exten@sub-record-check:12] Return("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:9] Macro("DAHDI/i1/07xxxxxxxxx-83", "dial-one,,trw,5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:1] Set("DAHDI/i1/07xxxxxxxxx-83", "DEXTEN=5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:2] Set("DAHDI/i1/07xxxxxxxxx-83", "DIALSTATUS_CW=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:3] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?screen,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:4] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?cf,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:5] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?skip1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,8) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:8] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?nodial") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:9] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?continue") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:10] Set("DAHDI/i1/07xxxxxxxxx-83", "EXTHASCW=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?next1:cwinusebusy") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,12) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:12] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?docfu:skip3") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,16) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:16] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?next2:continue") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,17) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:17] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?continue") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,25) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?nodial") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "1?dstring,1():dlocal,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("DAHDI/i1/07xxxxxxxxx-83", "DSTRING=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("DAHDI/i1/07xxxxxxxxx-83", "DEVICES=5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Return()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Set(DEVICES=024)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("DAHDI/i1/07xxxxxxxxx-83", "LOOPCNT=1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("DAHDI/i1/07xxxxxxxxx-83", "ITER=1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("DAHDI/i1/07xxxxxxxxx-83", "THISDIAL=SIP/5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "1?zap2dahdi,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Return()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("DAHDI/i1/07xxxxxxxxx-83", "NEWDIAL=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("DAHDI/i1/07xxxxxxxxx-83", "LOOPCNT2=1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("DAHDI/i1/07xxxxxxxxx-83", "ITER2=1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("DAHDI/i1/07xxxxxxxxx-83", "THISPART2=SIP/5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Set(THISPART2=DAHDI/5024)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("DAHDI/i1/07xxxxxxxxx-83", "NEWDIAL=SIP/5024&") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("DAHDI/i1/07xxxxxxxxx-83", "ITER2=2") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?begin2") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("DAHDI/i1/07xxxxxxxxx-83", "THISDIAL=SIP/5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:9] Set("DAHDI/i1/07xxxxxxxxx-83", "DSTRING=SIP/5024&") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:10] Set("DAHDI/i1/07xxxxxxxxx-83", "ITER=2") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:11] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?begin") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:12] Set("DAHDI/i1/07xxxxxxxxx-83", "DSTRING=SIP/5024") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [dstring@macro-dial-one:13] Return("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?nodial") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?skiptrace") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "1?ctset,1():ctclear,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("DAHDI/i1/07xxxxxxxxx-83", "DB(CALLTRACE/5024)=07xxxxxxxxx") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:30] Set("DAHDI/i1/07xxxxxxxxx-83", "D_OPTIONS=trw") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?SIPAddHeader(Alert-Info: )") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?SIPAddHeader()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "1?Set(CHANNEL(musicclass)=default)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?qwait,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:35] Set("DAHDI/i1/07xxxxxxxxx-83", "__CWIGNORE=") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:36] Set("DAHDI/i1/07xxxxxxxxx-83", "__KEEPCID=TRUE") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?usegoto,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?godial") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-dial-one,s,43) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:43] Dial("DAHDI/i1/07xxxxxxxxx-83", "SIP/5024,,trw") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] netsock2.c: == Using SIP RTP TOS bits 184 [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] netsock2.c: == Using SIP RTP CoS mark 5 [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] app_dial.c: -- Called SIP/5024 [2015-10-25 12:50:09] VERBOSE[4848][C-00000d12] chan_sip.c: -- Got SIP response 486 "Busy here" back from 10.10.0.18:5060 [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] app_dial.c: -- SIP/5024-000000b5 is busy [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:44] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?MacroExit()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:45] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Set(DIALSTATUS=)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:46] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?s-BUSY,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-dial-one:47] MacroExit("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:10] Set("DAHDI/i1/07xxxxxxxxx-83", "SV_DIALSTATUS=BUSY") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:11] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?docfu,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:12] GosubIf("DAHDI/i1/07xxxxxxxxx-83", "0?docfb,1()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:13] Set("DAHDI/i1/07xxxxxxxxx-83", "DIALSTATUS=BUSY") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:14] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?MacroExit()") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-exten-vm:15] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?s-BUSY,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-exten-vm,s-BUSY,1) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s-BUSY@macro-exten-vm:1] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "0?exit,1") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s-BUSY@macro-exten-vm:2] PlayTones("DAHDI/i1/07xxxxxxxxx-83", "busy") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s-BUSY@macro-exten-vm:3] Busy("DAHDI/i1/07xxxxxxxxx-83", "20") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] app_macro.c: == Spawn extension (macro-exten-vm, s-BUSY, 3) exited non-zero on 'DAHDI/i1/07xxxxxxxxx-83' in macro 'exten-vm' [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: == Spawn extension (from-did-direct, 5024, 2) exited non-zero on 'DAHDI/i1/07xxxxxxxxx-83' [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [h@from-did-direct:1] Macro("DAHDI/i1/07xxxxxxxxx-83", "hangupcall,") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("DAHDI/i1/07xxxxxxxxx-83", "1?theend") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Goto (macro-hangupcall,s,3) [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-hangupcall:3] ExecIf("DAHDI/i1/07xxxxxxxxx-83", "0?Set(CDR(recordingfile)=)") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("DAHDI/i1/07xxxxxxxxx-83", "") in new stack [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'DAHDI/i1/07xxxxxxxxx-83' in macro 'hangupcall' [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on 'DAHDI/i1/07xxxxxxxxx-83' [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 q931.c:6837 q931_hangup: Hangup other cref:118 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 q931.c:6594 __q931_hangup: ourstate Call Received, peerstate Call Delivered, hold-state Idle [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 q931.c:5783 q931_disconnect: Call 118 enters state 11 (Disconnect Request). Hold state: Idle [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Message Type: DISCONNECT (69) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=8, window is open V(A)=8 K=7 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Message Type: DISCONNECT (69) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > [08 02 81 91] [2015-10-25 12:50:09] VERBOSE[19249] 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) [2015-10-25 12:50:09] VERBOSE[19249] chan_dahdi.c: PRI Span: 1 > Ext: 1 Cause: User busy (17), class = Normal Event (1) ] [2015-10-25 12:50:09] VERBOSE[19249][C-00000d12] chan_dahdi.c: -- Hungup 'DAHDI/i1/07xxxxxxxxx-83' [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=5 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent from originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 < Message Type: RELEASE (77) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 Received message for call 0x7f43f4005660 on link 0x164cb10 TEI/SAPI 0/0 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:8620 post_handle_q931_message: Call 118 enters state 0 (Null). Hold state: Idle [2015-10-25 12:50:09] VERBOSE[4831] sig_pri.c: Span 1: Processing event PRI_EVENT_HANGUP(6) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:6837 q931_hangup: Hangup other cref:118 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:6594 __q931_hangup: ourstate Null, peerstate Release Request, hold-state Idle [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > DL-DATA request [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE COMPLETE (90) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=9, window is open V(A)=9 K=7 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 118/0x76) (Sent to originator) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE COMPLETE (90) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > [08 02 81 90] [2015-10-25 12:50:09] VERBOSE[4831] 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) [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:6837 q931_hangup: Hangup other cref:118 [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 q931.c:6594 __q931_hangup: ourstate Null, peerstate Null, hold-state Idle [2015-10-25 12:50:09] VERBOSE[4831] chan_dahdi.c: PRI Span: 1 Destroying call 0x7f43f4005660, ourstate Null, peerstate Null, hold-state Idle