[Aug 14 21:10:47] Asterisk SVN-group-private-starscream-r421076M-/branches/13 built by rmudgett @ pigtest on a i686 running Linux on 2014-08-08 20:51:03 UTC [Aug 14 21:10:47] NOTICE[15673] loader.c: 1 modules will be loaded. [Aug 14 21:10:47] ERROR[15673] config_options.c: Unable to load config file 'acl.conf' [Aug 14 21:10:47] NOTICE[15673] cdr.c: CDR simple logging enabled. [Aug 14 21:10:47] NOTICE[15673] loader.c: 260 modules will be loaded. [Aug 14 21:10:48] WARNING[15673] loader.c: Error loading module 'res_monitor.so': /usr/lib/asterisk/modules/res_monitor.so: undefined symbol: __ast_beep_start [Aug 14 21:10:48] NOTICE[15673] res_odbc.c: res_odbc loaded. [Aug 14 21:10:49] ERROR[15673] res_config_sqlite3.c: Missing config file 'res_config_sqlite3.conf' [Aug 14 21:10:50] WARNING[15673] chan_iax2.c: Section 'cfmc_general' lacks type [Aug 14 21:10:50] WARNING[15673] chan_iax2.c: Section 'cfmc_trunk' lacks type [Aug 14 21:10:50] ERROR[15673] chan_dahdi.c: Unknown signalling method 'ss7' at line 51. [Aug 14 21:10:50] ERROR[15673] chan_dahdi.c: Unknown signalling method 'ss7' at line 74. [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Detected alarm on channel 15: Red Alarm [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Detected alarm on channel 16: Red Alarm [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Detected alarm on channel 6: Red Alarm [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Detected alarm on channel 7: Red Alarm [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Detected alarm on channel 8: Red Alarm [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Ignoring any changes to 'userbase' (on reload) at line 23. [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Ignoring any changes to 'vmsecret' (on reload) at line 31. [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Ignoring any changes to 'hassip' (on reload) at line 35. [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Ignoring any changes to 'hasiax' (on reload) at line 39. [Aug 14 21:10:50] WARNING[15673] chan_dahdi.c: Ignoring any changes to 'hasmanager' (on reload) at line 47. [Aug 14 21:10:50] ERROR[15673] config_options.c: Unable to load config file 'pjsip_notify.conf' [Aug 14 21:10:50] NOTICE[15673] confbridge/conf_config_parser.c: Adding default_menu menu to app_confbridge [Aug 14 21:10:50] ERROR[15673] codec_dahdi.c: Failed to open /dev/dahdi/transcode: No such file or directory [Aug 14 21:10:50] WARNING[15673] pbx_config.c: The use of '_.' for an extension is strongly discouraged and can have unexpected behavior. Please use '_X.' instead at line 3726 of extensions.conf [Aug 14 21:10:50] WARNING[15673] pbx_config.c: The use of '_.' for an extension is strongly discouraged and can have unexpected behavior. Please use '_X.' instead at line 3727 of extensions.conf [Aug 14 21:10:51] WARNING[15673] app_queue.c: Unknown keyword in queue 'ast150': eventwhencalled at line 504 of queues.conf [Aug 14 21:10:51] WARNING[15673] app_queue.c: Unknown keyword in queue 'ast200': eventwhencalled at line 514 of queues.conf [Aug 14 21:10:51] VERBOSE[15673] asterisk.c: Asterisk Ready. [Aug 14 21:11:13] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:13] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:13] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:13] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:14] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:14] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:14] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:14] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:15] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:15] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:15] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:15] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:16] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:16] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:16] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:16] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:17] DEBUG[15697] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 14 21:11:17] DEBUG[15697] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x99e52cc' [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Allocated port 17336 for RTP instance '0x99e52cc' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9868db4 ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9868db4 Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:17336, base=10.24.21.234:17336, prio=0x7effffff (2130706431) [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: RTP instance '0x99e52cc' is setup and ready to go [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x99e52cc' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9868db4 Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:17337, base=10.24.21.234:17337, prio=0x7efffffe (2130706430) [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9868db4 Destroying ICE session 0x9868db4 [Aug 14 21:11:17] DEBUG[15697] pjsip: ice_session.c ICE session 0x9868db4 destroyed [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Setting payload 0 (0x963cc4c) based on m type on 0xb6696bd0 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Setting payload 8 (0x98a2944) based on m type on 0xb6696bd0 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Setting payload 18 (0x981d81c) based on m type on 0xb6696bd0 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Setting payload 127 (0x9617bac) based on m type on 0xb6696bd0 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Copying payload 0 (0x981a184) from 0xb6696bd0 to 0x99e53f4 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Copying payload 8 (0x9f9cd34) from 0xb6696bd0 to 0x99e53f4 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Copying payload 18 (0x98c7f3c) from 0xb6696bd0 to 0x99e53f4 [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Copying payload 127 (0xa0063d4) from 0xb6696bd0 to 0x99e53f4 [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Created CDR for channel PJSIP/100-00000000 [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_START) result is '"CHAN_START"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is '' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-) result is '"accountcode-"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is '' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-) result is '"peeraccount-"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15697] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/100-00000000 [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15757] logger.c: CALL_ID [C-00000000] created by thread. [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:17] DEBUG[15757][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'default' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:1] NoOp("PJSIP/100-00000000", "Extension 200 (pjsip_a)") in new stack [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(default) result is '"default"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:2] Gosub("PJSIP/100-00000000", "displayall,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Channel PJSIP/100-00000000 has no datastore, so we're allocating one. [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayall:1] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(tag) result is 'SIP-A' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayall:2] Gosub("PJSIP/100-00000000", "displayredir,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(from-all) result is '"" <>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:1] NoOp("PJSIP/100-00000000", "REDIRECTING(from-all) is "" <>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(from-tag) result is '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:2] NoOp("PJSIP/100-00000000", "REDIRECTING(from-tag) is ") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(to-all) result is '"" <>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:3] NoOp("PJSIP/100-00000000", "REDIRECTING(to-all) is "" <>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(to-tag) result is '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:4] NoOp("PJSIP/100-00000000", "REDIRECTING(to-tag) is ") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(count) result is '0' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:5] NoOp("PJSIP/100-00000000", "REDIRECTING(count) is 0") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function REDIRECTING(reason) result is 'unknown' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:6] NoOp("PJSIP/100-00000000", "REDIRECTING(reason) is unknown") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayredir:7] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displayall:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:3] Gosub("PJSIP/100-00000000", "set_interception,s,1(pots,200)") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to 'pots' [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG2' to '200' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:1] NoOp("PJSIP/100-00000000", "Setting interception variables for context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:2] Set("PJSIP/100-00000000", "__CONNECTED_LINE_SEND_SUB=connected_line_send,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:3] Set("PJSIP/100-00000000", "__CONNECTED_LINE_SEND_SUB_ARGS=context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:4] Set("PJSIP/100-00000000", "__REDIRECTING_SEND_SUB=redirecting_send,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:5] Set("PJSIP/100-00000000", "__REDIRECTING_SEND_SUB_ARGS=context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:6] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLER_SEND_MACRO=connected_line_send") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:7] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLER_SEND_MACRO_ARGS=caller context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:8] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLEE_SEND_MACRO=connected_line_send") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:9] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS=CALLEE context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:10] Set("PJSIP/100-00000000", "__REDIRECTING_CALLER_SEND_MACRO=redirecting_send") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:11] Set("PJSIP/100-00000000", "__REDIRECTING_CALLER_SEND_MACRO_ARGS=caller context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:12] Set("PJSIP/100-00000000", "__REDIRECTING_CALLEE_SEND_MACRO=redirecting_send") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:13] Set("PJSIP/100-00000000", "__REDIRECTING_CALLEE_SEND_MACRO_ARGS=CALLEE context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@set_interception:14] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:4] Set("PJSIP/100-00000000", "CHANNEL(accountcode)=apple") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:5] Set("PJSIP/100-00000000", "CHANNEL(peeraccount)=orange") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Macro' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [200@pjsip_a:6] Macro("PJSIP/100-00000000", "callit,PJSIP/200,30,kKtT") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@macro-callit:1] NoOp("PJSIP/100-00000000", "Requested to call PJSIP/200,30,kKtT CC_INTERFACES is ") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_macro.c: Executed application: NoOp [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function EXISTS() result is '0' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function IF(0?:PJSIP/200) result is 'PJSIP/200' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Set' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@macro-callit:2] Set("PJSIP/100-00000000", "DESTS=PJSIP/200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_macro.c: Executed application: Set [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Dial' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@macro-callit:3] Dial("PJSIP/100-00000000", "PJSIP/200,30,kKtT") in new stack [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_START) result is '"APP_START"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15697] config.c: extract int from [0] in [0, 86400] gives [0](0) [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0xb4f89e6c - Created CDR for channel PJSIP/200-00000001 [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0xb4f89e6c - Transitioning CDR for PJSIP/200-00000001 from state NONE to Single [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_START) result is '"CHAN_START"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is '' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-) result is '"accountcode-"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is '' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-) result is '"peeraccount-"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'default' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(default) result is '"default"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_CALLEE_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_CALLEE_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_CALLER_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_CALLER_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_CALLEE_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_CALLER_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_CALLER_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_SEND_SUB_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable REDIRECTING_SEND_SUB from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_SEND_SUB_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Inheriting variable CONNECTED_LINE_SEND_SUB from PJSIP/100-00000000 to PJSIP/200-00000001. [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9586ad4' [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Allocated port 18470 for RTP instance '0x9586ad4' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9fcae9c ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9fcae9c Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:18470, base=10.24.21.234:18470, prio=0x7effffff (2130706431) [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: RTP instance '0x9586ad4' is setup and ready to go [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9586ad4' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9fcae9c Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:18471, base=10.24.21.234:18471, prio=0x7efffffe (2130706430) [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0x9fcae9c Destroying ICE session 0x9fcae9c [Aug 14 21:11:17] DEBUG[15697] pjsip: ice_session.c ICE session 0x9fcae9c destroyed [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb4f6dffc' [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Allocated port 11520 for RTP instance '0xb4f6dffc' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0xb4cb9f5 ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:11520, base=10.24.21.234:11520, prio=0x7effffff (2130706431) [Aug 14 21:11:17] DEBUG[15697] rtp_engine.c: RTP instance '0xb4f6dffc' is setup and ready to go [Aug 14 21:11:17] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb4f6dffc' [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:11521, base=10.24.21.234:11521, prio=0x7efffffe (2130706430) [Aug 14 21:11:17] DEBUG[15697] pjsip: icess0xb4cb9f5 Destroying ICE session 0xb4cb9f5c [Aug 14 21:11:17] DEBUG[15697] pjsip: ice_session.c ICE session 0xb4cb9f5c destroyed [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Sending request [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:17] VERBOSE[15685] cdr.c: Dial Begin message for PJSIP/100-00000000, PJSIP/200-00000001: 1408068677.00046148 [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Processing Dial Begin message for channel PJSIP/100-00000000, peer PJSIP/200-00000001 [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Updated Party A PJSIP/100-00000000 snapshot [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Updated Party B PJSIP/200-00000001 snapshot [Aug 14 21:11:17] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state Single to Dial [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_dial.c: Called PJSIP/200 [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Set channel PJSIP/200-00000001 to read format ulaw [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: Set channel PJSIP/200-00000001 to write format ulaw [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) start [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Original location: macro-callit,s,3 [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to 'context:pots exten:200' [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_END) result is '"APP_END"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CONNECTEDLINE(all) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CONNECTEDLINE(tag) result is 'SIP-B' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(tag) result is 'SIP-A' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Spawn extension (macro-callit,s,3) exited with -1 on 'PJSIP/100-00000000' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) complete GOSUB_RETVAL= [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Ending location: macro-callit,s,3 [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) start [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Original location: macro-callit,s,3 [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to 'context:pots exten:200' [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pots exten:200") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CONNECTEDLINE(all) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CONNECTEDLINE(tag) result is 'SIP-B' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Gosub' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Function CALLERID(tag) result is 'SIP-A' [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'NoOp' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] pbx.c: Launching 'Return' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: Spawn extension (macro-callit,s,3) exited with -1 on 'PJSIP/100-00000000' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000' [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) complete GOSUB_RETVAL= [Aug 14 21:11:17] DEBUG[15757][C-00000000] app_stack.c: PJSIP/100-00000000 Ending location: macro-callit,s,3 [Aug 14 21:11:17] DEBUG[15757][C-00000000] channel.c: PJSIP/100-00000000: Dropping redundant connected line update "CfgSIP_20" <2200>. [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Received response [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Response is 180 Ringing [Aug 14 21:11:17] VERBOSE[15757][C-00000000] app_dial.c: PJSIP/200-00000001 is ringing [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:17] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:17] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 200 [Aug 14 21:11:17] DEBUG[15682] devicestate.c: Changing state for PJSIP/200 - state 6 (Ringing) [Aug 14 21:11:17] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 100 [Aug 14 21:11:17] DEBUG[15682] devicestate.c: Changing state for PJSIP/100 - state 2 (In use) [Aug 14 21:11:17] DEBUG[15754] app_queue.c: Device 'PJSIP/200' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Aug 14 21:11:17] DEBUG[15754] app_queue.c: Device 'PJSIP/100' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 14 21:11:17] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:17] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:17] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:17] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:18] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:18] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:18] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:18] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Received response [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Response is 200 OK [Aug 14 21:11:18] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9586ad4' [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 0 (0xb507859c) based on m type on 0xb66963b0 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 101 (0xb51f16fc) based on m type on 0xb66963b0 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 0 (0xb4dfa9ec) from 0xb66963b0 to 0x9586bfc [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 101 (0xb68010a4) from 0xb66963b0 to 0x9586bfc [Aug 14 21:11:18] VERBOSE[15757][C-00000000] app_dial.c: PJSIP/200-00000001 answered PJSIP/100-00000000 [Aug 14 21:11:18] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4f6dffc' [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 99 (0xb4e7c6ac) based on m type on 0xb66963b0 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 34 (0xb5168cec) based on m type on 0xb66963b0 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 34 (0xb5168cec) from 0xb66963b0 to 0xb4f6e124 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 99 (0xb4e7c6ac) from 0xb66963b0 to 0xb4f6e124 [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0xb4f89e6c - Set answered time to 1408068678.536591 [Aug 14 21:11:18] DEBUG[15757][C-00000000] features.c: Removing dialed interfaces datastore on PJSIP/200-00000001 since we're bridging [Aug 14 21:11:18] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 200 [Aug 14 21:11:18] DEBUG[15682] devicestate.c: Changing state for PJSIP/200 - state 2 (In use) [Aug 14 21:11:18] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 100 [Aug 14 21:11:18] DEBUG[15682] devicestate.c: Changing state for PJSIP/100 - state 2 (In use) [Aug 14 21:11:18] VERBOSE[15685] cdr.c: Dial End message for PJSIP/100-00000000, PJSIP/200-00000001: 1408068678.00536707 [Aug 14 21:11:18] DEBUG[15757][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: Cannot use native DAHDI. Must have two channels. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Processing Dial End message for channel PJSIP/100-00000000, peer PJSIP/200-00000001 [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge_native_rtp.c: Bridge '37812fb3-cff3-4c97-b6ad-7d26c08109a6' can not use native RTP bridge as two channels are required [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state Dial to DialedPending [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: calling simple_bridge technology constructor [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Set answered time to 1408068678.537477 [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: calling simple_bridge technology start [Aug 14 21:11:18] DEBUG[15754] app_queue.c: Device 'PJSIP/200' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb462ec3c(PJSIP/100-00000000) is joining [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: pushing 0xb462ec3c(PJSIP/100-00000000) [Aug 14 21:11:18] VERBOSE[15757][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 joined 'simple_bridge' basic-bridge <37812fb3-cff3-4c97-b6ad-7d26c08109a6> [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Sending request [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Method is ACK [Aug 14 21:11:18] DEBUG[15757][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: Cannot use native DAHDI. Must have two channels. [Aug 14 21:11:18] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x99e52cc' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 0 (0xa0e1c74) based on m type on 0xb6696640 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 8 (0xb4fcf77c) based on m type on 0xb6696640 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Setting payload 127 (0xb4b6079c) based on m type on 0xb6696640 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 0 (0xb4ca89e4) from 0xb6696640 to 0x99e53f4 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 8 (0xb4f0639c) from 0xb6696640 to 0x99e53f4 [Aug 14 21:11:18] DEBUG[15697] rtp_engine.c: Copying payload 127 (0xb491298c) from 0xb6696640 to 0x99e53f4 [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(ANSWER) result is '"ANSWER"' [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Aug 14 21:11:18] VERBOSE[15685] cdr.c: Bridge Enter message for channel PJSIP/100-00000000: 1408068678.00538361 [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Updating Party A PJSIP/100-00000000 snapshot [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Processing bridge enter for PJSIP/100-00000000 [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state DialedPending to Dial [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state Dial to Bridged [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge_native_rtp.c: Bridge '37812fb3-cff3-4c97-b6ad-7d26c08109a6' can not use native RTP bridge as two channels are required [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is already using the new technology. [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is happy that channel PJSIP/100-00000000 already has read format ulaw [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is happy that channel PJSIP/100-00000000 already has write format ulaw [Aug 14 21:11:18] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb462ec3c(PJSIP/100-00000000) is joining simple_bridge technology [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '200' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(200) result is '"200"' [Aug 14 21:11:18] DEBUG[15759][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb45694f4(PJSIP/200-00000001) is joining [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: pushing 0xb45694f4(PJSIP/200-00000001) [Aug 14 21:11:18] VERBOSE[15759][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 joined 'simple_bridge' basic-bridge <37812fb3-cff3-4c97-b6ad-7d26c08109a6> [Aug 14 21:11:18] VERBOSE[15685] cdr.c: Bridge Enter message for channel PJSIP/200-00000001: 1408068678.00540190 [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0xb4f89e6c - Updating Party A PJSIP/200-00000001 snapshot [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0xb4f89e6c - Processing bridge enter for PJSIP/200-00000001 [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0xb4f89e6c - Transitioning CDR for PJSIP/200-00000001 from state Single to Bridged [Aug 14 21:11:18] DEBUG[15685] cdr.c: Finalized CDR for PJSIP/200-00000001 - start 1408068677.040903 answer 1408068678.536591 end 1408068678.540302 dispo ANSWERED [Aug 14 21:11:18] VERBOSE[15685] cdr.c: 0x975a5b4 - Party A PJSIP/100-00000000 has new Party B PJSIP/200-00000001 [Aug 14 21:11:18] DEBUG[15759][C-00000000] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/100-00000000' has DTMF hooks. [Aug 14 21:11:18] DEBUG[15759][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: Cannot use native DAHDI. Channel 'PJSIP/100-00000000' not compatible. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge_native_rtp.c: Bridge '37812fb3-cff3-4c97-b6ad-7d26c08109a6' can not use native RTP bridge as it was forbidden while getting details [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is already using the new technology. [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is happy that channel PJSIP/200-00000001 already has read format ulaw [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is happy that channel PJSIP/200-00000001 already has write format ulaw [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_START) result is '"APP_START"' [Aug 14 21:11:18] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb45694f4(PJSIP/200-00000001) is joining simple_bridge technology [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(ANSWER) result is '"ANSWER"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_ENTER) result is '"BRIDGE_ENTER"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"37812fb3-cff3-4c97-b6ad-7d26c08109a6"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""37812fb3-cff3-4c97-b6ad-7d26c08109a6""}"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_ENTER) result is '"BRIDGE_ENTER"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:18] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"37812fb3-cff3-4c97-b6ad-7d26c08109a6"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""37812fb3-cff3-4c97-b6ad-7d26c08109a6""}"' [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Received request [Aug 14 21:11:18] DEBUG[15697] res_pjsip_session.c: Method is ACK [Aug 14 21:11:18] DEBUG[15759][C-00000000] res_rtp_asterisk.c: 0x9fc8778 -- Probation learning mode pass with source address 10.24.19.249:2230 [Aug 14 21:11:18] VERBOSE[15759][C-00000000] res_rtp_asterisk.c: 0x9fc8778 -- Probation passed - setting RTP source address to 10.24.19.249:2230 [Aug 14 21:11:18] DEBUG[15757][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Aug 14 21:11:18] DEBUG[15757][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x99e52cc' [Aug 14 21:11:18] DEBUG[15757][C-00000000] res_rtp_asterisk.c: 0x9fc1210 -- Probation learning mode pass with source address 10.24.17.232:2222 [Aug 14 21:11:18] VERBOSE[15757][C-00000000] res_rtp_asterisk.c: 0x9fc1210 -- Probation passed - setting RTP source address to 10.24.17.232:2222 [Aug 14 21:11:18] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Aug 14 21:11:19] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:19] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:19] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:19] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:19] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 50 (2), at 10.24.19.249:2230 [Aug 14 21:11:19] DTMF[15759][C-00000000] channel.c: DTMF begin '2' received on PJSIP/200-00000001 [Aug 14 21:11:19] DTMF[15759][C-00000000] channel.c: DTMF begin passthrough '2' on PJSIP/200-00000001 [Aug 14 21:11:19] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Creating END DTMF Frame: 50 (2), at 10.24.19.249:2230 [Aug 14 21:11:19] DTMF[15759][C-00000000] channel.c: DTMF end '2' received on PJSIP/200-00000001, duration 140 ms [Aug 14 21:11:19] DTMF[15759][C-00000000] channel.c: DTMF end accepted with begin '2' on PJSIP/200-00000001 [Aug 14 21:11:19] DTMF[15759][C-00000000] channel.c: DTMF end passthrough '2' on PJSIP/200-00000001 [Aug 14 21:11:20] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:20] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:20] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:20] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:20] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 10.24.19.249:2230 [Aug 14 21:11:20] DTMF[15759][C-00000000] channel.c: DTMF begin '0' received on PJSIP/200-00000001 [Aug 14 21:11:20] DTMF[15759][C-00000000] channel.c: DTMF begin passthrough '0' on PJSIP/200-00000001 [Aug 14 21:11:20] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 10.24.19.249:2230 [Aug 14 21:11:20] DTMF[15759][C-00000000] channel.c: DTMF end '0' received on PJSIP/200-00000001, duration 140 ms [Aug 14 21:11:20] DTMF[15759][C-00000000] channel.c: DTMF end accepted with begin '0' on PJSIP/200-00000001 [Aug 14 21:11:20] DTMF[15759][C-00000000] channel.c: DTMF end passthrough '0' on PJSIP/200-00000001 [Aug 14 21:11:21] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:21] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:21] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:21] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:22] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:22] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:22] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:22] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 0 (0xb4b44f64) based on m type on 0xb66967b0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 101 (0xb4f2fdb4) based on m type on 0xb66967b0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 0 (0xb4f7206c) from 0xb66967b0 to 0x9586bfc [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 101 (0xb4ce9954) from 0xb66967b0 to 0x9586bfc [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 99 (0xb4f8e9ac) based on m type on 0xb66967b0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 34 (0xb4f5985c) based on m type on 0xb66967b0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 34 (0xb4c06e4c) from 0xb66967b0 to 0xb4f6e124 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 99 (0xb4f5977c) from 0xb66967b0 to 0xb4f6e124 [Aug 14 21:11:22] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9586ad4' [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 0 (0xb4da2104) based on m type on 0xb66962c0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 101 (0xb440d3c4) based on m type on 0xb66962c0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 0 (0xb4e7000c) from 0xb66962c0 to 0x9586bfc [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 101 (0xb51f2c54) from 0xb66962c0 to 0x9586bfc [Aug 14 21:11:22] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9586ad4' [Aug 14 21:11:22] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4f6dffc' [Aug 14 21:11:22] DEBUG[15754] app_queue.c: Device 'PJSIP/100' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 99 (0xb4e52e9c) based on m type on 0xb66962c0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Setting payload 34 (0xb4dd727c) based on m type on 0xb66962c0 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 34 (0xb4dd727c) from 0xb66962c0 to 0xb4f6e124 [Aug 14 21:11:22] DEBUG[15697] rtp_engine.c: Copying payload 99 (0xb4e52e9c) from 0xb66962c0 to 0xb4f6e124 [Aug 14 21:11:22] VERBOSE[15757][C-00000000] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/100-00000000' [Aug 14 21:11:22] DEBUG[15757][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15757][C-00000000] channel.c: Set channel PJSIP/100-00000000 to write format slin [Aug 14 21:11:22] DEBUG[15757][C-00000000] res_musiconhold.c: PJSIP/100-00000000 Opened file 0 '/var/lib/asterisk/moh/reno_project-system' [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:22] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15757][C-00000000] res_rtp_asterisk.c: Got RTCP report of 92 bytes [Aug 14 21:11:23] DEBUG[15757][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15757][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15757][C-00000000] acl.c: Attached to given IP address [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:23] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:23] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:23] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Got RTCP report of 92 bytes [Aug 14 21:11:23] DEBUG[15759][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15759][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15759][C-00000000] acl.c: Attached to given IP address [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15717] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15717] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:23] DEBUG[15717] acl.c: Attached to given IP address [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:23] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:24] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:24] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:24] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:24] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:25] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:25] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:25] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15697] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 14 21:11:25] DEBUG[15697] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 200 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb4d7844c' [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Allocated port 11812 for RTP instance '0xb4d7844c' [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb422d31 ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb422d31 Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:11812, base=10.24.21.234:11812, prio=0x7effffff (2130706431) [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: RTP instance '0xb4d7844c' is setup and ready to go [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb4d7844c' [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb422d31 Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:11813, base=10.24.21.234:11813, prio=0x7efffffe (2130706430) [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb422d31 Destroying ICE session 0xb422d31c [Aug 14 21:11:25] DEBUG[15697] pjsip: ice_session.c ICE session 0xb422d31c destroyed [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Setting payload 0 (0x9706704) based on m type on 0xb6696bd0 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Setting payload 8 (0x99f770c) based on m type on 0xb6696bd0 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Setting payload 18 (0x9fc574c) based on m type on 0xb6696bd0 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Setting payload 127 (0xa104394) based on m type on 0xb6696bd0 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Copying payload 0 (0xa1168d4) from 0xb6696bd0 to 0xb4d78574 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Copying payload 8 (0x99b2e2c) from 0xb6696bd0 to 0xb4d78574 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Copying payload 18 (0x9800c0c) from 0xb6696bd0 to 0xb4d78574 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Copying payload 127 (0x9598b2c) from 0xb6696bd0 to 0xb4d78574 [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Created CDR for channel PJSIP/200-00000002 [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Transitioning CDR for PJSIP/200-00000002 from state NONE to Single [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_START) result is '"CHAN_START"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is '' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-) result is '"accountcode-"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is '' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-) result is '"peeraccount-"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'default' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(default) result is '"default"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15697] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/200-00000002 [Aug 14 21:11:25] DEBUG[15760] logger.c: CALL_ID [C-00000001] created by thread. [Aug 14 21:11:25] DEBUG[15760][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread. [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:1] NoOp("PJSIP/200-00000002", "Extension 202 (pjsip_b)") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:2] Gosub("PJSIP/200-00000002", "displayall,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Channel PJSIP/200-00000002 has no datastore, so we're allocating one. [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayall:1] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(all) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(tag) result is 'SIP-B' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayall:2] Gosub("PJSIP/200-00000002", "displayredir,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(from-all) result is '"" <>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:1] NoOp("PJSIP/200-00000002", "REDIRECTING(from-all) is "" <>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(from-tag) result is '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:2] NoOp("PJSIP/200-00000002", "REDIRECTING(from-tag) is ") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(to-all) result is '"" <>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:3] NoOp("PJSIP/200-00000002", "REDIRECTING(to-all) is "" <>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(to-tag) result is '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:4] NoOp("PJSIP/200-00000002", "REDIRECTING(to-tag) is ") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(count) result is '0' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:5] NoOp("PJSIP/200-00000002", "REDIRECTING(count) is 0") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function REDIRECTING(reason) result is 'unknown' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:6] NoOp("PJSIP/200-00000002", "REDIRECTING(reason) is unknown") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayredir:7] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displayall:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:3] Gosub("PJSIP/200-00000002", "set_interception,s,1(pjsip_b,202)") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to 'pjsip_b' [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG2' to '202' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:1] NoOp("PJSIP/200-00000002", "Setting interception variables for context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:2] Set("PJSIP/200-00000002", "__CONNECTED_LINE_SEND_SUB=connected_line_send,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:3] Set("PJSIP/200-00000002", "__CONNECTED_LINE_SEND_SUB_ARGS=context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:4] Set("PJSIP/200-00000002", "__REDIRECTING_SEND_SUB=redirecting_send,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:5] Set("PJSIP/200-00000002", "__REDIRECTING_SEND_SUB_ARGS=context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:6] Set("PJSIP/200-00000002", "__CONNECTED_LINE_CALLER_SEND_MACRO=connected_line_send") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:7] Set("PJSIP/200-00000002", "__CONNECTED_LINE_CALLER_SEND_MACRO_ARGS=caller context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:8] Set("PJSIP/200-00000002", "__CONNECTED_LINE_CALLEE_SEND_MACRO=connected_line_send") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:9] Set("PJSIP/200-00000002", "__CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS=CALLEE context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:10] Set("PJSIP/200-00000002", "__REDIRECTING_CALLER_SEND_MACRO=redirecting_send") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:11] Set("PJSIP/200-00000002", "__REDIRECTING_CALLER_SEND_MACRO_ARGS=caller context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:12] Set("PJSIP/200-00000002", "__REDIRECTING_CALLEE_SEND_MACRO=redirecting_send") in new stack [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:13] Set("PJSIP/200-00000002", "__REDIRECTING_CALLEE_SEND_MACRO_ARGS=CALLEE context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@set_interception:14] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:4] Set("PJSIP/200-00000002", "CHANNEL(accountcode)=green") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:5] Set("PJSIP/200-00000002", "CHANNEL(peeraccount)=pear") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Dial' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:6] Dial("PJSIP/200-00000002", "PJSIP/202,30,kKtThHb(predial)") in new stack [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_START) result is '"APP_START"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'green' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-green) result is '"accountcode-green"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'pear' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-pear) result is '"peeraccount-pear"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15697] config.c: extract int from [0] in [0, 86400] gives [0](0) [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb457e2c4 - Created CDR for channel PJSIP/202-00000003 [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb457e2c4 - Transitioning CDR for PJSIP/202-00000003 from state NONE to Single [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_CALLEE_SEND_MACRO_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_CALLEE_SEND_MACRO from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_CALLER_SEND_MACRO_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_CALLER_SEND_MACRO from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_CALLEE_SEND_MACRO from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_CALLER_SEND_MACRO_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_CALLER_SEND_MACRO from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_SEND_SUB_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable REDIRECTING_SEND_SUB from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_SEND_SUB_ARGS from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Inheriting variable CONNECTED_LINE_SEND_SUB from PJSIP/200-00000002 to PJSIP/202-00000003. [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Gosub args:predial new_args:pjsip_b,202,predial [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/202-00000003 Internal Gosub(pjsip_b,202,predial) start [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/202-00000003 Original location: pjsip_b,202,1 [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Channel PJSIP/202-00000003 has no datastore, so we're allocating one. [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:8] NoOp("PJSIP/202-00000003", "Predial partial location, ARGC=0, ARG1=, ARG2=") in new stack [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_START) result is '"CHAN_START"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/202-00000003' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/202-00000003) result is '"PJSIP/202-00000003"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is '' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-) result is '"accountcode-"' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:9] Gosub("PJSIP/202-00000003", "displaycli,s,1") in new stack [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is '' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-) result is '"peeraccount-"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.14' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.14) result is '"1408068685.14"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_22' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_22) result is '"CfgSIP_22"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2202' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(2202) result is '"2202"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'default' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(default) result is '"default"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(all) result is '"CfgSIP_22" <2202>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/202-00000003", "CALLERID(all) is "CfgSIP_22" <2202>") in new stack [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(tag) result is 'SIP-E' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/202-00000003", "CALLERID(tag) is SIP-E") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/202-00000003", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Set' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:10] Set("PJSIP/202-00000003", "CALLERID(tag)=Radish") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [202@pjsip_b:11] Return("PJSIP/202-00000003", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b,202,1) exited with -1 on 'PJSIP/202-00000003' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 1) exited non-zero on 'PJSIP/202-00000003' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/202-00000003 Internal Gosub(pjsip_b,202,predial) complete GOSUB_RETVAL= [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/202-00000003 Ending location: pjsip_b,202,1 [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb4fcf0f4' [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Allocated port 12960 for RTP instance '0xb4fcf0f4' [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:12960, base=10.24.21.234:12960, prio=0x7effffff (2130706431) [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: RTP instance '0xb4fcf0f4' is setup and ready to go [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb4fcf0f4' [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:12961, base=10.24.21.234:12961, prio=0x7efffffe (2130706430) [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Destroying ICE session 0xb4cb9f5c [Aug 14 21:11:25] DEBUG[15697] pjsip: ice_session.c ICE session 0xb4cb9f5c destroyed [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb4f84684' [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Allocated port 14620 for RTP instance '0xb4f84684' [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 ICE session created, comp_cnt=2, role is Unknown agent [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 0 added: comp_id=1, type=host, foundation=Ha1815ea, addr=10.24.21.234:14620, base=10.24.21.234:14620, prio=0x7effffff (2130706431) [Aug 14 21:11:25] DEBUG[15697] rtp_engine.c: RTP instance '0xb4f84684' is setup and ready to go [Aug 14 21:11:25] DEBUG[15697] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb4f84684' [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Candidate 1 added: comp_id=2, type=host, foundation=Ha1815ea, addr=10.24.21.234:14621, base=10.24.21.234:14621, prio=0x7efffffe (2130706430) [Aug 14 21:11:25] DEBUG[15697] pjsip: icess0xb4cb9f5 Destroying ICE session 0xb4cb9f5c [Aug 14 21:11:25] DEBUG[15697] pjsip: ice_session.c ICE session 0xb4cb9f5c destroyed [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Sending request [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE [Aug 14 21:11:25] VERBOSE[15685] cdr.c: Dial Begin message for PJSIP/200-00000002, PJSIP/202-00000003: 1408068685.00843300 [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_dial.c: Called PJSIP/202 [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Set channel PJSIP/202-00000003 to read format ulaw [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: Set channel PJSIP/202-00000003 to write format ulaw [Aug 14 21:11:25] DEBUG[15758][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread. [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Processing Dial Begin message for channel PJSIP/200-00000002, peer PJSIP/202-00000003 [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Original location: pjsip_b,202,6 [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Updated Party A PJSIP/200-00000002 snapshot [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Updated Party B PJSIP/202-00000003 snapshot [Aug 14 21:11:25] VERBOSE[15685] cdr.c: 0xb4b602fc - Transitioning CDR for PJSIP/200-00000002 from state Single to Dial [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to 'context:pjsip_b exten:202' [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/200-00000002", "Connected line send subroutine for context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_END) result is '"APP_END"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'green' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-green) result is '"accountcode-green"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'pear' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-pear) result is '"peeraccount-pear"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/200-00000002", "displaycolp,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(all) result is '"CfgSIP_22" <2202>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(tag) result is 'Radish' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(tag) is Radish") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(all) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(tag) result is 'SIP-B' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b,202,6) exited with -1 on 'PJSIP/200-00000002' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/200-00000002' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) complete GOSUB_RETVAL= [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Ending location: pjsip_b,202,6 [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:25] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Original location: pjsip_b,202,6 [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to 'context:pjsip_b exten:202' [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/200-00000002", "Connected line send subroutine for context:pjsip_b exten:202") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/200-00000002", "displaycolp,s,1") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(all) result is '"CfgSIP_22" <2202>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(tag) result is 'Radish' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(tag) is Radish") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(all) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(tag) result is 'SIP-B' [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/200-00000002", "") in new stack [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b,202,6) exited with -1 on 'PJSIP/200-00000002' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/200-00000002' [Aug 14 21:11:25] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) complete GOSUB_RETVAL= [Aug 14 21:11:25] DEBUG[15760][C-00000001] app_stack.c: PJSIP/200-00000002 Ending location: pjsip_b,202,6 [Aug 14 21:11:25] DEBUG[15760][C-00000001] channel.c: PJSIP/200-00000002: Dropping redundant connected line update "CfgSIP_22" <2202>. [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:25] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Received response [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Response is 180 Ringing [Aug 14 21:11:26] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 202 [Aug 14 21:11:26] DEBUG[15682] devicestate.c: Changing state for PJSIP/202 - state 6 (Ringing) [Aug 14 21:11:26] DEBUG[15754] app_queue.c: Device 'PJSIP/202' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Aug 14 21:11:26] VERBOSE[15760][C-00000001] app_dial.c: PJSIP/202-00000003 is ringing [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:26] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Aug 14 21:11:26] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 200 [Aug 14 21:11:26] DEBUG[15682] devicestate.c: Changing state for PJSIP/200 - state 2 (In use) [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:26] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:26] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:26] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:26] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:27] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:27] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:27] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:27] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15757][C-00000000] res_rtp_asterisk.c: Got RTCP report of 92 bytes [Aug 14 21:11:28] DEBUG[15757][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15757][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15757][C-00000000] acl.c: Attached to given IP address [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:28] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:28] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:28] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Aug 14 21:11:28] DEBUG[15759][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15759][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15759][C-00000000] acl.c: Attached to given IP address [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15717] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15717] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 14 21:11:28] DEBUG[15717] acl.c: Attached to given IP address [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:28] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:29] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:29] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:29] DEBUG[15759][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x9586ad4' so dropping frame [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Method is REFER [Aug 14 21:11:29] DEBUG[15697] res_pjsip_refer.c: Created progress monitor '0xb6696c48' for transfer occurring from channel 'PJSIP/200-00000001' and endpoint '200' [Aug 14 21:11:29] DEBUG[15697] res_pjsip_refer.c: Accepting REFER request for progress monitor '0xb46207a4' [Aug 14 21:11:29] DEBUG[15697] res_pjsip_refer.c: Sending initial 100 Trying NOTIFY for progress monitor '0xb46207a4' [Aug 14 21:11:29] DEBUG[15697] pjsip: evsub0xb4d0166 .....Subscription state changed NULL --> ACTIVE [Aug 14 21:11:29] DEBUG[15697] res_pjsip_refer.c: Attended transfer from 'PJSIP/200-00000001' pushed to second channel serializer [Aug 14 21:11:29] DEBUG[15698] res_pjsip_refer.c: Performing a REFER attended transfer - Transferer #1: PJSIP/200-00000001 Transferer #2: PJSIP/200-00000002 [Aug 14 21:11:29] VERBOSE[15757][C-00000000] res_musiconhold.c: Stopped music on hold on PJSIP/100-00000000 [Aug 14 21:11:29] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 100 [Aug 14 21:11:29] DEBUG[15682] devicestate.c: Changing state for PJSIP/100 - state 2 (In use) [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Set channel PJSIP/100-00000000 to write format ulaw [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Aug 14 21:11:29] DEBUG[15754] app_queue.c: Device 'PJSIP/100' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 14 21:11:29] DEBUG[15698] bridge_channel.c: Setting 0xb45694f4(PJSIP/200-00000001) state from:0 to:2 [Aug 14 21:11:29] DEBUG[15698] res_pjsip_refer.c: Final response for REFER attended transfer - Transferer #1: PJSIP/200-00000001 Transferer #2: PJSIP/200-00000002 is '200' [Aug 14 21:11:29] DEBUG[15698] res_pjsip_refer.c: Subscription '0xb4d01664' is being terminated as a result of a NOTIFY, removing REFER progress structure early on progress monitor '0xb46207a4' [Aug 14 21:11:29] DEBUG[15698] res_pjsip_refer.c: Sending NOTIFY with response '200' and state '5' on subscription '0xb4d01664' and progress monitor '0xb46207a4' [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: pulling 0xb45694f4(PJSIP/200-00000001) [Aug 14 21:11:29] VERBOSE[15759][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 left 'simple_bridge' basic-bridge <37812fb3-cff3-4c97-b6ad-7d26c08109a6> [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb45694f4(PJSIP/200-00000001) is leaving simple_bridge technology [Aug 14 21:11:29] DEBUG[15759][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: Cannot use native DAHDI. Must have two channels. [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:29] DEBUG[15698] pjsip: evsub0xb4d0166 Subscription state changed ACTIVE --> TERMINATED [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge_native_rtp.c: Bridge '37812fb3-cff3-4c97-b6ad-7d26c08109a6' can not use native RTP bridge as two channels are required [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is already using the new technology. [Aug 14 21:11:29] VERBOSE[15685] cdr.c: Bridge Leave message for PJSIP/200-00000001: 1408068689.00056188 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4f89e6c - Processing Bridge Leave for PJSIP/200-00000001 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4f89e6c - Transitioning CDR for PJSIP/200-00000001 from state Bridged to Finalized [Aug 14 21:11:29] DEBUG[15685] cdr.c: Finalized CDR for PJSIP/100-00000000 - start 1408068677.017081 answer 1408068678.537477 end 1408068689.056941 dispo ANSWERED [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge_channel.c: Setting 0xb462ec3c(PJSIP/100-00000000) state from:0 to:1 [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(ATTENDEDTRANSFER) result is '"ATTENDEDTRANSFER"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: pulling 0xb462ec3c(PJSIP/100-00000000) [Aug 14 21:11:29] VERBOSE[15757][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 left 'simple_bridge' basic-bridge <37812fb3-cff3-4c97-b6ad-7d26c08109a6> [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge_channel.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: 0xb462ec3c(PJSIP/100-00000000) is leaving simple_bridge technology [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: dissolving bridge with cause 16(Normal Clearing) [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: queueing action type:13 sub:1001 [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:29] DEBUG[15757][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6 is dissolved, not performing smart bridge operation. [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Actually Masquerading PJSIP/100-00000000(6) into the structure of PJSIP/200-00000002(4) [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge1_id":"37812fb3-cff3-4c97-b6ad-7d26c08109a6","channel2_name":"PJSIP/200-00000002","channel2_uniqueid":"1408068685.11","transferee_channel_name":"PJSIP/100-00000000","app":"Dial","transferee_channel_uniqueid":"1408068677.0","transfer_target_channel_name":"N/A","transfer_target_channel_uniqueid":"N/A"}) result is '"{""bridge1_id"":""37812fb3-cff3-4c97-b6ad-7d26c08109a6"",""channel2_name"":""PJSIP/200-00000002"",""channel2_uniqueid"":""1408068685.11"",""transferee_channel_name"":""PJSIP/100-00000000"",""app"":""Dial"",""transferee_channel_uniqueid"":""1408068677.0"",""transfer_target_channel_name"":""N/A"",""transfer_target_channel_uniqueid"":""N/A""}"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_EXIT) result is '"BRIDGE_EXIT"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Putting channel PJSIP/100-00000000 in ulaw/ulaw formats [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:29] DEBUG[15681][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Aug 14 21:11:29] VERBOSE[15685] cdr.c: Bridge Leave message for PJSIP/100-00000000: 1408068689.00057237 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0x975a5b4 - Processing Bridge Leave for PJSIP/100-00000000 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0x975a5b4 - Transitioning CDR for PJSIP/100-00000000 from state Bridged to Finalized [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"37812fb3-cff3-4c97-b6ad-7d26c08109a6"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""37812fb3-cff3-4c97-b6ad-7d26c08109a6""}"' [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: actually destroying basic bridge, nobody wants it anymore [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: calling basic bridge destructor [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: calling simple_bridge technology stop [Aug 14 21:11:29] DEBUG[15759][C-00000000] bridge.c: Bridge 37812fb3-cff3-4c97-b6ad-7d26c08109a6: calling simple_bridge technology destructor [Aug 14 21:11:29] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 100 [Aug 14 21:11:29] DEBUG[15682] devicestate.c: Changing state for PJSIP/100 - state 2 (In use) [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Driver for channel 'PJSIP/100-00000000' does not support indication 3, emulating it [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Set channel PJSIP/100-00000000 to write format slin [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Done Masquerading PJSIP/100-00000000 (6) [Aug 14 21:11:29] DEBUG[15759][C-00000000] channel.c: Hanging up channel 'PJSIP/200-00000001' [Aug 14 21:11:29] DEBUG[15759][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4f89e6c - Beginning finalize/dispatch for PJSIP/200-00000001 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4f89e6c - Dispatching CDR for Party A PJSIP/200-00000001, Party B [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_EXIT) result is '"BRIDGE_EXIT"' [Aug 14 21:11:29] DEBUG[15685] cdr.c: CDR for PJSIP/200-00000001 is dialed and has no Party B; discarding [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"37812fb3-cff3-4c97-b6ad-7d26c08109a6"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""37812fb3-cff3-4c97-b6ad-7d26c08109a6""}"' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: PJSIP/100-00000000 Original location: pjsip_b,202,6 [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to 'context:pjsip_b exten:202' [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: Gosub exited with status 0 [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pjsip_b exten:202") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(all) result is '"CfgSIP_22" <2202>' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Function CONNECTEDLINE(tag) result is 'Radish' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is Radish") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'Gosub' [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xa11b3ec - Created CDR for channel PJSIP/100-00000000 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xa11b3ec - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xa11b3ec - Set answered time to 1408068689.064810 [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: Setting 'ARG1' to '' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Function CALLERID(tag) result is 'SIP-A' [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'NoOp' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:29] DEBUG[15760][C-00000001] pbx.c: Launching 'Return' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack [Aug 14 21:11:29] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 200 [Aug 14 21:11:29] DEBUG[15682] devicestate.c: Changing state for PJSIP/200 - state 2 (In use) [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b,202,6) exited with -1 on 'PJSIP/100-00000000' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/100-00000000' [Aug 14 21:11:29] VERBOSE[15760][C-00000001] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) complete GOSUB_RETVAL= [Aug 14 21:11:29] DEBUG[15760][C-00000001] app_stack.c: PJSIP/100-00000000 Ending location: pjsip_b,202,6 [Aug 14 21:11:29] DEBUG[15760][C-00000001] channel.c: PJSIP/100-00000000: Dropping redundant connected line update "CfgSIP_22" <2202>. [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(HANGUP) result is '"HANGUP"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE({"dialstatus":"","hangupcause":16,"hangupsource":""}) result is '"{""dialstatus"":"""",""hangupcause"":16,""hangupsource"":""""}"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 14 21:11:29] DEBUG[15757][C-00000000] app_macro.c: Spawn extension (macro-callit,s,3) exited non-zero on 'PJSIP/200-00000002' in macro 'callit' [Aug 14 21:11:29] VERBOSE[15757][C-00000000] app_macro.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/200-00000002' in macro 'callit' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_END) result is '"CHAN_END"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000001' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000001) result is '"PJSIP/200-00000001"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-orange) result is '"accountcode-orange"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] pbx.c: Spawn extension (pjsip_a,200,6) exited non-zero on 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:29] VERBOSE[15757][C-00000000] pbx.c: Spawn extension (pjsip_a, 200, 6) exited non-zero on 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.3' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.3) result is '"1408068677.3"' [Aug 14 21:11:29] DEBUG[15757][C-00000000] channel.c: Hanging up channel 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15757][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 603 Decline [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Sending response [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Method is INVITE, Response is 603 Decline [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Destroying SIP session with endpoint 200 [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4d7844c' [Aug 14 21:11:29] DEBUG[15697] rtp_engine.c: Destroyed RTP instance '0xb4d7844c' [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4b602fc - Transitioning CDR for PJSIP/200-00000002 from state Dial to Finalized [Aug 14 21:11:29] DEBUG[15685] cdr.c: Finalized CDR for PJSIP/200-00000002 - start 1408068685.814419 answer 0.000000 end 1408068689.072227 dispo NO ANSWER [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4b602fc - Beginning finalize/dispatch for PJSIP/200-00000002 [Aug 14 21:11:29] VERBOSE[15685] cdr.c: 0xb4b602fc - Dispatching CDR for Party A PJSIP/200-00000002, Party B PJSIP/202-00000003 [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(clid) result is '"CfgSIP_20" <2200>' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE("CfgSIP_20" <2200>) result is '"""CfgSIP_20"" <2200>"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(src) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_END) result is '"APP_END"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(dst) result is '200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(200) result is '"200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(dcontext) result is 'pjsip_a' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(pjsip_a) result is '"pjsip_a"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'pear' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-pear) result is '"peeraccount-pear"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(channel) result is 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(dstchannel) result is 'PJSIP/202-00000003' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(PJSIP/202-00000003) result is '"PJSIP/202-00000003"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(lastapp) result is 'Dial' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(Dial) result is '"Dial"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(lastdata) result is 'PJSIP/202,30,kKtThHb(predial)' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(PJSIP/202,30,kKtThHb(predial)) result is '"PJSIP/202,30,kKtThHb(predial)"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(start) result is '2014-08-14 21:11:25' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(2014-08-14 21:11:25) result is '"2014-08-14 21:11:25"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(answer) result is '' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(end) result is '2014-08-14 21:11:29' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(2014-08-14 21:11:29) result is '"2014-08-14 21:11:29"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(duration) result is '3' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(3) result is '"3"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(billsec) result is '0' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(0) result is '"0"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(disposition) result is 'NO ANSWER' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(NO ANSWER) result is '"NO ANSWER"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(amaflags) result is 'DOCUMENTATION' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(DOCUMENTATION) result is '"DOCUMENTATION"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(apple) result is '"apple"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(uniqueid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(userfield) result is '' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(sequence) result is '2' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CDR(WhoHungUp) result is '' [Aug 14 21:11:29] DEBUG[15685] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 200 [Aug 14 21:11:29] DEBUG[15682] devicestate.c: Changing state for PJSIP/200 - state 1 (Not in use) [Aug 14 21:11:29] DEBUG[15754] app_queue.c: Device 'PJSIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 14 21:11:29] DEBUG[15697] taskprocessor.c: destroying taskprocessor '82bfdde3-c2e7-4da8-8897-acb7c95fdd99' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_START) result is '"APP_START"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_END) result is '"APP_END"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'macro-callit' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(macro-callit) result is '"macro-callit"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is 's' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(s) result is '"s"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(HANGUP) result is '"HANGUP"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_a' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_a) result is '"pjsip_a"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(200) result is '"200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE({"dialstatus":"","hangupcause":16,"hangupsource":"PJSIP/200-00000002"}) result is '"{""dialstatus"":"""",""hangupcause"":16,""hangupsource"":""PJSIP/200-00000002""}"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CHAN_END) result is '"CHAN_END"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/200-00000002' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'orange' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-orange) result is '"peeraccount-orange"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_20' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_20) result is '"CfgSIP_20"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(2200) result is '"2200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_a' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_a) result is '"pjsip_a"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '200' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE(200) result is '"200"' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Received request [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Method is BYE [Aug 14 21:11:29] DEBUG[15697] res_pjsip_session.c: Destroying SIP session with endpoint 200 [Aug 14 21:11:29] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9586ad4' [Aug 14 21:11:29] DEBUG[15697] rtp_engine.c: Destroyed RTP instance '0x9586ad4' [Aug 14 21:11:29] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4f6dffc' [Aug 14 21:11:29] DEBUG[15697] rtp_engine.c: Destroyed RTP instance '0xb4f6dffc' [Aug 14 21:11:29] DEBUG[15697] taskprocessor.c: destroying taskprocessor '930cc823-e75a-4a1f-9a82-84b536509dba' [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:29] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:29] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:29] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15697] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 14 21:11:29] DEBUG[15697] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 200 [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:29] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15760][C-00000001] res_rtp_asterisk.c: No remote address on RTP instance '0xb4fcf0f4' so dropping frame [Aug 14 21:11:30] DEBUG[15697] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 14 21:11:30] DEBUG[15697] res_pjsip_session.c: Received response [Aug 14 21:11:30] DEBUG[15697] res_pjsip_session.c: Response is 200 OK [Aug 14 21:11:30] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4fcf0f4' [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Setting payload 0 (0x9931484) based on m type on 0xb66963b0 [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Setting payload 101 (0x98c3b0c) based on m type on 0xb66963b0 [Aug 14 21:11:30] VERBOSE[15760][C-00000001] app_dial.c: PJSIP/202-00000003 answered PJSIP/100-00000000 [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Copying payload 0 (0x989ab5c) from 0xb66963b0 to 0xb4fcf21c [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Copying payload 101 (0x993c7ac) from 0xb66963b0 to 0xb4fcf21c [Aug 14 21:11:30] VERBOSE[15685] cdr.c: 0xb457e2c4 - Set answered time to 1408068690.331018 [Aug 14 21:11:30] DEBUG[15697] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4f84684' [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Setting payload 99 (0xb4da2104) based on m type on 0xb66963b0 [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Setting payload 34 (0xb440d3c4) based on m type on 0xb66963b0 [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Copying payload 34 (0xb440d3c4) from 0xb66963b0 to 0xb4f847ac [Aug 14 21:11:30] DEBUG[15697] rtp_engine.c: Copying payload 99 (0xb4da2104) from 0xb66963b0 to 0xb4f847ac [Aug 14 21:11:30] DEBUG[15697] res_pjsip_session.c: Sending request [Aug 14 21:11:30] DEBUG[15697] res_pjsip_session.c: Method is ACK [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(ANSWER) result is '"ANSWER"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/202-00000003' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/202-00000003) result is '"PJSIP/202-00000003"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'pear' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-pear) result is '"accountcode-pear"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'green' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-green) result is '"peeraccount-green"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.14' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.14) result is '"1408068685.14"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_22' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_22) result is '"CfgSIP_22"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(2202) result is '"2202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15760][C-00000001] channel.c: Set channel PJSIP/100-00000000 to write format ulaw [Aug 14 21:11:30] DEBUG[15682] devicestate.c: No provider found, checking channel drivers for PJSIP - 202 [Aug 14 21:11:30] DEBUG[15760][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Aug 14 21:11:30] DEBUG[15682] devicestate.c: Changing state for PJSIP/202 - state 2 (In use) [Aug 14 21:11:30] DEBUG[15760][C-00000001] features.c: Removing dialed interfaces datastore on PJSIP/202-00000003 since we're bridging [Aug 14 21:11:30] DEBUG[15760][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: Cannot use native DAHDI. Must have two channels. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge_native_rtp.c: Bridge 'bcec81b8-d4dd-461f-a709-1727b5f4e56a' can not use native RTP bridge as two channels are required [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: calling simple_bridge technology constructor [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: calling simple_bridge technology start [Aug 14 21:11:30] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:30] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:30] DEBUG[15746] db.c: Unable to find key '701@default' in family 'mwi_external/mailboxes' [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge_channel.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: 0xb4f5182c(PJSIP/100-00000000) is joining [Aug 14 21:11:30] DEBUG[15754] app_queue.c: Device 'PJSIP/202' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge_channel.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: pushing 0xb4f5182c(PJSIP/100-00000000) [Aug 14 21:11:30] VERBOSE[15760][C-00000001] bridge_channel.c: Channel PJSIP/100-00000000 joined 'simple_bridge' basic-bridge [Aug 14 21:11:30] DEBUG[15760][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: Cannot use native DAHDI. Must have two channels. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge_native_rtp.c: Bridge 'bcec81b8-d4dd-461f-a709-1727b5f4e56a' can not use native RTP bridge as two channels are required [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is already using the new technology. [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is happy that channel PJSIP/100-00000000 already has read format ulaw [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is happy that channel PJSIP/100-00000000 already has write format ulaw [Aug 14 21:11:30] DEBUG[15760][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: 0xb4f5182c(PJSIP/100-00000000) is joining simple_bridge technology [Aug 14 21:11:30] VERBOSE[15685] cdr.c: Dial End message for PJSIP/100-00000000, PJSIP/202-00000003: 1408068690.00333267 [Aug 14 21:11:30] VERBOSE[15685] cdr.c: 0xa11b3ec - Processing Dial End message for channel PJSIP/100-00000000, peer PJSIP/202-00000003 [Aug 14 21:11:30] ERROR[15685] cdr.c: FRACK!, Failed assertion 0 (0) [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(APP_START) result is '"APP_START"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'pear' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-pear) result is '"peeraccount-pear"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15761][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread. [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge_channel.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: 0xb4f6f894(PJSIP/202-00000003) is joining [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge_channel.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: pushing 0xb4f6f894(PJSIP/202-00000003) [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge_channel.c: Changing channel PJSIP/202-00000003 peeraccount 'green' to match channel PJSIP/100-00000000 accountcode 'apple'. [Aug 14 21:11:30] VERBOSE[15761][C-00000001] bridge_channel.c: Channel PJSIP/202-00000003 joined 'simple_bridge' basic-bridge [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_ENTER) result is '"BRIDGE_ENTER"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/100-00000000' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'apple' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-apple) result is '"accountcode-apple"' [Aug 14 21:11:30] DEBUG[15761][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/100-00000000' has DTMF hooks. [Aug 14 21:11:30] DEBUG[15761][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: Cannot use native DAHDI. Channel 'PJSIP/100-00000000' not compatible. [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'pear' [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-pear) result is '"peeraccount-pear"' [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge_native_rtp.c: Bridge 'bcec81b8-d4dd-461f-a709-1727b5f4e56a' can not use native RTP bridge as it was forbidden while getting details [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068677.0' [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is already using the new technology. [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is happy that channel PJSIP/202-00000003 already has read format ulaw [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a is happy that channel PJSIP/202-00000003 already has write format ulaw [Aug 14 21:11:30] DEBUG[15761][C-00000001] bridge.c: Bridge bcec81b8-d4dd-461f-a709-1727b5f4e56a: 0xb4f6f894(PJSIP/202-00000003) is joining simple_bridge technology [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_10' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_10) result is '"CfgSIP_10"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(num) result is '1100' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1100) result is '"1100"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(202) result is '"202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"bcec81b8-d4dd-461f-a709-1727b5f4e56a"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""bcec81b8-d4dd-461f-a709-1727b5f4e56a""}"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(LINKEDID_END) result is '"LINKEDID_END"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/202-00000003' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/202-00000003) result is '"PJSIP/202-00000003"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'pear' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-pear) result is '"accountcode-pear"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'green' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-green) result is '"peeraccount-green"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.14' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.14) result is '"1408068685.14"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068685.11' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.11) result is '"1408068685.11"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_22' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_22) result is '"CfgSIP_22"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(2202) result is '"2202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(BRIDGE_ENTER) result is '"BRIDGE_ENTER"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(channame) result is 'PJSIP/202-00000003' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/202-00000003) result is '"PJSIP/202-00000003"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(accountcode) result is 'pear' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(accountcode-pear) result is '"accountcode-pear"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(peeraccount) result is 'apple' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(peeraccount-apple) result is '"peeraccount-apple"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(uniqueid) result is '1408068685.14' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068685.14) result is '"1408068685.14"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(linkedid) result is '1408068677.0' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(1408068677.0) result is '"1408068677.0"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(name) result is 'CfgSIP_22' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(CfgSIP_22) result is '"CfgSIP_22"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CALLERID(num) result is '2202' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(2202) result is '"2202"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(context) result is 'pjsip_b' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(pjsip_b) result is '"pjsip_b"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CHANNEL(exten) result is '' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE() result is '""' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE(PJSIP/100-00000000) result is '"PJSIP/100-00000000"' [Aug 14 21:11:30] DEBUG[15688] pbx.c: Function CSV_QUOTE({"bridge_technology":"simple_bridge","bridge_id":"bcec81b8-d4dd-461f-a709-1727b5f4e56a"}) result is '"{""bridge_technology"":""simple_bridge"",""bridge_id"":""bcec81b8-d4dd-461f-a709-1727b5f4e56a""}"' [Aug 14 21:11:30] DEBUG[15761][C-00000001] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Aug 14 21:11:30] DEBUG[15761][C-00000001] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xb4fcf0f4' [Aug 14 21:11:30] DEBUG[15761][C-00000001] res_rtp_asterisk.c: 0xb4ceee20 -- Probation learning mode pass with source address 10.24.19.251:2232 [Aug 14 21:11:30] VERBOSE[15761][C-00000001] res_rtp_asterisk.c: 0xb4ceee20 -- Probation passed - setting RTP source address to 10.24.19.251:2232 [Aug 14 21:11:30] VERBOSE[15685] logger.c: Got 14 backtrace records [Aug 14 21:11:30] VERBOSE[15685] logger.c: #0: [0x824c101] main/utils.c:2566 __ast_assert_failed() (0x824c086+7B) [Aug 14 21:11:30] VERBOSE[15685] logger.c: #1: [0x80e4514] main/cdr.c:1397 base_process_dial_end() [Aug 14 21:11:30] VERBOSE[15685] logger.c: #2: [0x80e6399] main/cdr.c:1958 handle_dial_message() [Aug 14 21:11:30] VERBOSE[15685] logger.c: #3: [0x822896d] main/stasis_message_router.c:204 router_dispatch() [Aug 14 21:11:30] VERBOSE[15685] logger.c: #3: [0x822896d] main/stasis_message_router.c:204 router_dispatch()