[Dec 4 22:33:26] Asterisk 11.20.0 built by asterisk @ asterisk.astmachine on a x86_64 running Linux on 2015-11-06 23:15:37 UTC [Dec 4 22:33:26] VERBOSE[25013] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Dec 4 22:33:26] VERBOSE[25013] logger.c: Asterisk Queue Logger restarted [Dec 4 22:33:26] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:27] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:28] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:29] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:30] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:31] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:32] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:33] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:34] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:35] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:36] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:37] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:38] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:39] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:40] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:41] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:42] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:43] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:44] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:45] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:46] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:47] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:47] DEBUG[24999] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 1 [Dec 4 22:33:47] DEBUG[24999] sig_analog.c: channel (1) - signaling (2) - event (ANALOG_EVENT_RINGOFFHOOK) [Dec 4 22:33:47] DEBUG[24999][C-00000004] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Dec 4 22:33:47] DEBUG[24999][C-00000004] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Dec 4 22:33:47] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for DAHDI - 1 [Dec 4 22:33:47] DEBUG[24989] devicestate.c: Changing state for DAHDI/1 - state 2 (In use) [Dec 4 22:33:47] DEBUG[24989] devicestate.c: device 'DAHDI/1' state '2' [Dec 4 22:33:47] DEBUG[25011] app_queue.c: Device 'DAHDI/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 22:33:47] DEBUG[25086] sig_analog.c: __analog_ss_thread 1 [Dec 4 22:33:47] VERBOSE[25086][C-00000004] sig_analog.c: -- Starting simple switch on 'DAHDI/1-1' [Dec 4 22:33:48] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:49] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:49] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:49] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF begin '2' received on DAHDI/1-1 [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '2' on DAHDI/1-1 [Dec 4 22:33:49] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:49] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF end '2' received on DAHDI/1-1, duration 165 ms [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '2' on DAHDI/1-1 [Dec 4 22:33:49] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '2' (50), timeout = 0 [Dec 4 22:33:49] DEBUG[25086][C-00000004] features.c: Checking if 2@internal is a parking exten [Dec 4 22:33:49] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x35 '5' on DAHDI/1-1 [Dec 4 22:33:49] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x35 '5' on DAHDI/1-1 [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF begin '5' received on DAHDI/1-1 [Dec 4 22:33:49] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '5' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x35 '5' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x35 '5' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end '5' received on DAHDI/1-1, duration 178 ms [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '5' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '5' (53), timeout = 0 [Dec 4 22:33:50] DEBUG[25086][C-00000004] features.c: Checking if 25@internal is a parking exten [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin '6' received on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '6' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end '6' received on DAHDI/1-1, duration 178 ms [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '6' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '6' (54), timeout = 0 [Dec 4 22:33:50] DEBUG[25086][C-00000004] features.c: Checking if 256@internal is a parking exten [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x34 '4' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x34 '4' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin '4' received on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '4' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x34 '4' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x34 '4' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end '4' received on DAHDI/1-1, duration 165 ms [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '4' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '4' (52), timeout = 0 [Dec 4 22:33:50] DEBUG[25086][C-00000004] features.c: Checking if 2564@internal is a parking exten [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin '2' received on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '2' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end '2' received on DAHDI/1-1, duration 165 ms [Dec 4 22:33:50] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '2' on DAHDI/1-1 [Dec 4 22:33:50] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '2' (50), timeout = 0 [Dec 4 22:33:50] DEBUG[25086][C-00000004] features.c: Checking if 25642@internal is a parking exten [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x38 '8' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x38 '8' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin '8' received on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '8' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x38 '8' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x38 '8' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end '8' received on DAHDI/1-1, duration 165 ms [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '8' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '8' (56), timeout = 0 [Dec 4 22:33:51] DEBUG[25086][C-00000004] features.c: Checking if 256428@internal is a parking exten [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin '6' received on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end '6' received on DAHDI/1-1, duration 178 ms [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '6' (54), timeout = 0 [Dec 4 22:33:51] DEBUG[25086][C-00000004] features.c: Checking if 2564286@internal is a parking exten [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin '2' received on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '2' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end '2' received on DAHDI/1-1, duration 178 ms [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '2' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '2' (50), timeout = 0 [Dec 4 22:33:51] DEBUG[25086][C-00000004] features.c: Checking if 25642862@internal is a parking exten [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin '6' received on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x36 '6' on DAHDI/1-1 [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end '6' received on DAHDI/1-1, duration 178 ms [Dec 4 22:33:51] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '6' on DAHDI/1-1 [Dec 4 22:33:51] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '6' (54), timeout = 0 [Dec 4 22:33:51] DEBUG[25086][C-00000004] features.c: Checking if 256428626@internal is a parking exten [Dec 4 22:33:52] DEBUG[25086][C-00000004] sig_analog.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: Begin DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:52] DTMF[25086][C-00000004] channel.c: DTMF begin '2' received on DAHDI/1-1 [Dec 4 22:33:52] DTMF[25086][C-00000004] channel.c: DTMF begin ignored '2' on DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] sig_analog.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: End DTMF digit: 0x32 '2' on DAHDI/1-1 [Dec 4 22:33:52] DTMF[25086][C-00000004] channel.c: DTMF end '2' received on DAHDI/1-1, duration 165 ms [Dec 4 22:33:52] DTMF[25086][C-00000004] channel.c: DTMF end passthrough '2' on DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] sig_analog.c: waitfordigit returned '2' (50), timeout = 0 [Dec 4 22:33:52] DEBUG[25086][C-00000004] features.c: Checking if 2564286262@internal is a parking exten [Dec 4 22:33:52] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for DAHDI - 1 [Dec 4 22:33:52] DEBUG[24989] devicestate.c: Changing state for DAHDI/1 - state 2 (In use) [Dec 4 22:33:52] DEBUG[24989] devicestate.c: device 'DAHDI/1' state '2' [Dec 4 22:33:52] DEBUG[25011] app_queue.c: Device 'DAHDI/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: Enabled echo cancellation on channel 1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Answer' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [2564286262@internal:1] Answer("DAHDI/1-1", "") in new stack [Dec 4 22:33:52] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for DAHDI - 1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] sig_analog.c: analog_answer 1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] sig_analog.c: Took DAHDI/1-1 off hook [Dec 4 22:33:52] DEBUG[24989] devicestate.c: Changing state for DAHDI/1 - state 2 (In use) [Dec 4 22:33:52] DEBUG[24989] devicestate.c: device 'DAHDI/1' state '2' [Dec 4 22:33:52] DEBUG[25011] app_queue.c: Device 'DAHDI/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: Requested indication -1 on channel DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'NoOp' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [2564286262@internal:2] NoOp("DAHDI/1-1", "this is outbound-long-distance context") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'EXTEN' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'Preferred-Out' is 'DAHDI/4' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Gosub' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [2564286262@internal:3] Gosub("DAHDI/1-1", "DialOut,s,1(2564286262,DAHDI/4)") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] app_stack.c: Channel DAHDI/1-1 has no datastore, so we're allocating one. [Dec 4 22:33:52] DEBUG[25086][C-00000004] app_stack.c: Setting 'ARG1' to '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] app_stack.c: Setting 'ARG2' to 'DAHDI/4' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG2' is 'DAHDI/4' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'NoOp' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:1] NoOp("DAHDI/1-1", "Context: DialOut called with outgoing number 2564286262, and Preferred-Out=DAHDI/4") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Set' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:2] Set("DAHDI/1-1", "CALLERID(name-pres)=allowed") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'EPOCH' is '1449286432' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Function STRFTIME(1449286432,,%m/%e/%Y-%H:%M:%S) result is '12/ 4/2015-22:33:52' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Set' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:3] Set("DAHDI/1-1", "Time=12/ 4/2015-22:33:52 ") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'NoOp' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:4] NoOp("DAHDI/1-1", "4286262") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Expression result is '0' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'GotoIf' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:5] GotoIf("DAHDI/1-1", "0?International011") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Not taking any branch [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Expression result is '0' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'GotoIf' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:6] GotoIf("DAHDI/1-1", "0?International+") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Not taking any branch [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Expression result is '0' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'GotoIf' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:7] GotoIf("DAHDI/1-1", "0?Caribbean") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Not taking any branch [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG2' is 'DAHDI/4' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Expression result is '0' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'GotoIf' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:8] GotoIf("DAHDI/1-1", "0?Teliax:PSTN") in new stack [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Goto (DialOut,s,12) [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Goto' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:12] Goto("DAHDI/1-1", "gv") in new stack [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Goto (DialOut,s,14) [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'MOTIF_DEFAULT' is '8447' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Result of 'ARG1' is '2564286262' [Dec 4 22:33:52] DEBUG[25086][C-00000004] pbx.c: Launching 'Dial' [Dec 4 22:33:52] VERBOSE[25086][C-00000004] pbx.c: -- Executing [s@DialOut:14] Dial("DAHDI/1-1", "motif/8447/+12564286262@voice.google.com,,r") in new stack [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '0.0.0.0' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '0.0.0.0' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fa070008848' [Dec 4 22:33:52] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Allocated port 12690 for RTP instance '0x7fa070008848' [Dec 4 22:33:52] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:12690 (12690) for RTP instance '0x7fa070008848' [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '10.10.11.180' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '10.10.11.180' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '192.168.122.1' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '192.168.122.1' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '32.212.153.183' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '32.212.153.183' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '10.10.11.180' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '10.10.11.180' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] rtp_engine.c: RTP instance '0x7fa070008848' is setup and ready to go [Dec 4 22:33:52] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fa070008848' [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '10.10.11.180' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '10.10.11.180' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '192.168.122.1' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '192.168.122.1' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '32.212.153.183' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '32.212.153.183' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: Splitting '10.10.11.180' into... [Dec 4 22:33:52] DEBUG[25086][C-00000004] netsock2.c: ...host '10.10.11.180' and port ''. [Dec 4 22:33:52] DEBUG[25086][C-00000004] channel_internal_api.c: Channel Call ID changing from [C-00000004] to [C-00000004] [Dec 4 22:33:52] DEBUG[25086][C-00000004] rtp_engine.c: Can't find native functions for channel 'DAHDI/1-1' [Dec 4 22:33:52] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for Motif - +12564286262@voice.google.com [Dec 4 22:33:52] DEBUG[24989] devicestate.c: Changing state for Motif/+12564286262@voice.google.com - state 2 (In use) [Dec 4 22:33:52] DEBUG[24989] devicestate.c: device 'Motif/+12564286262@voice.google.com' state '2' [Dec 4 22:33:52] DEBUG[25011] app_queue.c: Device 'Motif/+12564286262@voice.google.com' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 22:33:52] VERBOSE[25086][C-00000004] app_dial.c: -- Called motif/8447/+12564286262@voice.google.com [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1 [Dec 4 22:33:52] DEBUG[25086][C-00000004] chan_dahdi.c: Requested indication 22 on channel DAHDI/1-1 [Dec 4 22:33:52] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:33:52] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:33:52] VERBOSE[25086][C-00000004] app_dial.c: -- Motif/+12564286262@voice.google.com-b53e is proceeding passing it to DAHDI/1-1 [Dec 4 22:33:52] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: Splitting '74.125.39.26' into... [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: ...host '74.125.39.26' and port ''. [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: Splitting '74.125.39.26' into... [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: ...host '74.125.39.26' and port ''. [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: Splitting '74.125.39.26' into... [Dec 4 22:33:52] DEBUG[24996][C-00000004] netsock2.c: ...host '74.125.39.26' and port ''. [Dec 4 22:33:52] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:33:52] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fa070008848' [Dec 4 22:33:53] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:54] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:55] DEBUG[24996][C-00000004] rtp_engine.c: Setting payload 0 based on m type on 0x7fa076e31290 [Dec 4 22:33:55] DEBUG[24996][C-00000004] rtp_engine.c: Setting payload 101 based on m type on 0x7fa076e31290 [Dec 4 22:33:55] DEBUG[24996][C-00000004] rtp_engine.c: Copying payload 0 from 0x7fa076e31290 to 0x7fa070008a10 [Dec 4 22:33:55] DEBUG[24996][C-00000004] rtp_engine.c: Copying payload 101 from 0x7fa076e31290 to 0x7fa070008a10 [Dec 4 22:33:55] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:33:55] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for Motif - +12564286262@voice.google.com [Dec 4 22:33:55] DEBUG[24989] devicestate.c: Changing state for Motif/+12564286262@voice.google.com - state 2 (In use) [Dec 4 22:33:55] DEBUG[24989] devicestate.c: device 'Motif/+12564286262@voice.google.com' state '2' [Dec 4 22:33:55] DEBUG[25011] app_queue.c: Device 'Motif/+12564286262@voice.google.com' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 22:33:55] VERBOSE[25086][C-00000004] app_dial.c: -- Motif/+12564286262@voice.google.com-b53e answered DAHDI/1-1 [Dec 4 22:33:55] DEBUG[25086][C-00000004] chan_dahdi.c: Requested indication -1 on channel DAHDI/1-1 [Dec 4 22:33:55] DEBUG[25086][C-00000004] features.c: bridge answer set, chan answer set [Dec 4 22:33:55] DEBUG[25086][C-00000004] features.c: Removing dialed interfaces datastore on Motif/+12564286262@voice.google.com-b53e since we're bridging [Dec 4 22:33:55] DEBUG[25086][C-00000004] chan_dahdi.c: Requested indication 20 on channel DAHDI/1-1 [Dec 4 22:33:55] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Setting the marker bit due to a source update [Dec 4 22:33:55] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Dec 4 22:33:55] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Dec 4 22:33:55] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7fa070008848' [Dec 4 22:33:55] DEBUG[25086][C-00000004] res_rtp_asterisk.c: 0x7fa07000cd90 -- Probation learning mode pass with source address 74.125.39.26:19305 [Dec 4 22:33:56] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:57] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:58] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:33:59] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:00] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:01] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:02] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:03] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:03] DEBUG[25086][C-00000004] chan_dahdi.c: Write returned -1 (Unknown error 500) on channel 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: analog_exception 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: Exception on 10, channel 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: __analog_handle_event 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: Got event ANALOG_EVENT_ONHOOK(1) on channel 1 (index 0) [Dec 4 22:34:03] DEBUG[25086][C-00000004] chan_dahdi.c: Disabled echo cancellation on channel 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] channel.c: Didn't get a frame from channel: DAHDI/1-1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Setting the marker bit due to a source update [Dec 4 22:34:03] DEBUG[25086][C-00000004] channel.c: Bridge stops bridging channels DAHDI/1-1 and Motif/+12564286262@voice.google.com-b53e [Dec 4 22:34:03] DEBUG[25086][C-00000004] channel.c: Hanging up channel 'Motif/+12564286262@voice.google.com-b53e' [Dec 4 22:34:03] DEBUG[25086][C-00000004] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fa070008848' [Dec 4 22:34:03] DEBUG[25086][C-00000004] rtp_engine.c: Destroyed RTP instance '0x7fa070008848' [Dec 4 22:34:03] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for Motif - +12564286262@voice.google.com [Dec 4 22:34:03] DEBUG[24989] devicestate.c: Changing state for Motif/+12564286262@voice.google.com - state 0 (Unknown) [Dec 4 22:34:03] DEBUG[24989] devicestate.c: device 'Motif/+12564286262@voice.google.com' state '0' [Dec 4 22:34:03] DEBUG[25011] app_queue.c: Device 'Motif/+12564286262@voice.google.com' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 22:34:03] DEBUG[25086][C-00000004] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Dec 4 22:34:03] DEBUG[25086][C-00000004] pbx.c: Spawn extension (DialOut,s,14) exited non-zero on 'DAHDI/1-1' [Dec 4 22:34:03] VERBOSE[25086][C-00000004] pbx.c: == Spawn extension (DialOut, s, 14) exited non-zero on 'DAHDI/1-1' [Dec 4 22:34:03] DEBUG[25086][C-00000004] channel.c: Soft-Hanging up channel 'DAHDI/1-1' [Dec 4 22:34:03] DEBUG[25086][C-00000004] channel.c: Hanging up channel 'DAHDI/1-1' [Dec 4 22:34:03] DEBUG[25086][C-00000004] chan_dahdi.c: dahdi_hangup(DAHDI/1-1) [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: analog_hangup 1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: Hangup: channel: 1 index = 0, normal = 1, callwait = 0, thirdcall = 0 [Dec 4 22:34:03] DEBUG[25086][C-00000004] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/1-1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/1-1 [Dec 4 22:34:03] DEBUG[25086][C-00000004] sig_analog.c: Updated conferencing on 1, with 0 conference users [Dec 4 22:34:03] VERBOSE[25086][C-00000004] sig_analog.c: -- Hanging up on 'DAHDI/1-1' [Dec 4 22:34:03] VERBOSE[25086][C-00000004] chan_dahdi.c: -- Hungup 'DAHDI/1-1' [Dec 4 22:34:03] DEBUG[24989] devicestate.c: No provider found, checking channel drivers for DAHDI - 1 [Dec 4 22:34:03] DEBUG[24989] devicestate.c: Changing state for DAHDI/1 - state 0 (Unknown) [Dec 4 22:34:03] DEBUG[24989] devicestate.c: device 'DAHDI/1' state '0' [Dec 4 22:34:03] DEBUG[25011] app_queue.c: Device 'DAHDI/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 22:34:03] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:34:04] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:05] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:07] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:07] Asterisk 11.20.0 built by asterisk @ asterisk.astmachine on a x86_64 running Linux on 2015-11-06 23:15:37 UTC [Dec 4 22:34:07] DEBUG[25013] config.c: Parsing /etc/asterisk/logger.conf [Dec 4 22:34:07] VERBOSE[25013] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Dec 4 22:34:07] VERBOSE[25013] logger.c: Asterisk Queue Logger restarted [Dec 4 22:34:08] DEBUG[24996] res_xmpp.c: JABBER: Sending Keep-Alive Ping for client '2538447' [Dec 4 22:34:08] DEBUG[24996] res_xmpp.c: XML parsing successful [Dec 4 22:34:09] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:10] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:11] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:12] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:13] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:14] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:15] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:16] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:17] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:18] DEBUG[24996] res_xmpp.c: JABBER: Unknown [Dec 4 22:34:19] DEBUG[24996] res_xmpp.c: JABBER: Unknown