System hangup after 3 consecutive digits read back from other IVR

I have a Sangoma 50 box with DAHDI trunks module and 5 Sangoma SIP phones attached. When I make a call to a health insurance IVR and start a insurance claim procedure that requires me to press a number of buttons (digits) on my side to advance through their IVR, I have no problem until it comes to the part were their IVR reads back my fax number.

My fax number contains three consecutive "4"s and when the third “4” is pronounced on there side, my side terminates the call. This happens on numerous sets.I revert back to my old digital phone system and I have no problem with the readback.

I can get more detailed log information if needed, but I thought I would ask it anyone has had this happen in the past.

On an other issue I have a Walmart IVR that did not recognize a “2” digit after it just received a series of digits that contained a “2” in that series and recognized it in there. After receiving “8” “6” “5” “2” “3” the IVR ask for me to dial “1” for one advancement or “2” for another, I pressed “2” and it said it didn’t recognize that response try again, so I pressed “2” again and it hung up. Works fine on digital system.

That sounds a lot like DTMF detection is cutting in. We’ll need logs, sorry :sunglasses:

asterisk -rvvv

Then paste the ENTIRE call log (from before you dialed, until it hangs up)

Here is a slice of this call from the Full log of that day concerning the call that failed. It shows the call made and hangup. I am running Asterisk 13.7.2, but this has been happening since ver 12.XXX. I have a fuller version of a hung up call showing setup but I have to edit it for HIPPA reasons.

[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:13] Set(“SIP/109-0000057e”, “OUTNUM=18776383379”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:14] Set(“SIP/109-0000057e”, “custom=DAHDI/g0”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/109-0000057e”, "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt$
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/109-0000057e”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in ne$
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:17] Macro(“SIP/109-0000057e”, “dialout-trunk-predial-hook,”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/109-0000057e”, “”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/109-0000057e”, “0?bypass,1”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/109-0000057e”, “1?Set(CONNECTEDLINE(num,i)=18776383379)”) in n$
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/109-0000057e”, “1?Set(CONNECTEDLINE(name,i)=CID:9107546718)”) $
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:21] ExecIf(“SIP/109-0000057e”, "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)910754$
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:22] GotoIf(“SIP/109-0000057e”, “0?customtrunk”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-dialout-trunk:23] Dial(“SIP/109-0000057e”, “DAHDI/g0/18776383379,300,Tt”) in new stack
[2016-09-06 14:24:03] VERBOSE[22154][C-000002e7] app_dial.c: Called DAHDI/g0/18776383379
[2016-09-06 14:24:07] VERBOSE[22154][C-000002e7] app_dial.c: DAHDI/2-1 answered SIP/109-0000057e
[2016-09-06 14:24:07] VERBOSE[22162][C-000002e7] bridge_channel.c: Channel DAHDI/2-1 joined ‘simple_bridge’ basic-bridge
[2016-09-06 14:24:07] VERBOSE[22154][C-000002e7] bridge_channel.c: Channel SIP/109-0000057e joined ‘simple_bridge’ basic-bridge
[2016-09-06 14:25:01] VERBOSE[2693] asterisk.c: Remote UNIX connection
[2016-09-06 14:25:01] VERBOSE[22268] asterisk.c: Remote UNIX connection disconnected
[2016-09-06 14:25:02] VERBOSE[2693] asterisk.c: Remote UNIX connection
[2016-09-06 14:25:02] VERBOSE[22283] asterisk.c: Remote UNIX connection disconnected
[2016-09-06 14:25:02] VERBOSE[2693] asterisk.c: Remote UNIX connection
[2016-09-06 14:25:02] VERBOSE[22285] asterisk.c: Remote UNIX connection disconnected
[2016-09-06 14:26:08] VERBOSE[22162][C-000002e7] bridge_channel.c: Channel DAHDI/2-1 left ‘simple_bridge’ basic-bridge
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] bridge_channel.c: Channel SIP/109-0000057e left ‘simple_bridge’ basic-bridge
[2016-09-06 14:26:08] VERBOSE[22162][C-000002e7] sig_analog.c: Hanging up on ‘DAHDI/2-1’
[2016-09-06 14:26:08] VERBOSE[22162][C-000002e7] chan_dahdi.c: Hungup ‘DAHDI/2-1’
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] app_macro.c: Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘SIP/109-0000057e’ in macro 'dialout-trun$
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Spawn extension (from-internal, 18776383379, 7) exited non-zero on ‘SIP/109-0000057e’
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Executing [h@from-internal:1] Macro(“SIP/109-0000057e”, “hangupcall”) in new stack
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“SIP/109-0000057e”, “1?theend”) in new stack
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Goto (macro-hangupcall,s,3)
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“SIP/109-0000057e”, “0?Set(CDR(recordingfile)=)”) in new stack
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Executing [s@macro-hangupcall:4] Hangup(“SIP/109-0000057e”, “”) in new stack
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/109-0000057e’ in macro ‘hangupcall’
[2016-09-06 14:26:08] VERBOSE[22154][C-000002e7] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/109-0000057e’
[2016-09-06 14:26:09] VERBOSE[2714] chan_sip.c: Extension Changed 109[ext-local] new state Idle for Notify User 106
[2016-09-06 14:26:09] VERBOSE[2714] chan_sip.c: Extension Changed 109[ext-local] new state Idle for Notify User 110
[2016-09-06 14:26:09] VERBOSE[2714] chan_sip.c: Extension Changed 109[ext-local] new state Idle for Notify User 107
[2016-09-06 14:26:09] VERBOSE[2714] chan_sip.c: Extension Changed 109[ext-local] new state Idle for Notify User 105
[2016-09-06 14:26:09] VERBOSE[22156][C-000002e7] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2016-09-06 14:26:09] VERBOSE[22156][C-000002e7] app_mixmonitor.c: End MixMonitor Recording SIP/109-0000057e

ALSO:

I don’t know if this helps but here is a “fail2ban-20160907” log for that day and time

[2016-09-06 14:26:05] SECURITY[3211] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“2016-09-06T14:26:05.524-0400”,Severity=“Informational”,Service=“AMI”,E$
[2016-09-06 14:26:05] SECURITY[3211] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“2016-09-06T14:26:05.524-0400”,Severity=“Informational”,Service=“AMI”,E$
[2016-09-06 14:26:12] SECURITY[3211] res_security_log.c: SecurityEvent=“ChallengeSent”,EventTV=“2016-09-06T14:26:12.601-0400”,Severity=“Informational”,Service=“SIP”,Ev$
[2016-09-06 14:26:12] SECURITY[3211] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“2016-09-06T14:26:12.605-0400”,Severity=“Informational”,Service=“SIP”,E$
[2016-09-06 14:26:19] SECURITY[3211] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“2016-09-06T14:26:19.361-0400”,Severity=“Informational”,Service=“AMI”,E$

Here is a new hangup on a called IVR. It was and 800 number and the digits entered at 08:25:45 were in response to a IVR request to enter a account number. After the numbers were entered the other IVR said “I don’t…” then hung up. (I X’d out the 800 number)

[09-15 08:25:16 50:15:90] GUI: CALL_OUTGOING, Index:67
[09-15 08:25:16 50:15:90] SIP: aid 0, cid 184, tid 7817, did 0, REQUEST: INVITE, Event: 8
[09-15 08:25:16 50:15:90] SIP: aid 0, cid 184, tid 7817, did 0, RESPONSE: 100 Trying, Call is being processed!, Event: 8
[09-15 08:25:20 50:15:90] SIP: aid 0, cid 184, tid 7817, did 185, REQUEST: INVITE, Event: 10
[09-15 08:25:20 50:15:90] SIP: aid 0, cid 184, tid 7817, did 185, RESPONSE: 200 OK, Remote phone has answered!, Event: 10
[09-15 08:25:20 50:15:90] eXosip_get_sdp_info:240–>>>>>>>SIP Parse Normal SDP Body<<<<<<<
[09-15 08:25:20 50:15:90] ###SDP INFO########Addr Type=IP4—NetType=IN—Addr=192.168.0.85##################
[09-15 08:25:20 50:15:90] SIP: aid 0, SDP Payload pos 0, Type 0(0)
[09-15 08:25:20 50:15:90] SIP: Check CFG Setting, Match index_0, CodecType 0
[09-15 08:25:20 50:15:90] SIP: SDP IP 192.168.0.85, Port 12626, Interval 2, codec 0, audio 0, direct 3
[09-15 08:25:20 50:15:90] Answer2CallCtl: 5419, Contact=sip:[email protected]:5060
[09-15 08:25:20 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-15 08:25:20 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:25:20 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:25:20 50:15:90] CALL: State=0x62, Event=0x304, Chn=0
[09-15 08:25:20 50:15:90] chn=0, AEC_switch = 1
[09-15 08:25:20 50:15:90] MS: Chn 0 MSDspSetSendRev
[09-15 08:25:20 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8d8
[09-15 08:25:20 50:15:90] Chn 0 seq 59611 error(last seq 40417)
[09-15 08:25:20 50:15:90] GUI: CALL_BSNAME, Index:67
[09-15 08:25:20 50:15:90] GUI: CallIn->PeerName:
[09-15 08:25:20 50:15:90] GUI: CallIn->PeerNumber:1XXXXXXXXXX[09-15 08:25:20 50:15:90] GUI: CALL_OUTGOING_OK, Index:67
[09-15 08:25:20 50:15:90] GUI:DEBUGINFO:CallFailureInfoShow!,File:./src/callwin.c------Line:4053
[09-15 08:25:22 50:15:90] SIP: aid 0, cid 0, tid 7818, did 0, REQUEST: OPTIONS, Event: 27
[09-15 08:25:43 50:15:90] SIP: aid 0, cid 0, tid 7819, did 9, REQUEST: NOTIFY, Event: 43
[09-15 08:25:45 50:15:90] Dial Number-5, Duration 100
[09-15 08:25:45 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:45 50:15:90] CALL: DTMF 5, Duration 100, Send 2833 OK
[09-15 08:25:45 50:15:90] GUI: MSG_CHAR
[09-15 08:25:45 50:15:90] RFC2833: Chn 0 Line 67 Rev DTMF(Type=101) Event 5, Duration 1760, LastDuration 1600
[09-15 08:25:46 50:15:90] Dial Number-6, Duration 80
[09-15 08:25:46 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:46 50:15:90] CALL: DTMF 6, Duration 80, Send 2833 OK
[09-15 08:25:46 50:15:90] GUI: MSG_CHAR
[09-15 08:25:46 50:15:90] RFC2833: Chn 0 Line 67 Rev DTMF(Type=101) Event 6, Duration 960, LastDuration 800
[09-15 08:25:46 50:15:90] Dial Number-1, Duration 110
[09-15 08:25:46 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:46 50:15:90] CALL: DTMF 1, Duration 110, Send 2833 OK
[09-15 08:25:46 50:15:90] GUI: MSG_CHAR
[09-15 08:25:46 50:15:90] RFC2833: Chn 0 Line 67 Rev DTMF(Type=101) Event 1, Duration 960, LastDuration 800
[09-15 08:25:47 50:15:90] Dial Number-4, Duration 100
[09-15 08:25:47 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:47 50:15:90] CALL: DTMF 4, Duration 100, Send 2833 OK
[09-15 08:25:47 50:15:90] GUI: MSG_CHAR
[09-15 08:25:48 50:15:90] Dial Number-3, Duration 80
[09-15 08:25:48 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:48 50:15:90] CALL: DTMF 3, Duration 80, Send 2833 OK
[09-15 08:25:48 50:15:90] GUI: MSG_CHAR
[09-15 08:25:48 50:15:90] Dial Number-3, Duration 80
[09-15 08:25:48 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:48 50:15:90] CALL: DTMF 3, Duration 80, Send 2833 OK
[09-15 08:25:48 50:15:90] GUI: MSG_CHAR
[09-15 08:25:49 50:15:90] Dial Number-8, Duration 100
[09-15 08:25:49 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:49 50:15:90] CALL: DTMF 8, Duration 100, Send 2833 OK
[09-15 08:25:49 50:15:90] GUI: MSG_CHAR
[09-15 08:25:49 50:15:90] Dial Number-5, Duration 80
[09-15 08:25:49 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:49 50:15:90] CALL: DTMF 5, Duration 80, Send 2833 OK
[09-15 08:25:49 50:15:90] GUI: MSG_CHAR
[09-15 08:25:49 50:15:90] Dial Number-4, Duration 110
[09-15 08:25:49 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-15 08:25:49 50:15:90] CALL: DTMF 4, Duration 110, Send 2833 OK
[09-15 08:25:49 50:15:90] GUI: MSG_CHAR
[09-15 08:25:50 50:15:90] Dial SOFTKEY1
[09-15 08:25:50 50:15:90] Chn 0 rev unprocess event 0x19a in L2_OFFHOOK!
[09-15 08:25:50 50:15:90] CALL: State=0x64, Event=0x10d, Chn=0
[09-15 08:25:50 50:15:90] chn=0, AEC_switch = 0
[09-15 08:25:50 50:15:90] MS: Chn 0 MSDspStopSendRev
[09-15 08:25:50 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8d9
[09-15 08:25:50 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8e2
[09-15 08:25:50 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:25:50 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:25:50 50:15:90] SIP: sdp_message_pro: Local IP is 192.168.0.92
[09-15 08:25:50 50:15:90] SIP: sdp_message - CodecType 0
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: aid 0, cid 184, tid 7820, did 185, REQUEST: INVITE, Event: 8
[09-15 08:25:50 50:15:90] SIP: aid 0, cid 184, tid 7820, did 185, RESPONSE: 100 Trying, Call is being processed!, Event: 8
[09-15 08:25:50 50:15:90] SIP: aid 0, cid 184, tid 7820, did 185, REQUEST: INVITE, Event: 10
[09-15 08:25:50 50:15:90] SIP: aid 0, cid 184, tid 7820, did 185, RESPONSE: 200 OK, Remote phone has answered!, Event: 10
[09-15 08:25:50 50:15:90] eXosip_get_sdp_info:240–>>>>>>>SIP Parse Normal SDP Body<<<<<<<
[09-15 08:25:50 50:15:90] ###SDP INFO########Addr Type=IP4—NetType=IN—Addr=192.168.0.85##################
[09-15 08:25:50 50:15:90] SIP: aid 0, SDP Payload pos 0, Type 0(0)
[09-15 08:25:50 50:15:90] SIP: Check CFG Setting, Match index_0, CodecType 0
[09-15 08:25:50 50:15:90] SIP: SDP IP 192.168.0.85, Port 12626, Interval 2, codec 0, audio 0, direct 2
[09-15 08:25:50 50:15:90] Answer2CallCtl: 5419, Contact=sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:25:50 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:25:50 50:15:90] CALL: State=0x80, Event=0x304, Chn=0
[09-15 08:25:50 50:15:90] CALL: Receive 200 OK for Inivite_HOLD Line=67
[09-15 08:25:50 50:15:90] GUI: CALL_HOLD, Index:67
[09-15 08:25:50 50:15:90] GUI: CALL_TRANSFER, Index:67
[09-15 08:25:50 50:15:90] GUI: CALL_BSNAME, Index:67
[09-15 08:25:51 50:15:90] BSP: SetLineLedStatus line 0, error flag 0x1
[09-15 08:25:56 50:15:90] FXS Chn 0 On Hook, tick 1363908390
[09-15 08:25:56 50:15:90] CALL: State=0x81, Event=0x122, Chn=0
[09-15 08:25:56 50:15:90] CALL:20971–Resv Onhook—LcmLine=67,CurLine=67!!!
[09-15 08:25:56 50:15:90] CALL: CurLine 67, State 0x8c, OnHook!!!
[09-15 08:25:56 50:15:90] chn=0, AEC_switch = 1
[09-15 08:25:56 50:15:90] MS: Chn 0 MSDspSetSendRev
[09-15 08:25:56 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8db
[09-15 08:25:56 50:15:90] CALL: User abandon new service
[09-15 08:25:56 50:15:90] CALL: _XPhoneNextState…
[09-15 08:25:56 50:15:90] CALL: Clear Transfer, Conf and NS Flag
[09-15 08:25:56 50:15:90] CALL: Req LCM Switch to Line 67, LineCSState 0x64
[09-15 08:25:56 50:15:90] chn=0, AEC_switch = 1
[09-15 08:25:56 50:15:90] MS: Chn 0 MSDspSetSendRev
[09-15 08:25:56 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:25:56 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:25:56 50:15:90] SIP: sdp_message_pro: Local IP is 192.168.0.92
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:25:56 50:15:90] CALL: State=0x64, Event=0x215, Chn=0
[09-15 08:25:56 50:15:90] chn=0, AEC_switch = 1
[09-15 08:25:56 50:15:90] MS: Chn 0 MSDspSetSendRev
[09-15 08:25:56 50:15:90] GUI: CALL_RESTORE, Index:67
[09-15 08:25:56 50:15:90] HANDSET mode
[09-15 08:25:56 50:15:90] BSP: OpenHandset HandsetVolume :14, MicVolum 10
[09-15 08:25:56 50:15:90] SIP: aid 0, cid 184, tid 7821, did 185, REQUEST: INVITE, Event: 8
[09-15 08:25:56 50:15:90] SIP: aid 0, cid 184, tid 7821, did 185, RESPONSE: 100 Trying, Call is being processed!, Event: 8
[09-15 08:25:56 50:15:90] SIP: aid 0, cid 184, tid 7821, did 185, REQUEST: INVITE, Event: 10
[09-15 08:25:56 50:15:90] SIP: aid 0, cid 184, tid 7821, did 185, RESPONSE: 200 OK, Remote phone has answered!, Event: 10
[09-15 08:25:56 50:15:90] eXosip_get_sdp_info:240–>>>>>>>SIP Parse Normal SDP Body<<<<<<<
[09-15 08:25:56 50:15:90] ###SDP INFO########Addr Type=IP4—NetType=IN—Addr=192.168.0.85##################
[09-15 08:25:56 50:15:90] SIP: aid 0, SDP Payload pos 0, Type 0(0)
[09-15 08:25:56 50:15:90] SIP: Check CFG Setting, Match index_0, CodecType 0
[09-15 08:25:56 50:15:90] SIP: SDP IP 192.168.0.85, Port 12626, Interval 2, codec 0, audio 0, direct 3
[09-15 08:25:56 50:15:90] Answer2CallCtl: 5419, Contact=sip:[email protected]:5060
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:25:56 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:25:56 50:15:90] CALL: State=0x64, Event=0x304, Chn=0
[09-15 08:25:56 50:15:90] chn=0, AEC_switch = 1
[09-15 08:25:56 50:15:90] MS: Chn 0 MSDspSetSendRev
[09-15 08:25:56 50:15:90] GUI: lcmCallRestoreHandler MuteInfo:32812480
[09-15 08:25:56 50:15:90] GUI: CALL_SWITCH, Index:67
[09-15 08:25:56 50:15:90] GUI: CALL_OFFHOOKTYPE:2
[09-15 08:25:56 50:15:90] GUI: CALL_BSNAME, Index:67
[09-15 08:25:56 50:15:90] GUI: CallIn->PeerName:
[09-15 08:25:56 50:15:90] GUI: CallIn->PeerNumber:1XXXXXXXXXX
[09-15 08:26:00 50:15:90] FXS Chn 0 Off Hook, tick 1363908871
[09-15 08:26:00 50:15:90] Chn 0 rev unprocess event 0x100 in L2_OFFHOOK!
[09-15 08:26:01 50:15:90] FXS Chn 0 On Hook, tick 1363908926
[09-15 08:26:01 50:15:90] CALL: State=0x64, Event=0x122, Chn=0
[09-15 08:26:01 50:15:90] CALL:20971–Resv Onhook—LcmLine=67,CurLine=67!!!
[09-15 08:26:01 50:15:90] CALL: CurLine 67, State 0x64, OnHook!!!
[09-15 08:26:01 50:15:90] CALL: CurLine 67, OnHook, Send BYE to Peer!!!
[09-15 08:26:01 50:15:90] SendSpecialEvent2LCM: Event=2534
[09-15 08:26:01 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8de
[09-15 08:26:01 50:15:90] CALL: line 67 OnHook, CurLineState 0x64
[09-15 08:26:01 50:15:90] CALL: _XPhoneNextState…
[09-15 08:26:01 50:15:90] CALL: Clear Transfer, Conf and NS Flag
[09-15 08:26:01 50:15:90] CALL: There isn’t any call, Release
[09-15 08:26:01 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8f7
[09-15 08:26:01 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x954
[09-15 08:26:01 50:15:90] SendSpecialEvent2LCM: Event=2534
[09-15 08:26:01 50:15:90] chn=0, AEC_switch = 0
[09-15 08:26:01 50:15:90] MS: Chn 0 MSDspStopSendRev
[09-15 08:26:01 50:15:90] SIP: ActionUrlPro local_uri sip:[email protected]:5060
[09-15 08:26:01 50:15:90] SIP: ActionUrlPro remote_uri sip:[email protected]:5060
[09-15 08:26:01 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:26:01 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:26:01 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:26:01 50:15:90] GUI:MS_ZRTP_END_EVENT
[09-15 08:26:01 50:15:90] L2Call receive NormalReleaseEvent, release
[09-15 08:26:01 50:15:90] CALL: State=0x60, Event=0x207, Chn=0
[09-15 08:26:01 50:15:90] SIPPro: 12811, Release All Sip Dialog!!
[09-15 08:26:01 50:15:90] GUI: CALL_ONHOOK,index:67
[09-15 08:26:01 50:15:90] GUI: 2:Call LCMSUBCallData:32785328:subdatastatistic:53
[09-15 08:26:01 50:15:90] CALL: State=0x60, Event=0x91c, Chn=0
[09-15 08:26:01 50:15:90] CALL: LCM Exit MenuCfg
[09-15 08:26:01 50:15:90] GUI: CALL_ONHOOK, Index:67
[09-15 08:26:01 50:15:90] GUI: Idle Softkey History,Directory,DND,Menu
[09-15 08:26:01 50:15:90] LCM: Select aid:0
[09-15 08:26:01 50:15:90] L2C: LCM set aid 0
[09-15 08:26:01 50:15:90] GUI: Receive CALL_BUSY_UNLOCK_KEYPAD!
[09-15 08:26:08 50:15:90] Open /dev/ttyS1
[09-15 08:26:08 50:15:90] Baudrate is 2400

[09-15 08:26:08 50:15:90] init_ehs_mode

[09-15 08:26:20 50:15:90] CALL: State=0x60, Event=0x1004, Chn=0
[09-15 08:26:20 50:15:90] CALL: Chn 0 Line 0 rev unprocess event 0x1004 in CS_STATE_IDLE
[09-15 08:26:21 50:15:90] SIP: aid 0, cid 0, tid 7823, did 0, REQUEST: OPTIONS, Event: 27
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7824, did 15, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7824, did 15, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7825, did 14, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7825, did 14, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7826, did 13, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7826, did 13, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7827, did 12, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7827, did 12, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7828, did 11, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7828, did 11, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7829, did 10, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7829, did 10, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7830, did 9, REQUEST: SUBSCRIBE, Event: 40
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7830, did 9, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-15 08:27:20 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-15 08:27:20 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-15 08:27:20 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7831, did 15, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7831, did 15, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 8, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7838, did 15, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7832, did 14, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7832, did 14, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 7, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7839, did 14, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7833, did 13, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7833, did 13, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 6, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7840, did 13, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7834, did 12, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7834, did 12, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 3, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7841, did 12, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7835, did 11, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7835, did 11, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 2, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7842, did 11, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7836, did 10, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7836, did 10, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 1, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7843, did 10, REQUEST: NOTIFY, Event: 43
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7837, did 9, REQUEST: SUBSCRIBE, Event: 38
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7837, did 9, RESPONSE: 200 OK, 2xx received for SUBSCRIBE!, Event: 38
[09-15 08:27:20 50:15:90] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-15 08:27:20 50:15:90] SIP: aid 0, Dsskey 0, Subscribe Response Status 200
[09-15 08:27:20 50:15:90] SIP: aid 0, cid 0, tid 7844, did 9, REQUEST: NOTIFY, Event: 43
[09-15 08:27:21 50:15:90] SIP: aid 0, cid 0, tid 7845, did 0, REQUEST: OPTIONS, Event: 27
[09-15 08:27:50 50:15:90] Open /dev/ttyS1
[09-15 08:27:50 50:15:90] Baudrate is 2400

[09-15 08:27:50 50:15:90] init_ehs_mode

[09-15 08:27:55 50:15:90] SIPPNP: MCast Send:

[09-15 08:27:55 50:15:90] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
[09-15 08:27:55 50:15:90] SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.0.92:60000;branch=z9hG4bK1820698314
From: sip:[email protected];tag=1969758766
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 20 SUBSCRIBE
Contact: sip:[email protected]:60000
Max-Forwards: 70
User-Agent: S700 2.0.4.15
Expires: 0
Event: ua-profile;profile-type=“device”;vendor=“Sangoma”;model=“S700”;version="2.0.4.15"
Accept: application/url
Content-Length: 0

[09-15 08:27:55 50:15:90] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

[09-15 08:28:21 50:15:90] SIP: aid 0, cid 0, tid 7846, did 0, REQUEST: OPTIONS, Event: 27
[09-15 08:29:21 50:15:90] SIP: aid 0, cid 0, tid 7847, did 0, REQUEST: OPTIONS, Event: 27
[09-15 08:29:33 50:15:90] Open /dev/ttyS1
[09-15

At a guess your DAHDI hardware is being too relaxed about DTMF detection. Also, you shouldn’t have a ‘t’ on your outbound trunk ANYWAY (that was a design decision that was changed earlier this year - I don’t know how your machine is even still doing that!). Go into Advanced Settings and set Asterisk Outbound Trunk Dial Options to just ‘T’ by itself.

I’d also check that you’re up to date. Admin → Module Admin → Check Online.

I will change the small “t” thing next week and I do an update every week, but remember one of the original problems was every time I called an IVR and it read back a number, I had successfully entered, with three "4"s, when it got to the third consecutive “4” it dropped the call.

I’m sorry, I don’t have that particular log yet but i’m working on it to have for you next week…

This was a hangup from a call yesterday that had digits inputed from a phone on the FreePBX system and then the remote IVR read back the number and the call was diconnected after the third “1”, that was never dialled. Only two “1” digits were dialed in response to the commands from the remote IVR. This was a copy of the log from a S700 SIP phone. Following this log is a log from the PBX.

I did notice the “NTP clock skew detected:”, and just to let you know, both the phone and the PBX are have the same NTP server settings.

[09-20 14:45:09 50:15:90] CALL: DTMF 5, Duration 70, Send 2833 OK
[09-20 14:45:09 50:15:90] GUI: MSG_CHAR
[09-20 14:45:09 50:15:90] Dial Number-6, Duration 110
[09-20 14:45:09 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:09 50:15:90] CALL: DTMF 6, Duration 110, Send 2833 OK
[09-20 14:45:09 50:15:90] GUI: MSG_CHAR
[09-20 14:45:10 50:15:90] Dial Number-1, Duration 80
[09-20 14:45:10 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:10 50:15:90] CALL: DTMF 1, Duration 80, Send 2833 OK
[09-20 14:45:10 50:15:90] GUI: MSG_CHAR
[09-20 14:45:10 50:15:90] Dial Number-4, Duration 110
[09-20 14:45:10 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:10 50:15:90] CALL: DTMF 4, Duration 110, Send 2833 OK
[09-20 14:45:10 50:15:90] GUI: MSG_CHAR
[09-20 14:45:10 50:15:90] Dial Number-3, Duration 50
[09-20 14:45:10 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:10 50:15:90] CALL: DTMF 3, Duration 50, Send 2833 OK
[09-20 14:45:10 50:15:90] GUI: MSG_CHAR
[09-20 14:45:11 50:15:90] Dial Number-3, Duration 80
[09-20 14:45:11 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:11 50:15:90] CALL: DTMF 3, Duration 80, Send 2833 OK
[09-20 14:45:11 50:15:90] GUI: MSG_CHAR
[09-20 14:45:11 50:15:90] Dial Number-8, Duration 50
[09-20 14:45:11 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:11 50:15:90] CALL: DTMF 8, Duration 50, Send 2833 OK
[09-20 14:45:11 50:15:90] GUI: MSG_CHAR
[09-20 14:45:11 50:15:90] RFC2833: Chn 0 Line 67 Rev DTMF(Type=101) Event 8, Duration 1120, LastDuration 960
[09-20 14:45:11 50:15:90] Dial Number-5, Duration 80
[09-20 14:45:11 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:11 50:15:90] CALL: DTMF 5, Duration 80, Send 2833 OK
[09-20 14:45:11 50:15:90] GUI: MSG_CHAR
[09-20 14:45:12 50:15:90] Dial Number-4, Duration 60
[09-20 14:45:12 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:12 50:15:90] CALL: DTMF 4, Duration 60, Send 2833 OK
[09-20 14:45:12 50:15:90] GUI: MSG_CHAR
[09-20 14:45:13 50:15:90] Dial Number-11, Duration 80
[09-20 14:45:13 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:13 50:15:90] CALL: DTMF 11, Duration 80, Send 2833 OK
[09-20 14:45:13 50:15:90] GUI: MSG_CHAR
[09-20 14:45:30 50:15:90] Dial Number-1, Duration 190
[09-20 14:45:30 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:30 50:15:90] CALL: DTMF 1, Duration 190, Send 2833 OK
[09-20 14:45:30 50:15:90] GUI: MSG_CHAR
[09-20 14:45:33 50:15:90] SIP: aid 0, cid 0, tid 55232, did 0, REQUEST: OPTIONS, Event: 27
[09-20 14:45:34 50:15:90] Dial Number-1, Duration 130
[09-20 14:45:34 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:34 50:15:90] CALL: DTMF 1, Duration 130, Send 2833 OK
[09-20 14:45:34 50:15:90] GUI: MSG_CHAR
[09-20 14:45:37 50:15:90] SIP: aid 0, cid 0, tid 55233, did 1143, REQUEST: NOTIFY, Event: 43
[09-20 14:45:38 50:15:90] Dial Number-1, Duration 80
[09-20 14:45:38 50:15:90] CALL: State=0x64, Event=0x3, Chn=0
[09-20 14:45:38 50:15:90] CALL: DTMF 1, Duration 80, Send 2833 OK
[09-20 14:45:38 50:15:90] GUI: MSG_CHAR
[09-20 14:45:38 50:15:90] RFC2833: Chn 0 Line 67 Rev DTMF(Type=101) Event 1, Duration 1440, LastDuration 1280
[09-20 14:45:40 50:15:90] Internal RTCP NTP clock skew detected: lsr=02565994, dlsr=00000560, now=02565eb2, eedelay=00000000
[09-20 14:45:50 50:15:90] Internal RTCP NTP clock skew detected: lsr=02605994, dlsr=00000560, now=02605eb2, eedelay=00000000
[09-20 14:45:55 50:15:90] Internal RTCP NTP clock skew detected: lsr=02655994, dlsr=00000560, now=02655eb2, eedelay=00000000
[09-20 14:45:58 50:15:90] SIP: aid 0, cid 0, tid 55234, did 1143, REQUEST: NOTIFY, Event: 43
[09-20 14:45:59 50:15:90] SIP: aid 0, cid 1171, tid 55235, did 1172, REQUEST: BYE, Event: 18
[09-20 14:45:59 50:15:90] SIP: aid 0, cid 1171, tid 55235, did 1172, RESPONSE: 200 OK, New request received!, Event: 18
[09-20 14:45:59 50:15:90] SIP: aid 0, cid 1171, tid 55235, did 1172, REQUEST: BYE, Event: 25
[09-20 14:45:59 50:15:90] SIP: aid 0, cid 1171, tid 55235, did 1172, RESPONSE: 200 OK, Bye Received!, Event: 25
[09-20 14:45:59 50:15:90] SIP: SIP_CALL_CLOSED, cid 1171, did 1172
[09-20 14:45:59 50:15:90] SIP: ActionUrlCall, can’t get call_dialog!!!
[09-20 14:45:59 50:15:90] SIP: ActionUrlPro active_url sip:[email protected]:5060
[09-20 14:45:59 50:15:90] SIP: aid 0, cid 1171, call free
[09-20 14:45:59 50:15:90] GetTUReportEvent:11130**********0*****
[09-20 14:45:59 50:15:90] CALL: State=0x64, Event=0x306, Chn=0
[09-20 14:45:59 50:15:90] XPhoneRelPro:20312######===>>>Line 67 LineState 0x64…
[09-20 14:45:59 50:15:90] SendSpecialEvent2LCM: Event=2534
[09-20 14:45:59 50:15:90] CALL: _XPhoneNextState…
[09-20 14:45:59 50:15:90] CALL: Clear Transfer, Conf and NS Flag
[09-20 14:45:59 50:15:90] CALL: There isn’t any call, Release
[09-20 14:45:59 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8f7
[09-20 14:45:59 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x954
[09-20 14:45:59 50:15:90] SendSpecialEvent2LCM: Event=2534
[09-20 14:45:59 50:15:90] chn=0, AEC_switch = 0
[09-20 14:45:59 50:15:90] MS: Chn 0 MSDspStopSendRev
[09-20 14:45:59 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 67, event 0x8e1
[09-20 14:45:59 50:15:90] GUI:MS_ZRTP_END_EVENT
[09-20 14:45:59 50:15:90] GUI: CALL_REL_ALL, Index:0
[09-20 14:45:59 50:15:90] GUI: 2:Call LCMSUBCallData:32300512:subdatastatistic:309
[09-20 14:45:59 50:15:90] L2Call receive NormalReleaseEvent, release
[09-20 14:45:59 50:15:90] SIPPro: 12811, Release All Sip Dialog!!
[09-20 14:45:59 50:15:90] CALL: State=0x60, Event=0x91c, Chn=0
[09-20 14:45:59 50:15:90] CALL: LCM Exit MenuCfg
[09-20 14:45:59 50:15:90] GUI: Idle Softkey History,Directory,DND,Menu
[09-20 14:45:59 50:15:90] LCM: Select aid:0
[09-20 14:45:59 50:15:90] L2C: LCM set aid 0
[09-20 14:45:59 50:15:90] GUI: Receive CALL_BUSY_UNLOCK_KEYPAD!
[09-20 14:45:59 50:15:90] GUI: CALL_ONHOOK,index:67
[09-20 14:45:59 50:15:90] GUI: CALL_ONHOOK, Index:67
[09-20 14:46:02 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 0, did 0, REQUEST: REGISTER, Event: 2
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 0, did 0, RESPONSE: 401 Unauthorized, Registration failed!, Event: 2
[09-20 14:46:02 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-20 14:46:02 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-20 14:46:02 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55238, did 0, REQUEST: OPTIONS, Event: 27
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 0, did 0, REQUEST: REGISTER, Event: 1
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 0, did 0, RESPONSE: 200 OK, User is successfully registred!, Event: 1
[09-20 14:46:02 50:15:90] SIP: aid 0, Fail to get User-Agent header
[09-20 14:46:02 50:15:90] SIP: aid 0, expires: 900(900)
[09-20 14:46:02 50:15:90] SIP: aid 0, expires: 900(900)
[09-20 14:46:02 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-20 14:46:02 50:15:90] SIP: aid 0 DssKey 5 DSS_BLF_Send_Subscribe OK
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55240, did 0, REQUEST: NOTIFY, Event: 27
[09-20 14:46:02 50:15:90] CALL: State=0x60, Event=0x31d, Chn=0
[09-20 14:46:02 50:15:90] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8d4
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55239, did 0, REQUEST: SUBSCRIBE, Event: 40
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55239, did 0, RESPONSE: 401 Unauthorized, 4xx received for SUBSCRIBE!, Event: 40
[09-20 14:46:02 50:15:90] SIP: find_authentication_info, aid 0, username: 107, realm: “asterisk”
[09-20 14:46:02 50:15:90] SIP: find_auth_info, aid 0, username: 107, account match
[09-20 14:46:02 50:15:90] SIP: sip_nict_init, no route, req_uri->host:port is 192.168.0.85:5060
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55241, did 0, REQUEST: SUBSCRIBE, Event: 40
[09-20 14:46:02 50:15:90] SIP: aid 0, cid 0, tid 55241, did 0, RESPONSE: 404 Not Found, 4xx received for SUBSCRIBE!, Event: 40
[09-20 14:46:02 50:15:90] SIP: aid 0, Dsskey 5, Subscribe Response Status 404
[09-20 14:46:02 50:15:90] SIP: sid 1173, After subscribe_free, Total free memory: 32480 KB

[09-20 14:46:02 50:15:90] GUI: Receive Call Register Success!
[09-20 14:46:02 50:15:90] LCM: Select aid:0
[09-20 14:46:02 50:15:90] L2C: LCM set aid 0
[09-20 14:46:06 50:15:90] SIP: aid 0, cid 0, tid 55242, did 1143, REQUEST: NOTIFY, Event: 43
[09-20 14:46:10 50:15:90] Open /dev/ttyS1
[09-20 14:46:10 50:15:90] Baudrate is 2400

[09-20 14:46:10 50:15:90] init_ehs_mode

[09-20 14:46:11 50:15:90] FXS Chn 0 On Hook, tick 1409389123
[09-20 14:46:11 50:15:90] Chn 0 rev unprocess event 0x122 in L2_IDLE!
[09-20 14:46:46 50:15:90] SIP REFRESH####Alive Time=271######js->s_reg_period=300############

This is the log from the Asterisk on the same call:

-- Executing [18009420854@from-internal:1] Macro("SIP/107-00000017", "user-callerid,LIMIT,EXTERNAL,") in new stack

== Extension Changed 107[ext-local] new state InUse for Notify User 103
== Extension Changed 107[ext-local] new state InUse for Notify User 105
== Extension Changed 107[ext-local] new state InUse for Notify User 109
== Extension Changed 107[ext-local] new state InUse for Notify User 110
– Executing [s@macro-user-callerid:1] Set(“SIP/107-00000017”, “TOUCH_MONITOR=1474397073.265”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/107-00000017”, “AMPUSER=107”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/107-00000017”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/107-00000017”, “1?Set(REALCALLERIDNUM=107)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/107-00000017”, “AMPUSER=107”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/107-00000017”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/107-00000017”, “AMPUSERCIDNAME=Beverly”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/107-00000017”, “0?report”) in new stack
– Executing [s@macro-user-callerid:9] Set(“SIP/107-00000017”, “AMPUSERCID=107”) in new stack
– Executing [s@macro-user-callerid:10] Set(“SIP/107-00000017”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/107-00000017”, “CALLERID(all)=“Beverly” <107>”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/107-00000017”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:13] ExecIf(“SIP/107-00000017”, “1?Set(GROUP(concurrency_limit)=107)”) in new stack
– Executing [s@macro-user-callerid:14] ExecIf(“SIP/107-00000017”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [s@macro-user-callerid:15] GotoIf(“SIP/107-00000017”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,29)
– Executing [s@macro-user-callerid:29] Set(“SIP/107-00000017”, “CALLERID(number)=107”) in new stack
– Executing [s@macro-user-callerid:30] Set(“SIP/107-00000017”, “CALLERID(name)=Beverly”) in new stack
– Executing [s@macro-user-callerid:31] GotoIf(“SIP/107-00000017”, “0?cnum”) in new stack
– Executing [s@macro-user-callerid:32] Set(“SIP/107-00000017”, “CDR(cnam)=Beverly”) in new stack
– Executing [s@macro-user-callerid:33] Set(“SIP/107-00000017”, “CDR(cnum)=107”) in new stack
– Executing [s@macro-user-callerid:34] Set(“SIP/107-00000017”, “CHANNEL(language)=en”) in new stack
– Executing [18009420854@from-internal:2] Gosub(“SIP/107-00000017”, “sub-record-check,s,1(out,18009420854,yes)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/107-00000017”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“SIP/107-00000017”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“SIP/107-00000017”, “NOW=1474397073”) in new stack
– Executing [s@sub-record-check:4] Set(“SIP/107-00000017”, “__DAY=20”) in new stack
– Executing [s@sub-record-check:5] Set(“SIP/107-00000017”, “__MONTH=09”) in new stack
– Executing [s@sub-record-check:6] Set(“SIP/107-00000017”, “__YEAR=2016”) in new stack
– Executing [s@sub-record-check:7] Set(“SIP/107-00000017”, “__TIMESTR=20160920-144433”) in new stack
– Executing [s@sub-record-check:8] Set(“SIP/107-00000017”, “__FROMEXTEN=107”) in new stack
– Executing [s@sub-record-check:9] Set(“SIP/107-00000017”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:10] NoOp(“SIP/107-00000017”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/107-00000017”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/107-00000017”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/107-00000017”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/107-00000017”, “3?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/107-00000017”, “1?sub-record-check,out,1”) in new stack
– Goto (sub-record-check,out,1)
– Executing [out@sub-record-check:1] NoOp(“SIP/107-00000017”, “Outbound Recording Check from 107 to 18009420854”) in new stack
– Executing [out@sub-record-check:2] Set(“SIP/107-00000017”, “RECMODE=dontcare”) in new stack
– Executing [out@sub-record-check:3] ExecIf(“SIP/107-00000017”, “1?Goto(routewins)”) in new stack
– Goto (sub-record-check,out,7)
– Executing [out@sub-record-check:7] Gosub(“SIP/107-00000017”, “recordcheck,1(yes,out,18009420854)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/107-00000017”, “Starting recording check against yes”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/107-00000017”, “yes”) in new stack
– Goto (sub-record-check,recordcheck,9)
– Executing [recordcheck@sub-record-check:9] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [recordcheck@sub-record-check:10] Set(“SIP/107-00000017”, “__REC_POLICY_MODE=YES”) in new stack
– Executing [recordcheck@sub-record-check:11] Goto(“SIP/107-00000017”, “startrec”) in new stack
– Goto (sub-record-check,recordcheck,16)
– Executing [recordcheck@sub-record-check:16] NoOp(“SIP/107-00000017”, “Starting recording: out, 18009420854”) in new stack
– Executing [recordcheck@sub-record-check:17] Set(“SIP/107-00000017”, “AUDIOHOOK_INHERIT(MixMonitor)=yes”) in new stack
– Executing [recordcheck@sub-record-check:18] Set(“SIP/107-00000017”, “__CALLFILENAME=out-18009420854-107-20160920-144433-1474397073.265”) in new stack
– Executing [recordcheck@sub-record-check:19] MixMonitor(“SIP/107-00000017”, “2016/09/20/out-18009420854-107-20160920-144433-1474397073.265.wav,ai(LOCAL_MIXMON_ID),”) in new stack
– Executing [recordcheck@sub-record-check:20] Set(“SIP/107-00000017”, “__MIXMON_ID=0xb7200bb8”) in new stack
– Executing [recordcheck@sub-record-check:21] Set(“SIP/107-00000017”, “__RECORD_ID=SIP/107-00000017”) in new stack
– Executing [recordcheck@sub-record-check:22] Set(“SIP/107-00000017”, “__REC_STATUS=RECORDING”) in new stack
– Executing [recordcheck@sub-record-check:23] Set(“SIP/107-00000017”, “CDR(recordingfile)=out-18009420854-107-20160920-144433-1474397073.265.wav”) in new stack
– Executing [recordcheck@sub-record-check:24] Return(“SIP/107-00000017”, “”) in new stack
– Executing [out@sub-record-check:8] Return(“SIP/107-00000017”, “”) in new stack
– Executing [18009420854@from-internal:3] ExecIf(“SIP/107-00000017”, “0 ?Set(CDR(accountcode)=)”) in new stack
– Executing [18009420854@from-internal:4] Set(“SIP/107-00000017”, “ROUTE_CIDSAVE=“Beverly” <107>”) in new stack
== Begin MixMonitor Recording SIP/107-00000017
– Executing [18009420854@from-internal:5] Set(“SIP/107-00000017”, “MOHCLASS=default”) in new stack
– Executing [18009420854@from-internal:6] Set(“SIP/107-00000017”, “_NODEST=”) in new stack
– Executing [18009420854@from-internal:7] Macro(“SIP/107-00000017”, “dialout-trunk,1,18009420854,off”) in new stack
– Executing [s@macro-dialout-trunk:1] Set(“SIP/107-00000017”, “DIAL_TRUNK=1”) in new stack
– Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/107-00000017”, “0?sub-pincheck,s,1()”) in new stack
– Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/107-00000017”, “0?disabletrunk,1”) in new stack
– Executing [s@macro-dialout-trunk:4] Set(“SIP/107-00000017”, “DIAL_NUMBER=18009420854”) in new stack
– Executing [s@macro-dialout-trunk:5] Set(“SIP/107-00000017”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
– Executing [s@macro-dialout-trunk:6] Set(“SIP/107-00000017”, “OUTBOUND_GROUP=OUT_1”) in new stack
– Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/107-00000017”, “1?nomax”) in new stack
– Goto (macro-dialout-trunk,s,9)
– Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/107-00000017”, “0?skipoutcid”) in new stack
– Executing [s@macro-dialout-trunk:10] Set(“SIP/107-00000017”, “DIAL_TRUNK_OPTIONS=T”) in new stack
– Executing [s@macro-dialout-trunk:11] Macro(“SIP/107-00000017”, “outbound-callerid,1”) in new stack
– Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/107-00000017”, “0?Set(CALLERPRES(name-pres)=)”) in new stack
– Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/107-00000017”, “0?Set(CALLERPRES(num-pres)=)”) in new stack
– Executing [s@macro-outbound-callerid:3] ExecIf(“SIP/107-00000017”, “0?Set(REALCALLERIDNUM=107)”) in new stack
– Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/107-00000017”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,7)
– Executing [s@macro-outbound-callerid:7] Set(“SIP/107-00000017”, “USEROUTCID=”) in new stack
– Executing [s@macro-outbound-callerid:8] Set(“SIP/107-00000017”, “EMERGENCYCID=”) in new stack
– Executing [s@macro-outbound-callerid:9] Set(“SIP/107-00000017”, “TRUNKOUTCID=910754XXXX”) in new stack
– Executing [s@macro-outbound-callerid:10] GotoIf(“SIP/107-00000017”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,15)
– Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/107-00000017”, “1?Set(CALLERID(all)=910754XXXX)”) in new stack
– Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/107-00000017”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/107-00000017”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [s@macro-outbound-callerid:18] ExecIf(“SIP/107-00000017”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
– Executing [s@macro-outbound-callerid:19] ExecIf(“SIP/107-00000017”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
– Executing [s@macro-outbound-callerid:20] Set(“SIP/107-00000017”, “CDR(outbound_cnum)=910754XXXX”) in new stack
– Executing [s@macro-outbound-callerid:21] Set(“SIP/107-00000017”, “CDR(outbound_cnam)=”) in new stack
[2016-09-20 14:44:34] WARNING[5389]: func_cdr.c:352 cdr_write_callback: CDR requires a value (CDR(variable)=value)
– Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/107-00000017”, “1?sub-flp-1,s,1()”) in new stack
– Executing [s@sub-flp-1:1] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:2] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:3] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:4] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:5] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:6] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:7] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:8] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:9] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:10] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:11] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:12] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:13] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:14] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:15] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:16] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:17] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:18] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:19] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:20] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:21] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:22] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:23] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:24] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:25] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:26] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:27] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:28] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:29] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:30] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:31] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:32] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:33] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:34] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:35] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:36] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:37] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:38] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:39] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:40] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:41] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:42] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:43] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:44] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:45] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:46] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:47] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:48] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:49] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:50] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:51] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:52] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:53] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:54] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:55] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:56] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:57] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:58] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:59] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:60] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:61] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:62] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:63] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:64] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:65] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:66] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:67] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:68] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:69] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:70] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:71] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:72] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:73] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:74] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:75] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:76] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:77] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:78] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:79] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:80] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:81] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:82] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:83] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:84] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:85] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:86] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:87] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:88] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:89] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:90] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:91] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:92] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:93] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:94] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:95] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:96] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:97] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:98] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:99] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:100] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:101] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:102] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:103] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:104] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:105] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:106] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:107] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:108] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:109] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:110] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:111] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:112] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:113] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:114] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:115] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:116] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:117] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:118] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:119] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:120] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:121] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:122] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:123] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:124] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:125] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:126] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:127] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:128] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:129] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:130] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:131] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:132] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:133] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:134] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:135] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:136] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:137] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:138] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:139] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:140] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:141] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:142] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:143] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:144] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:145] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:146] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:147] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:148] ExecIf(“SIP/107-00000017”, “0?Return()”) in new stack
– Executing [s@sub-flp-1:149] Return(“SIP/107-00000017”, “”) in new stack
– Executing [s@macro-dialout-trunk:13] Set(“SIP/107-00000017”, “OUTNUM=18009420854”) in new stack
– Executing [s@macro-dialout-trunk:14] Set(“SIP/107-00000017”, “custom=DAHDI/g0”) in new stack
– Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/107-00000017”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack
– Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/107-00000017”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack
– Executing [s@macro-dialout-trunk:17] Macro(“SIP/107-00000017”, “dialout-trunk-predial-hook,”) in new stack
– Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/107-00000017”, “”) in new stack
– Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/107-00000017”, “0?bypass,1”) in new stack
– Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/107-00000017”, “1?Set(CONNECTEDLINE(num,i)=18009420854)”) in new stack
– Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/107-00000017”, “1?Set(CONNECTEDLINE(name,i)=CID:910754XXXX)”) in new stack
– Executing [s@macro-dialout-trunk:21] ExecIf(“SIP/107-00000017”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)910754XXXX)”) in new stack
– Executing [s@macro-dialout-trunk:22] GotoIf(“SIP/107-00000017”, “0?customtrunk”) in new stack
– Executing [s@macro-dialout-trunk:23] Dial(“SIP/107-00000017”, “DAHDI/g0/18009420854,300,T”) in new stack
– Called DAHDI/g0/18009420854
– DAHDI/3-1 answered SIP/107-00000017
– Channel DAHDI/3-1 joined ‘simple_bridge’ basic-bridge <170819f3-f919-408b-b6c8-b73fea0c6827>
– Channel SIP/107-00000017 joined ‘simple_bridge’ basic-bridge <170819f3-f919-408b-b6c8-b73fea0c6827>
– Channel SIP/109-00000016 left ‘simple_bridge’ basic-bridge <16b5f0cf-5342-4e0a-9016-deaa4882a3ad>
– Channel DAHDI/2-1 left ‘simple_bridge’ basic-bridge <16b5f0cf-5342-4e0a-9016-deaa4882a3ad>
– Hanging up on ‘DAHDI/2-1’
– Hungup ‘DAHDI/2-1’
== Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘SIP/109-00000016’ in macro ‘dialout-trunk’
== Spawn extension (from-internal, 2007939, 8) exited non-zero on ‘SIP/109-00000016’
– Executing [h@from-internal:1] Macro(“SIP/109-00000016”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/109-00000016”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“SIP/109-00000016”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] Hangup(“SIP/109-00000016”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/109-00000016’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/109-00000016’
== Extension Changed 109[ext-local] new state Idle for Notify User 103
== Extension Changed 109[ext-local] new state Idle for Notify User 105
== Extension Changed 109[ext-local] new state Idle for Notify User 107
== Extension Changed 109[ext-local] new state Idle for Notify User 110
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Extension Changed 109[ext-local] new state InUse for Notify User 103
== Extension Changed 109[ext-local] new state InUse for Notify User 105
== Extension Changed 109[ext-local] new state InUse for Notify User 107
== Extension Changed 109[ext-local] new state InUse for Notify User 110
– Executing [8403419@from-internal:1] ResetCDR(“SIP/109-00000018”, “”) in new stack
– Executing [8403419@from-internal:2] NoCDR(“SIP/109-00000018”, “”) in new stack
– Executing [8403419@from-internal:3] Progress(“SIP/109-00000018”, “”) in new stack
– Executing [8403419@from-internal:4] Wait(“SIP/109-00000018”, “1”) in new stack
– Channel DAHDI/3-1 left ‘simple_bridge’ basic-bridge <170819f3-f919-408b-b6c8-b73fea0c6827>
– Hanging up on ‘DAHDI/3-1’
– Hungup ‘DAHDI/3-1’
– Channel SIP/107-00000017 left ‘simple_bridge’ basic-bridge <170819f3-f919-408b-b6c8-b73fea0c6827>
== Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘SIP/107-00000017’ in macro ‘dialout-trunk’
== Spawn extension (from-internal, 18009420854, 7) exited non-zero on ‘SIP/107-00000017’
– Executing [h@from-internal:1] Macro(“SIP/107-00000017”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/107-00000017”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“SIP/107-00000017”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] Hangup(“SIP/107-00000017”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/107-00000017’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/107-00000017’
== MixMonitor close filestream (mixed)
== Extension Changed 107[ext-local] new state Idle for Notify User 103
== Extension Changed 107[ext-local] new state Idle for Notify User 105
== Extension Changed 107[ext-local] new state Idle for Notify User 109
== Extension Changed 107[ext-local] new state Idle for Notify User 110
== End MixMonitor Recording SIP/107-00000017
– Executing [8403419@from-internal:5] Playback(“SIP/109-00000018”, “silence/1&cannot-complete-as-dialed&check-number-dial-again,noanswer”) in new stack
– <SIP/109-00000018> Playing ‘silence/1.ulaw’ (language ‘en’)
– <SIP/109-00000018> Playing ‘cannot-complete-as-dialed.ulaw’ (language ‘en’)
– <SIP/109-00000018> Playing ‘check-number-dial-again.ulaw’ (language ‘en’)
– Executing [8403419@from-internal:6] Wait(“SIP/109-00000018”, “1”) in new stack
– Executing [8403419@from-internal:7] Congestion(“SIP/109-00000018”, “20”) in new stack
[2016-09-20 14:46:09] WARNING[15841][C-00000019]: channel.c:4856 ast_prod: Prodding channel ‘SIP/109-00000018’ failed
== Spawn extension (from-internal, 8403419, 7) exited non-zero on ‘SIP/109-00000018’
– Executing [h@from-internal:1] Macro(“SIP/109-00000018”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/109-00000018”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“SIP/109-00000018”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] Hangup(“SIP/109-00000018”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/109-00000018’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/109-00000018’
== Extension Changed 109[ext-local] new state Idle for Notify User 103
== Extension Changed 109[ext-local] new state Idle for Notify User 105
== Extension Changed 109[ext-local] new state Idle for Notify User 107
== Extension Changed 109[ext-local] new state Idle for Notify User 110

Here is one more call that was hung up from on the PBX of a call that was hung up when the third “4” was repeaded by the the remote IVR:

[2016-03-01 11:36:00] VERBOSE[27063] pbx_spool.c: Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
[2016-03-01 11:36:00] VERBOSE[27064] dial.c: Called s@tc-maint
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [s@tc-maint:1] Set(“Local/s@tc-maint-0000713b;2”, “CDR_PROP(disable)=true”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [s@tc-maint:2] Set(“Local/s@tc-maint-0000713b;2”, “TCMAINT=RETURN”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-0000713b;2”, “timeconditions,2,1()”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:1] Set(“Local/s@tc-maint-0000713b;2”, “DB(TC/2/INUSESTATE)=INUSE”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:2] Set(“Local/s@tc-maint-0000713b;2”, “DB(TC/2/NOT_INUSESTATE)=NOT_INUSE”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:3] GotoIfTime(“Local/s@tc-maint-0000713b;2”, “08:00-17:00,mon-thu,,,America/New_York?truestate”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Goto (timeconditions,2,14)
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:14] GotoIf(“Local/s@tc-maint-0000713b;2”, “0?falsegoto”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:15] ExecIf(“Local/s@tc-maint-0000713b;2”, “0?Set(DB(TC/2)=)”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:16] Set(“Local/s@tc-maint-0000713b;2”, “DEVICE_STATE(Custom:TC2)=NOT_INUSE”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:17] ExecIf(“Local/s@tc-maint-0000713b;2”, “0?Set(NOT_INUSE)”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:18] GotoIf(“Local/s@tc-maint-0000713b;2”, “0?ext-group,600,1”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:19] Set(“Local/s@tc-maint-0000713b;2”, “TCSTATE=true”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:20] Set(“Local/s@tc-maint-0000713b;2”, “TCOVERRIDE=false”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [2@timeconditions:21] Return(“Local/s@tc-maint-0000713b;2”, “”) in new stack
[2016-03-01 11:36:00] VERBOSE[27065][C-00007687] pbx.c: Executing [s@tc-maint:4] System(“Local/s@tc-maint-0000713b;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1”) in new stack
[2016-03-01 11:36:01] VERBOSE[27065][C-00007687] pbx.c: Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-0000713b;2”, “”) in new stack
[2016-03-01 11:36:01] VERBOSE[27064] dial.c: Local/s@tc-maint-0000713b;1 answered
[2016-03-01 11:36:01] NOTICE[27063] pbx_spool.c: Call completed to Local/s@tc-maint
[2016-03-01 11:36:01] VERBOSE[27065][C-00007687] pbx.c: Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-0000713b;2’
[2016-03-01 11:36:36] VERBOSE[2766][C-00007688] netsock2.c: Using SIP RTP TOS bits 184
[2016-03-01 11:36:36] VERBOSE[2766][C-00007688] netsock2.c: Using SIP RTP CoS mark 5
[2016-03-01 11:36:36] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state InUse for Notify User 101
[2016-03-01 11:36:36] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state InUse for Notify User 104
[2016-03-01 11:36:36] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state InUse for Notify User 105
[2016-03-01 11:36:36] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state InUse for Notify User 103
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@from-internal:1] Macro(“SIP/102-00000b45”, “user-callerid,LIMIT”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/102-00000b45”, “TOUCH_MONITOR=1456850196.347274”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/102-00000b45”, “AMPUSER=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/102-00000b45”, “0?report”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/102-00000b45”, “1?Set(REALCALLERIDNUM=102)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/102-00000b45”, “AMPUSER=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:6] GotoIf(“SIP/102-00000b45”, “0?limit”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/102-00000b45”, “AMPUSERCIDNAME=Front Desk Backup”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/102-00000b45”, “0?report”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:9] Set(“SIP/102-00000b45”, “AMPUSERCID=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/102-00000b45”, “__DIAL_OPTIONS=Ttr”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:11] Set(“SIP/102-00000b45”, “CALLERID(all)=“Front Desk Backup” <102>”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:12] GotoIf(“SIP/102-00000b45”, “0?limit”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“SIP/102-00000b45”, “1?Set(GROUP(concurrency_limit)=102)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:14] ExecIf(“SIP/102-00000b45”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:15] GotoIf(“SIP/102-00000b45”, “1?continue”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (macro-user-callerid,s,29)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:29] Set(“SIP/102-00000b45”, “CALLERID(number)=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:30] Set(“SIP/102-00000b45”, “CALLERID(name)=Front Desk Backup”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:31] Set(“SIP/102-00000b45”, “CDR(cnum)=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:32] Set(“SIP/102-00000b45”, “CDR(cnam)=Front Desk Backup”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-user-callerid:33] Set(“SIP/102-00000b45”, “CHANNEL(language)=en”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@from-internal:2] Set(“SIP/102-00000b45”, “ROUTEUSER=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@from-internal:3] GotoIf(“SIP/102-00000b45”, “1?notblind”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (from-internal,18007530404,6)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@from-internal:6] GotoIf(“SIP/102-00000b45”, “1?restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,18007530404,2:outbound-allroutes,18007530404,2”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,18007530404,2)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:2] Gosub(“SIP/102-00000b45”, “sub-record-check,s,1(out,18007530404,dontcare)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/102-00000b45”, “0?initialized”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/102-00000b45”, “__REC_STATUS=INITIALIZED”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/102-00000b45”, “NOW=1456850196”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/102-00000b45”, “__DAY=01”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/102-00000b45”, “__MONTH=03”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/102-00000b45”, “__YEAR=2016”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/102-00000b45”, “__TIMESTR=20160301-113636”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/102-00000b45”, “__FROMEXTEN=102”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/102-00000b45”, “__MON_FMT=wav”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/102-00000b45”, “Recordings initialized”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/102-00000b45”, “0?Set(ARG3=dontcare)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/102-00000b45”, “REC_POLICY_MODE_SAVE=”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/102-00000b45”, “0?Set(REC_STATUS=NO)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/102-00000b45”, “3?checkaction”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (sub-record-check,s,17)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/102-00000b45”, “1?sub-record-check,out,1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (sub-record-check,out,1)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [out@sub-record-check:1] NoOp(“SIP/102-00000b45”, “Outbound Recording Check from 102 to 18007530404”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [out@sub-record-check:2] Set(“SIP/102-00000b45”, “RECMODE=dontcare”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [out@sub-record-check:3] ExecIf(“SIP/102-00000b45”, “1?Goto(routewins)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (sub-record-check,out,7)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [out@sub-record-check:7] Gosub(“SIP/102-00000b45”, “recordcheck,1(dontcare,out,18007530404)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/102-00000b45”, “Starting recording check against dontcare”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/102-00000b45”, “dontcare”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/102-00000b45”, “”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [out@sub-record-check:8] Return(“SIP/102-00000b45”, “”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:3] ExecIf(“SIP/102-00000b45”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:4] Set(“SIP/102-00000b45”, “ROUTE_CIDSAVE=“Front Desk Backup” <102>”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:5] Set(“SIP/102-00000b45”, “MOHCLASS=default”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:6] Set(“SIP/102-00000b45”, “_NODEST=”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [18007530404@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:7] Macro(“SIP/102-00000b45”, “dialout-trunk,1,18007530404,off”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:1] Set(“SIP/102-00000b45”, “DIAL_TRUNK=1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/102-00000b45”, “0?sub-pincheck,s,1()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/102-00000b45”, “0?disabletrunk,1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:4] Set(“SIP/102-00000b45”, “DIAL_NUMBER=18007530404”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:5] Set(“SIP/102-00000b45”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:6] Set(“SIP/102-00000b45”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/102-00000b45”, “1?nomax”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (macro-dialout-trunk,s,9)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/102-00000b45”, “0?skipoutcid”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:10] Set(“SIP/102-00000b45”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:11] Macro(“SIP/102-00000b45”, “outbound-callerid,1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERPRES(name-pres)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERPRES(num-pres)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:3] ExecIf(“SIP/102-00000b45”, “0?Set(REALCALLERIDNUM=102)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/102-00000b45”, “1?normcid”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (macro-outbound-callerid,s,7)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:7] Set(“SIP/102-00000b45”, “USEROUTCID=”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:8] Set(“SIP/102-00000b45”, “EMERGENCYCID=”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:9] Set(“SIP/102-00000b45”, “TRUNKOUTCID=9107546718”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:10] GotoIf(“SIP/102-00000b45”, “1?trunkcid”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Goto (macro-outbound-callerid,s,15)
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/102-00000b45”, “1?Set(CALLERID(all)=9107546718)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERID(all)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERID(all)=)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:18] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:19] ExecIf(“SIP/102-00000b45”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:20] Set(“SIP/102-00000b45”, “CDR(outbound_cnum)=9107546718”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-outbound-callerid:21] Set(“SIP/102-00000b45”, “CDR(outbound_cnam)=”) in new stack
[2016-03-01 11:36:36] WARNING[2677] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/102-00000b45”, “1?sub-flp-1,s,1()”) in new stack

More:

[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:1] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:2] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:3] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:4] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:5] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:6] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:7] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:8] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:9] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:10] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:11] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:12] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:13] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:14] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:15] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:16] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:17] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:18] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:19] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:20] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:21] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:22] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:23] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:24] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:25] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:26] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:27] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:28] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:29] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:30] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:31] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:32] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:33] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:34] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:35] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:36] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:37] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:38] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:39] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:40] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:41] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:42] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:43] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:44] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:45] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:46] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:47] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:48] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:49] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:50] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:51] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:52] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:53] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:54] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:55] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:56] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:57] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:58] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:59] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:60] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:61] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:62] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:63] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:64] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:65] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:66] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:67] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:68] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:69] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:70] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:71] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:72] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:73] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:74] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:75] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:76] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:77] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:78] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:79] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:80] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:81] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:82] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:83] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:84] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:85] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:86] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:87] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:88] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:89] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:90] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:91] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:92] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:93] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:94] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:95] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:96] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:97] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:98] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:99] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:100] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:101] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:102] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:103] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:104] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:105] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:106] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:107] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:108] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:109] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:110] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:111] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:112] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:113] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:114] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:115] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:116] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:117] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:118] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:119] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:120] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:121] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:122] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:123] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:124] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:125] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:126] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:127] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:128] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:129] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:130] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:131] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:132] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:133] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:134] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:135] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:136] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:137] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:138] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:139] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:140] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:141] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:142] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:143] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:144] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:145] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:146] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:147] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:148] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:149] ExecIf(“SIP/102-00000b45”, “0?Return()”) in new stack

More:

[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@sub-flp-1:150] Return(“SIP/102-00000b45”, “”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:13] Set(“SIP/102-00000b45”, “OUTNUM=18007530404”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:14] Set(“SIP/102-00000b45”, “custom=DAHDI/R0”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/102-00000b45”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/102-00000b45”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:17] Macro(“SIP/102-00000b45”, “dialout-trunk-predial-hook,”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/102-00000b45”, “”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/102-00000b45”, “0?bypass,1”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/102-00000b45”, “1?Set(CONNECTEDLINE(num,i)=18007530404)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/102-00000b45”, “1?Set(CONNECTEDLINE(name,i)=CID:9107546718)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:21] ExecIf(“SIP/102-00000b45”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)9107546718)”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:22] GotoIf(“SIP/102-00000b45”, “0?customtrunk”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] pbx.c: Executing [s@macro-dialout-trunk:23] Dial(“SIP/102-00000b45”, “DAHDI/R0/18007530404,300,Tt”) in new stack
[2016-03-01 11:36:36] VERBOSE[27119][C-00007688] app_dial.c: Called DAHDI/R0/18007530404
[2016-03-01 11:36:40] VERBOSE[27119][C-00007688] app_dial.c: DAHDI/2-1 answered SIP/102-00000b45
[2016-03-01 11:36:40] VERBOSE[27123][C-00007688] bridge_channel.c: Channel DAHDI/2-1 joined ‘simple_bridge’ basic-bridge <4e05ccd7-fa5f-472f-9050-a59a0dcc7a13>
[2016-03-01 11:36:40] VERBOSE[27119][C-00007688] bridge_channel.c: Channel SIP/102-00000b45 joined ‘simple_bridge’ basic-bridge <4e05ccd7-fa5f-472f-9050-a59a0dcc7a13>
[2016-03-01 11:37:00] VERBOSE[27125] pbx_spool.c: Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
[2016-03-01 11:37:00] VERBOSE[27126] dial.c: Called s@tc-maint
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [s@tc-maint:1] Set(“Local/s@tc-maint-0000713c;2”, “CDR_PROP(disable)=true”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [s@tc-maint:2] Set(“Local/s@tc-maint-0000713c;2”, “TCMAINT=RETURN”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-0000713c;2”, “timeconditions,2,1()”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:1] Set(“Local/s@tc-maint-0000713c;2”, “DB(TC/2/INUSESTATE)=INUSE”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:2] Set(“Local/s@tc-maint-0000713c;2”, “DB(TC/2/NOT_INUSESTATE)=NOT_INUSE”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:3] GotoIfTime(“Local/s@tc-maint-0000713c;2”, “08:00-17:00,mon-thu,,,America/New_York?truestate”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Goto (timeconditions,2,14)
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:14] GotoIf(“Local/s@tc-maint-0000713c;2”, “0?falsegoto”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:15] ExecIf(“Local/s@tc-maint-0000713c;2”, “0?Set(DB(TC/2)=)”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:16] Set(“Local/s@tc-maint-0000713c;2”, “DEVICE_STATE(Custom:TC2)=NOT_INUSE”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:17] ExecIf(“Local/s@tc-maint-0000713c;2”, “0?Set(NOT_INUSE)”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:18] GotoIf(“Local/s@tc-maint-0000713c;2”, “0?ext-group,600,1”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:19] Set(“Local/s@tc-maint-0000713c;2”, “TCSTATE=true”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:20] Set(“Local/s@tc-maint-0000713c;2”, “TCOVERRIDE=false”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [2@timeconditions:21] Return(“Local/s@tc-maint-0000713c;2”, “”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [s@tc-maint:4] System(“Local/s@tc-maint-0000713c;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0”) in new stack
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-0000713c;2”, “”) in new stack
[2016-03-01 11:37:00] VERBOSE[27126] dial.c: Local/s@tc-maint-0000713c;1 answered
[2016-03-01 11:37:00] VERBOSE[27127][C-00007689] pbx.c: Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-0000713c;2’
[2016-03-01 11:37:00] NOTICE[27125] pbx_spool.c: Call completed to Local/s@tc-maint
[2016-03-01 11:37:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:48] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:49] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 10
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:50] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:51] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:53] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:37:54] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:37:57] VERBOSE[2766][C-0000768a] netsock2.c: Using SIP RTP TOS bits 184
[2016-03-01 11:37:57] VERBOSE[2766][C-0000768a] netsock2.c: Using SIP RTP CoS mark 5
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 104
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 102
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 105
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 103
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [8402655@from-internal:1] Macro(“SIP/101-00000b46”, “user-callerid,LIMIT”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/101-00000b46”, “TOUCH_MONITOR=1456850277.347293”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/101-00000b46”, “AMPUSER=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/101-00000b46”, “0?report”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/101-00000b46”, “1?Set(REALCALLERIDNUM=101)”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/101-00000b46”, “AMPUSER=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:6] GotoIf(“SIP/101-00000b46”, “0?limit”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/101-00000b46”, “AMPUSERCIDNAME=Front Desk”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/101-00000b46”, “0?report”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:9] Set(“SIP/101-00000b46”, “AMPUSERCID=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/101-00000b46”, “__DIAL_OPTIONS=Ttr”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:11] Set(“SIP/101-00000b46”, “CALLERID(all)=“Front Desk” <101>”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:12] GotoIf(“SIP/101-00000b46”, “0?limit”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“SIP/101-00000b46”, “1?Set(GROUP(concurrency_limit)=101)”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:14] ExecIf(“SIP/101-00000b46”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:15] GotoIf(“SIP/101-00000b46”, “1?continue”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Goto (macro-user-callerid,s,29)
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:29] Set(“SIP/101-00000b46”, “CALLERID(number)=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:30] Set(“SIP/101-00000b46”, “CALLERID(name)=Front Desk”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:31] Set(“SIP/101-00000b46”, “CDR(cnum)=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:32] Set(“SIP/101-00000b46”, “CDR(cnam)=Front Desk”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [s@macro-user-callerid:33] Set(“SIP/101-00000b46”, “CHANNEL(language)=en”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [8402655@from-internal:2] Set(“SIP/101-00000b46”, “ROUTEUSER=101”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [8402655@from-internal:3] GotoIf(“SIP/101-00000b46”, “1?notblind”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Goto (from-internal,8402655,6)
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [8402655@from-internal:6] GotoIf(“SIP/101-00000b46”, “1?restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,8402655,2:outbound-allroutes,8402655,2”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Goto (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,8402655,2)
[2016-03-01 11:37:57] WARNING[27174][C-0000768a] pbx.c: Channel ‘SIP/101-00000b46’ sent to invalid extension but no invalid handler: context,exten,priority=restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,8402655,2
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Executing [h@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:1] Hangup(“SIP/101-00000b46”, “”) in new stack
[2016-03-01 11:37:57] VERBOSE[27174][C-0000768a] pbx.c: Spawn extension (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce, h, 1) exited non-zero on ‘SIP/101-00000b46’
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 104
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 102
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 105
[2016-03-01 11:37:57] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 103
[2016-03-01 11:38:00] VERBOSE[27179] pbx_spool.c: Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
[2016-03-01 11:38:00] VERBOSE[27180] dial.c: Called s@tc-maint
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [s@tc-maint:1] Set(“Local/s@tc-maint-0000713d;2”, “CDR_PROP(disable)=true”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [s@tc-maint:2] Set(“Local/s@tc-maint-0000713d;2”, “TCMAINT=RETURN”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-0000713d;2”, “timeconditions,2,1()”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:1] Set(“Local/s@tc-maint-0000713d;2”, “DB(TC/2/INUSESTATE)=INUSE”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:2] Set(“Local/s@tc-maint-0000713d;2”, “DB(TC/2/NOT_INUSESTATE)=NOT_INUSE”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:3] GotoIfTime(“Local/s@tc-maint-0000713d;2”, “08:00-17:00,mon-thu,,,America/New_York?truestate”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Goto (timeconditions,2,14)
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:14] GotoIf(“Local/s@tc-maint-0000713d;2”, “0?falsegoto”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:15] ExecIf(“Local/s@tc-maint-0000713d;2”, “0?Set(DB(TC/2)=)”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:16] Set(“Local/s@tc-maint-0000713d;2”, “DEVICE_STATE(Custom:TC2)=NOT_INUSE”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:17] ExecIf(“Local/s@tc-maint-0000713d;2”, “0?Set(NOT_INUSE)”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:18] GotoIf(“Local/s@tc-maint-0000713d;2”, “0?ext-group,600,1”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:19] Set(“Local/s@tc-maint-0000713d;2”, “TCSTATE=true”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:20] Set(“Local/s@tc-maint-0000713d;2”, “TCOVERRIDE=false”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [2@timeconditions:21] Return(“Local/s@tc-maint-0000713d;2”, “”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [s@tc-maint:4] System(“Local/s@tc-maint-0000713d;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1”) in new stack
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-0000713d;2”, “”) in new stack
[2016-03-01 11:38:00] VERBOSE[27180] dial.c: Local/s@tc-maint-0000713d;1 answered
[2016-03-01 11:38:00] NOTICE[27179] pbx_spool.c: Call completed to Local/s@tc-maint
[2016-03-01 11:38:00] VERBOSE[27181][C-0000768b] pbx.c: Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-0000713d;2’
[2016-03-01 11:38:20] VERBOSE[2766][C-0000768c] netsock2.c: Using SIP RTP TOS bits 184
[2016-03-01 11:38:20] VERBOSE[2766][C-0000768c] netsock2.c: Using SIP RTP CoS mark 5
[2016-03-01 11:38:20] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 104
[2016-03-01 11:38:20] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 102
[2016-03-01 11:38:20] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 105
[2016-03-01 11:38:20] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state InUse for Notify User 103
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@from-internal:1] Macro(“SIP/101-00000b47”, “user-callerid,LIMIT”) in new stack

More:

[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/101-00000b47”, “TOUCH_MONITOR=1456850300.347309”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/101-00000b47”, “AMPUSER=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/101-00000b47”, “0?report”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/101-00000b47”, “1?Set(REALCALLERIDNUM=101)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/101-00000b47”, “AMPUSER=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:6] GotoIf(“SIP/101-00000b47”, “0?limit”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/101-00000b47”, “AMPUSERCIDNAME=Front Desk”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“SIP/101-00000b47”, “0?report”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:9] Set(“SIP/101-00000b47”, “AMPUSERCID=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/101-00000b47”, “__DIAL_OPTIONS=Ttr”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:11] Set(“SIP/101-00000b47”, “CALLERID(all)=“Front Desk” <101>”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:12] GotoIf(“SIP/101-00000b47”, “0?limit”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“SIP/101-00000b47”, “1?Set(GROUP(concurrency_limit)=101)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:14] ExecIf(“SIP/101-00000b47”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:15] GotoIf(“SIP/101-00000b47”, “1?continue”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (macro-user-callerid,s,29)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:29] Set(“SIP/101-00000b47”, “CALLERID(number)=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:30] Set(“SIP/101-00000b47”, “CALLERID(name)=Front Desk”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:31] Set(“SIP/101-00000b47”, “CDR(cnum)=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:32] Set(“SIP/101-00000b47”, “CDR(cnam)=Front Desk”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-user-callerid:33] Set(“SIP/101-00000b47”, “CHANNEL(language)=en”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@from-internal:2] Set(“SIP/101-00000b47”, “ROUTEUSER=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@from-internal:3] GotoIf(“SIP/101-00000b47”, “1?notblind”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (from-internal,19108402655,6)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@from-internal:6] GotoIf(“SIP/101-00000b47”, “1?restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,19108402655,2:outbound-allroutes,19108402655,2”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce,19108402655,2)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:2] Gosub(“SIP/101-00000b47”, “sub-record-check,s,1(out,19108402655,dontcare)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/101-00000b47”, “0?initialized”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/101-00000b47”, “__REC_STATUS=INITIALIZED”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/101-00000b47”, “NOW=1456850300”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/101-00000b47”, “__DAY=01”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/101-00000b47”, “__MONTH=03”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/101-00000b47”, “__YEAR=2016”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/101-00000b47”, “__TIMESTR=20160301-113820”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/101-00000b47”, “__FROMEXTEN=101”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/101-00000b47”, “__MON_FMT=wav”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/101-00000b47”, “Recordings initialized”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/101-00000b47”, “0?Set(ARG3=dontcare)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/101-00000b47”, “REC_POLICY_MODE_SAVE=”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/101-00000b47”, “0?Set(REC_STATUS=NO)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/101-00000b47”, “3?checkaction”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (sub-record-check,s,17)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/101-00000b47”, “1?sub-record-check,out,1”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (sub-record-check,out,1)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [out@sub-record-check:1] NoOp(“SIP/101-00000b47”, “Outbound Recording Check from 101 to 19108402655”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [out@sub-record-check:2] Set(“SIP/101-00000b47”, “RECMODE=dontcare”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [out@sub-record-check:3] ExecIf(“SIP/101-00000b47”, “1?Goto(routewins)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (sub-record-check,out,7)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [out@sub-record-check:7] Gosub(“SIP/101-00000b47”, “recordcheck,1(dontcare,out,19108402655)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/101-00000b47”, “Starting recording check against dontcare”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/101-00000b47”, “dontcare”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/101-00000b47”, “”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [out@sub-record-check:8] Return(“SIP/101-00000b47”, “”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:3] ExecIf(“SIP/101-00000b47”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:4] Set(“SIP/101-00000b47”, “ROUTE_CIDSAVE=“Front Desk” <101>”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:5] Set(“SIP/101-00000b47”, “MOHCLASS=default”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:6] Set(“SIP/101-00000b47”, “_NODEST=”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [19108402655@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:7] Macro(“SIP/101-00000b47”, “dialout-trunk,1,19108402655,off”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:1] Set(“SIP/101-00000b47”, “DIAL_TRUNK=1”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/101-00000b47”, “0?sub-pincheck,s,1()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/101-00000b47”, “0?disabletrunk,1”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:4] Set(“SIP/101-00000b47”, “DIAL_NUMBER=19108402655”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:5] Set(“SIP/101-00000b47”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:6] Set(“SIP/101-00000b47”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/101-00000b47”, “1?nomax”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (macro-dialout-trunk,s,9)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/101-00000b47”, “0?skipoutcid”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:10] Set(“SIP/101-00000b47”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:11] Macro(“SIP/101-00000b47”, “outbound-callerid,1”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERPRES(name-pres)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERPRES(num-pres)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:3] ExecIf(“SIP/101-00000b47”, “0?Set(REALCALLERIDNUM=101)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/101-00000b47”, “1?normcid”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (macro-outbound-callerid,s,7)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:7] Set(“SIP/101-00000b47”, “USEROUTCID=”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:8] Set(“SIP/101-00000b47”, “EMERGENCYCID=”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:9] Set(“SIP/101-00000b47”, “TRUNKOUTCID=9107546718”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:10] GotoIf(“SIP/101-00000b47”, “1?trunkcid”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Goto (macro-outbound-callerid,s,15)
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/101-00000b47”, “1?Set(CALLERID(all)=9107546718)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERID(all)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERID(all)=)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:18] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:19] ExecIf(“SIP/101-00000b47”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:20] Set(“SIP/101-00000b47”, “CDR(outbound_cnum)=9107546718”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-outbound-callerid:21] Set(“SIP/101-00000b47”, “CDR(outbound_cnam)=”) in new stack
[2016-03-01 11:38:20] WARNING[2677] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/101-00000b47”, “1?sub-flp-1,s,1()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:1] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:2] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:3] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:4] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:5] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:6] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:7] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:8] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:20] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:9] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:10] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:11] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:12] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:13] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:14] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:15] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:16] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:17] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:18] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:19] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:20] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:21] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:22] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:23] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:24] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:25] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:26] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:27] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:28] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:29] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:30] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:31] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:32] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:33] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:34] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:35] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:36] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:37] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:38] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:39] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:40] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:41] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:42] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:43] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:44] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:45] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:46] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:47] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:48] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:49] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:50] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:51] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:52] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:53] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:54] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:55] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:56] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:57] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:58] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:59] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:60] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:61] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:62] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:63] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:64] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:65] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:66] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:67] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:68] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:69] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:70] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:71] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:72] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:73] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:74] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:75] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:76] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:77] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:78] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:79] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:80] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:81] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:82] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:83] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:84] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:85] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:86] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:87] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:88] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:89] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:90] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:91] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:92] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:93] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:94] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:95] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:96] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:97] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:98] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:99] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:100] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack

More:

[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:101] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:102] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:103] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:104] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:105] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:106] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:107] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:108] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:109] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:110] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:111] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:112] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:113] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:114] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:115] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:116] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:117] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:118] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:119] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:120] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:121] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:122] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:123] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:124] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:125] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:126] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:127] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:128] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:129] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:130] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:131] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:132] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:133] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:134] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:135] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:136] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:137] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:138] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:139] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:140] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:141] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:142] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:143] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:144] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:145] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:146] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:147] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:148] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:149] ExecIf(“SIP/101-00000b47”, “0?Return()”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@sub-flp-1:150] Return(“SIP/101-00000b47”, “”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:13] Set(“SIP/101-00000b47”, “OUTNUM=19108402655”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:14] Set(“SIP/101-00000b47”, “custom=DAHDI/R0”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/101-00000b47”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/101-00000b47”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:17] Macro(“SIP/101-00000b47”, “dialout-trunk-predial-hook,”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/101-00000b47”, “”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/101-00000b47”, “0?bypass,1”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/101-00000b47”, “1?Set(CONNECTEDLINE(num,i)=19108402655)”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/101-00000b47”, “1?Set(CONNECTEDLINE(name,i)=CID:9107546718)”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:21] ExecIf(“SIP/101-00000b47”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)9107546718)”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:22] GotoIf(“SIP/101-00000b47”, “0?customtrunk”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] pbx.c: Executing [s@macro-dialout-trunk:23] Dial(“SIP/101-00000b47”, “DAHDI/R0/19108402655,300,Tt”) in new stack
[2016-03-01 11:38:21] VERBOSE[27235][C-0000768c] app_dial.c: Called DAHDI/R0/19108402655
[2016-03-01 11:38:24] VERBOSE[27235][C-0000768c] app_dial.c: DAHDI/4-1 answered SIP/101-00000b47
[2016-03-01 11:38:24] VERBOSE[27236][C-0000768c] bridge_channel.c: Channel DAHDI/4-1 joined ‘simple_bridge’ basic-bridge <38ac807a-2735-42c0-a747-4edac04ffc9f>
[2016-03-01 11:38:24] VERBOSE[27235][C-0000768c] bridge_channel.c: Channel SIP/101-00000b47 joined ‘simple_bridge’ basic-bridge <38ac807a-2735-42c0-a747-4edac04ffc9f>
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Encountered corrupt speex frame; too many wideband frames in a row.
[2016-03-01 11:38:25] WARNING[27119][C-00007688] codec_builtin.c: Had error while reading wideband frames for speex samples
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:26] WARNING[27119][C-00007688] codec_builtin.c: Unknown speex control frame 12
[2016-03-01 11:38:37] VERBOSE[27123][C-00007688] bridge_channel.c: Channel DAHDI/2-1 left ‘simple_bridge’ basic-bridge <4e05ccd7-fa5f-472f-9050-a59a0dcc7a13>
[2016-03-01 11:38:37] VERBOSE[27123][C-00007688] sig_analog.c: Hanging up on ‘DAHDI/2-1’
[2016-03-01 11:38:37] VERBOSE[27123][C-00007688] chan_dahdi.c: Hungup ‘DAHDI/2-1’
[2016-03-01 11:38:37] VERBOSE[27119][C-00007688] bridge_channel.c: Channel SIP/102-00000b45 left ‘simple_bridge’ basic-bridge <4e05ccd7-fa5f-472f-9050-a59a0dcc7a13>
[2016-03-01 11:38:37] VERBOSE[27119][C-00007688] app_macro.c: Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘SIP/102-00000b45’ in macro ‘dialout-trunk’
[2016-03-01 11:38:37] VERBOSE[27119][C-00007688] pbx.c: Spawn extension (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce, 18007530404, 7) exited non-zero on ‘SIP/102-00000b45’
[2016-03-01 11:38:37] VERBOSE[27119][C-00007688] pbx.c: Executing [h@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:1] Hangup(“SIP/102-00000b45”, “”) in new stack
[2016-03-01 11:38:37] VERBOSE[27119][C-00007688] pbx.c: Spawn extension (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce, h, 1) exited non-zero on ‘SIP/102-00000b45’
[2016-03-01 11:38:37] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state Idle for Notify User 101
[2016-03-01 11:38:37] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state Idle for Notify User 104
[2016-03-01 11:38:37] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state Idle for Notify User 105
[2016-03-01 11:38:37] VERBOSE[2678] chan_sip.c: Extension Changed 102[ext-local] new state Idle for Notify User 103
[2016-03-01 11:39:00] VERBOSE[27255] pbx_spool.c: Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
[2016-03-01 11:39:00] VERBOSE[27256] dial.c: Called s@tc-maint
[2016-03-01 11:39:00] VERBOSE[27257][C-0000768d] pbx.c: Executing [s@tc-maint:1] Set(“Local/s@tc-maint-0000713e;2”, “CDR_PROP(disable)=true”) in new stack
[2016-03-01 11:39:00] VERBOSE[27257][C-0000768d] pbx.c: Executing [s@tc-maint:2] Set(“Local/s@tc-maint-0000713e;2”, “TCMAINT=RETURN”) in new stack
[2016-03-01 11:39:00] VERBOSE[27257][C-0000768d] pbx.c: Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-0000713e;2”, “timeconditions,2,1()”) in new stack
[2016-03-01 11:39:00] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:1] Set(“Local/s@tc-maint-0000713e;2”, “DB(TC/2/INUSESTATE)=INUSE”) in new stack
[2016-03-01 11:39:00] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:2] Set(“Local/s@tc-maint-0000713e;2”, “DB(TC/2/NOT_INUSESTATE)=NOT_INUSE”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:3] GotoIfTime(“Local/s@tc-maint-0000713e;2”, “08:00-17:00,mon-thu,,,America/New_York?truestate”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Goto (timeconditions,2,14)
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:14] GotoIf(“Local/s@tc-maint-0000713e;2”, “0?falsegoto”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:15] ExecIf(“Local/s@tc-maint-0000713e;2”, “0?Set(DB(TC/2)=)”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:16] Set(“Local/s@tc-maint-0000713e;2”, “DEVICE_STATE(Custom:TC2)=NOT_INUSE”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:17] ExecIf(“Local/s@tc-maint-0000713e;2”, “0?Set(NOT_INUSE)”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:18] GotoIf(“Local/s@tc-maint-0000713e;2”, “0?ext-group,600,1”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:19] Set(“Local/s@tc-maint-0000713e;2”, “TCSTATE=true”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:20] Set(“Local/s@tc-maint-0000713e;2”, “TCOVERRIDE=false”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [2@timeconditions:21] Return(“Local/s@tc-maint-0000713e;2”, “”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [s@tc-maint:4] System(“Local/s@tc-maint-0000713e;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0”) in new stack
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-0000713e;2”, “”) in new stack
[2016-03-01 11:39:01] VERBOSE[27256] dial.c: Local/s@tc-maint-0000713e;1 answered
[2016-03-01 11:39:01] NOTICE[27255] pbx_spool.c: Call completed to Local/s@tc-maint
[2016-03-01 11:39:01] VERBOSE[27257][C-0000768d] pbx.c: Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-0000713e;2’
[2016-03-01 11:39:07] VERBOSE[27235][C-0000768c] bridge_channel.c: Channel SIP/101-00000b47 left ‘simple_bridge’ basic-bridge <38ac807a-2735-42c0-a747-4edac04ffc9f>
[2016-03-01 11:39:07] VERBOSE[27235][C-0000768c] app_macro.c: Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on ‘SIP/101-00000b47’ in macro ‘dialout-trunk’
[2016-03-01 11:39:07] VERBOSE[27235][C-0000768c] pbx.c: Spawn extension (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce, 19108402655, 7) exited non-zero on ‘SIP/101-00000b47’
[2016-03-01 11:39:07] VERBOSE[27235][C-0000768c] pbx.c: Executing [h@restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce:1] Hangup(“SIP/101-00000b47”, “”) in new stack
[2016-03-01 11:39:07] VERBOSE[27235][C-0000768c] pbx.c: Spawn extension (restrictedroute-40340efc2dd8c5d22ae776d1d451f0ce, h, 1) exited non-zero on ‘SIP/101-00000b47’
[2016-03-01 11:39:07] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 104
[2016-03-01 11:39:07] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 102
[2016-03-01 11:39:07] VERBOSE[27236][C-0000768c] bridge_channel.c: Channel DAHDI/4-1 left ‘simple_bridge’ basic-bridge <38ac807a-2735-42c0-a747-4edac04ffc9f>
[2016-03-01 11:39:07] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 105
[2016-03-01 11:39:07] VERBOSE[2678] chan_sip.c: Extension Changed 101[ext-local] new state Idle for Notify User 103
[2016-03-01 11:39:07] VERBOSE[27236][C-0000768c] sig_analog.c: Hanging up on ‘DAHDI/4-1’
[2016-03-01 11:39:07] VERBOSE[27236][C-0000768c] chan_dahdi.c: Hungup ‘DAHDI/4-1’
[2016-03-01 11:40:00] VERBOSE[27313] pbx_spool.c: Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)