[Aug 14 21:01:00] 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:01:00] NOTICE[15330] loader.c: 1 modules will be loaded.
[Aug 14 21:01:00] ERROR[15330] config_options.c: Unable to load config file 'acl.conf'
[Aug 14 21:01:00] NOTICE[15330] cdr.c: CDR simple logging enabled.
[Aug 14 21:01:00] NOTICE[15330] loader.c: 260 modules will be loaded.
[Aug 14 21:01:00] WARNING[15330] loader.c: Error loading module 'res_monitor.so': /usr/lib/asterisk/modules/res_monitor.so: undefined symbol: __ast_beep_start
[Aug 14 21:01:00] NOTICE[15330] res_odbc.c: res_odbc loaded.
[Aug 14 21:01:02] NOTICE[15354] res_pjsip/pjsip_distributor.c: Request from '"202" <sip:202@10.24.21.234>' failed for '10.24.19.251:5060' (callid: 3a4fd7d2-540be985-9ec02278@10.24.19.251) - No matching endpoint found
[Aug 14 21:01:02] WARNING[15354] res_pjsip.c: No SIP authenticator registered. Assuming authentication is not required
[Aug 14 21:01:02] NOTICE[15354] res_pjsip/pjsip_distributor.c: Request from '"201" <sip:201@10.24.21.234>' failed for '10.24.19.249:5060' (callid: 8670da7c-860cd9af-af1fa022@10.24.19.249) - No matching endpoint found
[Aug 14 21:01:02] WARNING[15354] res_pjsip.c: No SIP authenticator registered. Assuming authentication is not required
[Aug 14 21:01:02] ERROR[15330] res_config_sqlite3.c: Missing config file 'res_config_sqlite3.conf'
[Aug 14 21:01:02] NOTICE[15354] res_pjsip/pjsip_distributor.c: Request from '"200" <sip:200@10.24.21.234>' failed for '10.24.19.249:5060' (callid: f5607efb-6952426e-de80bd21@10.24.19.249) - No matching endpoint found
[Aug 14 21:01:02] NOTICE[15354] res_pjsip/pjsip_distributor.c: Request from '"200" <sip:200@10.24.21.234>' failed for '10.24.19.249:5060' (callid: f5607efb-6952426e-de80bd21@10.24.19.249) - No matching endpoint found
[Aug 14 21:01:02] WARNING[15330] chan_iax2.c: Section 'cfmc_general' lacks type
[Aug 14 21:01:02] WARNING[15330] chan_iax2.c: Section 'cfmc_trunk' lacks type
[Aug 14 21:01:02] ERROR[15330] chan_dahdi.c: Unknown signalling method 'ss7' at line 51.
[Aug 14 21:01:02] ERROR[15330] chan_dahdi.c: Unknown signalling method 'ss7' at line 74.
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Detected alarm on channel 15: Red Alarm
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Detected alarm on channel 16: Red Alarm
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Detected alarm on channel 6: Red Alarm
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Detected alarm on channel 7: Red Alarm
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Detected alarm on channel 8: Red Alarm
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Ignoring any changes to 'userbase' (on reload) at line 23.
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Ignoring any changes to 'vmsecret' (on reload) at line 31.
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Ignoring any changes to 'hassip' (on reload) at line 35.
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Ignoring any changes to 'hasiax' (on reload) at line 39.
[Aug 14 21:01:02] WARNING[15330] chan_dahdi.c: Ignoring any changes to 'hasmanager' (on reload) at line 47.
[Aug 14 21:01:02] ERROR[15330] config_options.c: Unable to load config file 'pjsip_notify.conf'
[Aug 14 21:01:03] NOTICE[15330] confbridge/conf_config_parser.c: Adding default_menu menu to app_confbridge
[Aug 14 21:01:03] ERROR[15330] codec_dahdi.c: Failed to open /dev/dahdi/transcode: No such file or directory
[Aug 14 21:01:04] WARNING[15330] 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:01:04] WARNING[15330] 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:01:04] WARNING[15330] app_queue.c: Unknown keyword in queue 'ast150': eventwhencalled at line 504 of queues.conf
[Aug 14 21:01:04] WARNING[15330] app_queue.c: Unknown keyword in queue 'ast200': eventwhencalled at line 514 of queues.conf
[Aug 14 21:01:04] VERBOSE[15330] asterisk.c: Asterisk Ready.
[Aug 14 21:02:02] VERBOSE[15354] res_pjsip_registrar.c: Added contact 'sip:200@10.24.19.249:5060' to AOR '200' with expiration of 600 seconds
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Created CDR for channel PJSIP/100-00000000
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [200@pjsip_a:1] NoOp("PJSIP/100-00000000", "Extension 200 (pjsip_a)") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [200@pjsip_a:2] Gosub("PJSIP/100-00000000", "displayall,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayall:1] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayall:2] Gosub("PJSIP/100-00000000", "displayredir,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:1] NoOp("PJSIP/100-00000000", "REDIRECTING(from-all) is "" <>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:2] NoOp("PJSIP/100-00000000", "REDIRECTING(from-tag) is ") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:3] NoOp("PJSIP/100-00000000", "REDIRECTING(to-all) is "" <>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:4] NoOp("PJSIP/100-00000000", "REDIRECTING(to-tag) is ") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:5] NoOp("PJSIP/100-00000000", "REDIRECTING(count) is 0") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:6] NoOp("PJSIP/100-00000000", "REDIRECTING(reason) is unknown") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayredir:7] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displayall:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@set_interception:14] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [200@pjsip_a:4] Set("PJSIP/100-00000000", "CHANNEL(accountcode)=apple") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [200@pjsip_a:5] Set("PJSIP/100-00000000", "CHANNEL(peeraccount)=orange") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [200@pjsip_a:6] Macro("PJSIP/100-00000000", "callit,PJSIP/200,30,kKtT") in new stack
[Aug 14 21:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@macro-callit:2] Set("PJSIP/100-00000000", "DESTS=PJSIP/200") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@macro-callit:3] Dial("PJSIP/100-00000000", "PJSIP/200,30,kKtT") in new stack
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9bd0074 - Created CDR for channel PJSIP/200-00000001
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9bd0074 - Transitioning CDR for PJSIP/200-00000001 from state NONE to Single
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] app_dial.c: Called PJSIP/200
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) start
[Aug 14 21:02:31] VERBOSE[15439][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:02:31] VERBOSE[15342] cdr.c: Dial Begin message for PJSIP/100-00000000, PJSIP/200-00000001: 1408068151.00917154
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Processing Dial Begin message for channel PJSIP/100-00000000, peer PJSIP/200-00000001
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Updated Party A PJSIP/100-00000000 snapshot
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Updated Party B PJSIP/200-00000001 snapshot
[Aug 14 21:02:31] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state Single to Dial
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000'
[Aug 14 21:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pots exten:200)) start
[Aug 14 21:02:31] VERBOSE[15439][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:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:31] VERBOSE[15439][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000'
[Aug 14 21:02:31] VERBOSE[15439][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:02:32] VERBOSE[15439][C-00000000] app_dial.c: PJSIP/200-00000001 is ringing
[Aug 14 21:02:33] VERBOSE[15439][C-00000000] app_dial.c: PJSIP/200-00000001 answered PJSIP/100-00000000
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9bd0074 - Set answered time to 1408068153.486260
[Aug 14 21:02:33] VERBOSE[15439][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 joined 'simple_bridge' basic-bridge <3886c45b-d5ca-4e7e-a47f-5d367823906e>
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: Dial End message for PJSIP/100-00000000, PJSIP/200-00000001: 1408068153.00486894
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Processing Dial End message for channel PJSIP/100-00000000, peer PJSIP/200-00000001
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state Dial to DialedPending
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Set answered time to 1408068153.488474
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: Bridge Enter message for channel PJSIP/100-00000000: 1408068153.00488059
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Updating Party A PJSIP/100-00000000 snapshot
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Processing bridge enter for PJSIP/100-00000000
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state DialedPending to Dial
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state Dial to Bridged
[Aug 14 21:02:33] VERBOSE[15441][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 joined 'simple_bridge' basic-bridge <3886c45b-d5ca-4e7e-a47f-5d367823906e>
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: Bridge Enter message for channel PJSIP/200-00000001: 1408068153.00491485
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9bd0074 - Updating Party A PJSIP/200-00000001 snapshot
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9bd0074 - Processing bridge enter for PJSIP/200-00000001
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9bd0074 - Transitioning CDR for PJSIP/200-00000001 from state Single to Bridged
[Aug 14 21:02:33] VERBOSE[15342] cdr.c: 0x9a2bc2c - Party A PJSIP/100-00000000 has new Party B PJSIP/200-00000001
[Aug 14 21:02:33] VERBOSE[15441][C-00000000] res_rtp_asterisk.c: 0xb50d9b30 -- Probation passed - setting RTP source address to 10.24.19.249:2226
[Aug 14 21:02:33] VERBOSE[15439][C-00000000] res_rtp_asterisk.c: 0x9b8bdc0 -- Probation passed - setting RTP source address to 10.24.17.232:2234
[Aug 14 21:02:40] VERBOSE[15439][C-00000000] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/100-00000000'
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Created CDR for channel PJSIP/200-00000002
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Transitioning CDR for PJSIP/200-00000002 from state NONE to Single
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:1] NoOp("PJSIP/200-00000002", "Extension 202 (pjsip_b)") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:2] Gosub("PJSIP/200-00000002", "displayall,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayall:1] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayall:2] Gosub("PJSIP/200-00000002", "displayredir,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:1] NoOp("PJSIP/200-00000002", "REDIRECTING(from-all) is "" <>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:2] NoOp("PJSIP/200-00000002", "REDIRECTING(from-tag) is ") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:3] NoOp("PJSIP/200-00000002", "REDIRECTING(to-all) is "" <>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:4] NoOp("PJSIP/200-00000002", "REDIRECTING(to-tag) is ") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:5] NoOp("PJSIP/200-00000002", "REDIRECTING(count) is 0") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:6] NoOp("PJSIP/200-00000002", "REDIRECTING(reason) is unknown") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayredir:7] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displayall:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@set_interception:14] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:4] Set("PJSIP/200-00000002", "CHANNEL(accountcode)=green") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:5] Set("PJSIP/200-00000002", "CHANNEL(peeraccount)=pear") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:6] Dial("PJSIP/200-00000002", "PJSIP/202,30,kKtThHb(predial)") in new stack
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9b03064 - Created CDR for channel PJSIP/202-00000003
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9b03064 - Transitioning CDR for PJSIP/202-00000003 from state NONE to Single
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: PJSIP/202-00000003 Internal Gosub(pjsip_b,202,predial) start
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:9] Gosub("PJSIP/202-00000003", "displaycli,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/202-00000003", "CALLERID(all) is "CfgSIP_22" <2202>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/202-00000003", "CALLERID(tag) is SIP-E") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/202-00000003", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:10] Set("PJSIP/202-00000003", "CALLERID(tag)=Radish") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [202@pjsip_b:11] Return("PJSIP/202-00000003", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 1) exited non-zero on 'PJSIP/202-00000003'
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: PJSIP/202-00000003 Internal Gosub(pjsip_b,202,predial) complete GOSUB_RETVAL=
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_dial.c: Called PJSIP/202
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: Dial Begin message for PJSIP/200-00000002, PJSIP/202-00000003: 1408068164.00417433
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Processing Dial Begin message for channel PJSIP/200-00000002, peer PJSIP/202-00000003
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Updated Party A PJSIP/200-00000002 snapshot
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Updated Party B PJSIP/202-00000003 snapshot
[Aug 14 21:02:44] VERBOSE[15342] cdr.c: 0x9c6031c - Transitioning CDR for PJSIP/200-00000002 from state Single to Dial
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/200-00000002", "displaycolp,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(tag) is Radish") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/200-00000002'
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] app_stack.c: PJSIP/200-00000002 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/200-00000002", "displaycolp,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/200-00000002", "CONNECTEDLINE(tag) is Radish") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/200-00000002", "displaycli,s,1") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/200-00000002", "CALLERID(all) is "CfgSIP_20" <2200>") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/200-00000002", "CALLERID(tag) is SIP-B") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/200-00000002", "") in new stack
[Aug 14 21:02:44] VERBOSE[15442][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/200-00000002'
[Aug 14 21:02:44] VERBOSE[15442][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:02:44] VERBOSE[15442][C-00000001] app_dial.c: PJSIP/202-00000003 is ringing
[Aug 14 21:02:46] VERBOSE[15439][C-00000000] res_musiconhold.c: Stopped music on hold on PJSIP/100-00000000
[Aug 14 21:02:46] VERBOSE[15441][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 left 'simple_bridge' basic-bridge <3886c45b-d5ca-4e7e-a47f-5d367823906e>
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: Bridge Leave message for PJSIP/200-00000001: 1408068166.00015893
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9bd0074 - Processing Bridge Leave for PJSIP/200-00000001
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9bd0074 - Transitioning CDR for PJSIP/200-00000001 from state Bridged to Finalized
[Aug 14 21:02:46] VERBOSE[15439][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 left 'simple_bridge' basic-bridge <3886c45b-d5ca-4e7e-a47f-5d367823906e>
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: Bridge Leave message for PJSIP/100-00000000: 1408068166.00017031
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9a2bc2c - Processing Bridge Leave for PJSIP/100-00000000
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9a2bc2c - Transitioning CDR for PJSIP/100-00000000 from state Bridged to Finalized
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9bd0074 - Beginning finalize/dispatch for PJSIP/200-00000001
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9bd0074 - Dispatching CDR for Party A PJSIP/200-00000001, Party B <none>
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_b exten:202)) start
[Aug 14 21:02:46] VERBOSE[15442][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:02:46] VERBOSE[15342] cdr.c: 0xb4748e0c - Created CDR for channel PJSIP/100-00000000
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0xb4748e0c - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0xb4748e0c - Set answered time to 1408068166.023676
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Aug 14 21:02:46] VERBOSE[15439][C-00000000] app_macro.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/200-00000002' in macro 'callit'
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_22" <2202>") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is Radish") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Aug 14 21:02:46] VERBOSE[15442][C-00000001] app_stack.c: Spawn extension (pjsip_b, 202, 6) exited non-zero on 'PJSIP/100-00000000'
[Aug 14 21:02:46] VERBOSE[15442][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:02:46] VERBOSE[15439][C-00000000] pbx.c: Spawn extension (pjsip_a, 200, 6) exited non-zero on 'PJSIP/200-00000002'
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9c6031c - Transitioning CDR for PJSIP/200-00000002 from state Dial to Finalized
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9c6031c - Beginning finalize/dispatch for PJSIP/200-00000002
[Aug 14 21:02:46] VERBOSE[15342] cdr.c: 0x9c6031c - Dispatching CDR for Party A PJSIP/200-00000002, Party B PJSIP/202-00000003
[Aug 14 21:02:50] VERBOSE[15342] cdr.c: 0x9b03064 - Set answered time to 1408068170.129873
[Aug 14 21:02:50] VERBOSE[15442][C-00000001] app_dial.c: PJSIP/202-00000003 answered PJSIP/100-00000000
[Aug 14 21:02:50] VERBOSE[15342] cdr.c: Dial End message for PJSIP/100-00000000, PJSIP/202-00000003: 1408068170.00131831
[Aug 14 21:02:50] VERBOSE[15342] cdr.c: 0xb4748e0c - Processing Dial End message for channel PJSIP/100-00000000, peer PJSIP/202-00000003
[Aug 14 21:02:50] ERROR[15342] cdr.c: FRACK!, Failed assertion 0 (0)
[Aug 14 21:02:50] VERBOSE[15442][C-00000001] bridge_channel.c: Channel PJSIP/100-00000000 joined 'simple_bridge' basic-bridge <fab1e1e2-c6e2-4771-bc46-5759143e30a5>
[Aug 14 21:02:50] VERBOSE[15443][C-00000001] bridge_channel.c: Channel PJSIP/202-00000003 joined 'simple_bridge' basic-bridge <fab1e1e2-c6e2-4771-bc46-5759143e30a5>
[Aug 14 21:02:50] VERBOSE[15443][C-00000001] res_rtp_asterisk.c: 0xb4e608f0 -- Probation passed - setting RTP source address to 10.24.19.251:2230
[Aug 14 21:02:50] VERBOSE[15342] logger.c: Got 14 backtrace records
[Aug 14 21:02:50] VERBOSE[15342] logger.c: #0: [0x824c101] main/utils.c:2566 __ast_assert_failed() (0x824c086+7B)
[Aug 14 21:02:50] VERBOSE[15342] logger.c: #1: [0x80e4514] main/cdr.c:1397 base_process_dial_end()
[Aug 14 21:02:50] VERBOSE[15342] logger.c: #2: [0x80e6399] main/cdr.c:1958 handle_dial_message()
[Aug 14 21:02:50] VERBOSE[15342] logger.c: #3: [0x822896d] main/stasis_message_router.c:204 router_dispatch()