[Apr 29 10:11:34] DEBUG[8787]: manager.c:5204 process_message: Running action 'Originate' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4529 pbx_substitute_variables_helper_full: Expression result is '0' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'GotoIf' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:11555 pbx_builtin_gotoif: Not taking any branch [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: func_lock.c:228 get_lock: Channel Local/19544447408@onsite-0000335e;2 has no lock datastore, so we're allocating one. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4529 pbx_substitute_variables_helper_full: Expression result is '1' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'GotoIf' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:11555 pbx_builtin_gotoif: Not taking any branch [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Verbose' Locked 1 Channel Using 141 Data 142,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53,54,55,56,57,58,59,60,61,62,63,64,65,66,67,68,69,70,71,72,73,74,75,76,77,78,79,80,81,82,83,84,85,86,87,88,89,90,91,92,93,94,95,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110,111,112,113,114,115,116,117,118,119,120,121,122,123,124,125,126,127,128,129,130,131,132,133,134,135,136,137,138,139,140 [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Dial' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f15f94790b8' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: res_rtp_asterisk.c:1748 ast_rtp_new: Allocated port 20882 for RTP instance '0x7f15f94790b8' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7f15f94790b8' is setup and ready to go [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: res_rtp_asterisk.c:3876 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f15f94790b8' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: rtp_engine.c:1650 ast_rtp_instance_early_bridge_make_compatible: Can't find native functions for channel 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable Target. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable R. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable var. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message2. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd2. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message3. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd3. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable campaign. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable phonenumber. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable recordid. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable transferclid. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable did. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable queuename. [Apr 29 10:11:34] DEBUG[9054][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable trunk-did. [Apr 29 10:11:36] DEBUG[9054][C-00002e7d]: res_rtp_asterisk.c:3921 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f15f94790b8' [Apr 29 10:11:47] DEBUG[22773][C-00002e7d]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x7f15e3a9e0b0 [Apr 29 10:11:47] DEBUG[22773][C-00002e7d]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7f15e3a9e0b0 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:5361 set_format: Set channel Motif/19544447408@voice.google.com-25e4 to write format slin [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:5361 set_format: Set channel Motif/19544447408@voice.google.com-25e4 to read format slin [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: features.c:4240 clear_dialed_interfaces: Removing dialed interfaces datastore on Motif/19544447408@voice.google.com-25e4 since we're bridging [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:6666 ast_set_owners_and_peers: setting peeraccount to stl-admin for Motif/19544447408@voice.google.com-25e4 from data on channel Local/19544447408@onsite-0000335e;2 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:6671 ast_set_owners_and_peers: setting peeraccount to stl-admin for Local/19544447408@onsite-0000335e;2 from data on channel Motif/19544447408@voice.google.com-25e4 [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Goto' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'UserEvent' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4529 pbx_substitute_variables_helper_full: Expression result is '1' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'GotoIf' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Verbose' 19544447408 Immediate Live Dialing Local/15000@onsite [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Dial' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: rtp_engine.c:1650 ast_rtp_instance_early_bridge_make_compatible: Can't find native functions for channel 'Local/15000@onsite-0000335f;1' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message2. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd2. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable message3. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable rnd3. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable campaign. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable phonenumber. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable recordid. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable transferclid. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable did. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable queuename. [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6507 ast_channel_inherit_variables: Not copying variable trunk-did. [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4529 pbx_substitute_variables_helper_full: Expression result is '1' [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'GotoIf' [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Verbose' 1 Music 15000 [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Answer' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: features.c:4240 clear_dialed_interfaces: Removing dialed interfaces datastore on Local/15000@onsite-0000335f;1 since we're bridging [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6666 ast_set_owners_and_peers: setting peeraccount to stl-admin for Local/15000@onsite-0000335f;1 from data on channel Local/19544447408@onsite-0000335e;1 [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: channel.c:6671 ast_set_owners_and_peers: setting peeraccount to stl-admin for Local/19544447408@onsite-0000335e;1 from data on channel Local/15000@onsite-0000335f;1 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:6304 __ast_channel_masquerade: Planning to masquerade channel Motif/19544447408@voice.google.com-25e4 into the structure of Local/19544447408@onsite-0000335e;1 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:6314 __ast_channel_masquerade: Done planning to masquerade channel Motif/19544447408@voice.google.com-25e4 into the structure of Local/19544447408@onsite-0000335e;1 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:5361 set_format: Set channel Motif/19544447408@voice.google.com-25e4 to write format slin [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:5361 set_format: Set channel Motif/19544447408@voice.google.com-25e4 to read format slin [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:7155 ast_do_masquerade: Putting channel Motif/19544447408@voice.google.com-25e4 in slin/slin formats [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:7227 ast_do_masquerade: Done Masquerading Motif/19544447408@voice.google.com-25e4 (6) [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: chan_local.c:657 local_write: Not posting to 'Local/19544447408@onsite-0000335e;2' queue since already masqueraded out [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:7954 ast_channel_bridge: Bridge stops because we're zombie or need a soft hangup: c0=Local/19544447408@onsite-0000335e;2, c1=Local/19544447408@onsite-0000335e;1, flags: No,No,Yes,Yes [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:8053 ast_channel_bridge: Bridge stops bridging channels Local/19544447408@onsite-0000335e;2 and Local/19544447408@onsite-0000335e;1 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:2661 ast_softhangup_nolock: Soft-Hanging up channel 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_stack.c:578 gosub_exec: Channel Local/19544447408@onsite-0000335e;2 has no datastore, so we're allocating one. [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_stack.c:620 gosub_exec: Setting 'ARG1' to 'args' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: func_strings.c:970 regex: FUNCTION REGEX ([1-9])(141) [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Verbose' 141 -> 1 --> Channel 19544447408 Via 141 Lasted Seconds 1 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: func_strings.c:970 regex: FUNCTION REGEX ([1-9])(141) [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4529 pbx_substitute_variables_helper_full: Expression result is '0' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'GotoIf' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:11555 pbx_builtin_gotoif: Not taking any branch [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Verbose' 1-Re-Inserting 141 --> 142,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53,54,55,56,57,58,59,60,61,62,63,64,65,66,67,68,69,70,71,72,73,74,75,76,77,78,79,80,81,82,83,84,85,86,87,88,89,90,91,92,93,94,95,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110,111,112,113,114,115,116,117,118,119,120,121,122,123,124,125,126,127,128,129,130,131,132,133,134,135,136,137,138,139,140 [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Set' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Return' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_stack.c:1017 gosub_run: Spawn extension (onsite,19544447408,8) exited with -1 on 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: cdr_mysql.c:336 mysql_log: Inserting a CDR record. [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: cdr_mysql.c:339 mysql_log: SQL command as follows: INSERT INTO cdr (`calldate`,`src`,`dst`,`dstchannel`,`duration`,`billsec`,`disposition`,`amaflags`,`accountcode`,`uniqueid`) VALUES ('2013-04-29 10:11:34','0000000000','19544447408','Motif/19544447408@voice.google.com-25e4','13','1','ANSWERED','3','stl-admin','G2-1367244694.48630') [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:2840 ast_hangup: Hanging up channel 'Local/19544447408@onsite-0000335e;1' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_dial.c:3100 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: pbx.c:6316 __ast_pbx_run: Spawn extension (onsite,19544447408,8) exited non-zero on 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:2661 ast_softhangup_nolock: Soft-Hanging up channel 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:2840 ast_hangup: Hanging up channel 'Local/19544447408@onsite-0000335e;2' [Apr 29 10:11:47] DEBUG[9056][C-00002e7d]: pbx.c:4633 pbx_extension_helper: Launching 'Playback' [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: res_rtp_asterisk.c:2646 ast_rtp_write: Ooh, format changed from unknown to ulaw [Apr 29 10:11:47] DEBUG[9055][C-00002e7d]: res_rtp_asterisk.c:2681 ast_rtp_write: Created smoother: format: ulaw ms: 20 len: 160 gvoice-1*CLI> core set debug 0 Core debug is now OFF gvoice-1*CLI>