[Apr  6 17:56:53.369] Asterisk GIT-13-13.15.0-rc1-1403-gdcac292 built by rmudgett @ pigtest on a i686 running Linux on 2018-04-06 17:22:40 UTC
[Apr  6 17:58:04.748] DEBUG[31488] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=1 (rdata0xb4145ddc)
[Apr  6 17:58:04.748] DEBUG[31488] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002e to use for Request msg INVITE/cseq=1 (rdata0xb4145ddc)
[Apr  6 17:58:04.748] DEBUG[31486] threadpool.c: Increasing threadpool SIP's size by 5
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.17.232:5060 does not match identify 'test_identify_apply'
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.17.232:5060 does not match identify 'piglet'
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.17.232:5060 does not match identify 'test_identify_multiple'
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '100' domain '10.24.21.234'
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip_endpoint_identifier_user.c: Identified by From username '100' domain '10.24.21.234'
[Apr  6 17:58:04.749] DEBUG[31551] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002e to use for Request msg INVITE/cseq=1 (rdata0xb4111b2c)
[Apr  6 17:58:04.750] VERBOSE[31551] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '10.24.21.234'
[Apr  6 17:58:04.751] DEBUG[31551] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Apr  6 17:58:04.751] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:100@10.24.21.234
[Apr  6 17:58:04.751] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234;user=phone
[Apr  6 17:58:04.751] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:04.751] DEBUG[31551] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:04.751] DEBUG[31551] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb4aee458'
[Apr  6 17:58:04.751] DEBUG[31551] res_rtp_asterisk.c: Allocated port 14344 for RTP instance '0xb4aee458'
[Apr  6 17:58:04.751] DEBUG[31551] res_rtp_asterisk.c: Creating ICE session [::]:14344 (14344) for RTP instance '0xb4aee458'
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: RTP instance '0xb4aee458' is setup and ready to go
[Apr  6 17:58:04.855] DEBUG[31551] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb4aee458'
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bdae0
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb60bdae0
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb60bdae0
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 127 format for m type on 0xb60bdae0
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Copying payload 0 (0xb45f89e8) from 0xb60bdae0 to 0xb4aee608
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Copying payload 8 (0xb45f9bd0) from 0xb60bdae0 to 0xb4aee608
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Copying payload 18 (0xb45fb0e8) from 0xb60bdae0 to 0xb4aee608
[Apr  6 17:58:04.855] DEBUG[31551] rtp_engine.c: Copying payload 127 (0xb45fc7a0) from 0xb60bdae0 to 0xb4aee608
[Apr  6 17:58:04.855] DEBUG[31551] res_pjsip_session.c: Media stream 'audio' handled by audio
[Apr  6 17:58:04.855] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xb4aee458'
[Apr  6 17:58:04.855] DEBUG[31551] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Apr  6 17:58:04.855] DEBUG[31551] res_pjsip_session.c: Method is INVITE
[Apr  6 17:58:04.856] DEBUG[31462] threadpool.c: Increasing threadpool stasis-core's size by 1
[Apr  6 17:58:04.856] VERBOSE[31476] cdr.c: 0x8ad8810 - Created CDR for channel PJSIP/100-00000000
[Apr  6 17:58:04.856] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single
[Apr  6 17:58:04.856] DEBUG[31551] channel.c: Channel 0x8ad6060 'PJSIP/100-00000000' allocated
[Apr  6 17:58:04.856] DEBUG[31551] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/100-00000000
[Apr  6 17:58:04.857] DEBUG[31557] logger.c: CALL_ID [C-00000000] created by thread.
[Apr  6 17:58:04.857] DEBUG[31557][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread.
[Apr  6 17:58:04.858] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.858] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:1] NoOp("PJSIP/100-00000000", "Extension 200 (pjsip_a)") in new stack
[Apr  6 17:58:04.858] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.859] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:2] Gosub("PJSIP/100-00000000", "displayall,s,1") in new stack
[Apr  6 17:58:04.859] DEBUG[31557][C-00000000] app_stack.c: Channel PJSIP/100-00000000 has no datastore, so we're allocating one.
[Apr  6 17:58:04.859] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.859] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayall:1] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Apr  6 17:58:04.860] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>'
[Apr  6 17:58:04.860] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.860] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Apr  6 17:58:04.861] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(tag) result is 'SIP-A'
[Apr  6 17:58:04.861] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.861] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Apr  6 17:58:04.861] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.861] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.862] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.862] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayall:2] Gosub("PJSIP/100-00000000", "displayredir,s,1") in new stack
[Apr  6 17:58:04.863] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(from-all) result is '"" <>'
[Apr  6 17:58:04.863] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.863] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:1] NoOp("PJSIP/100-00000000", "REDIRECTING(from-all) is "" <>") in new stack
[Apr  6 17:58:04.864] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(from-tag) result is ''
[Apr  6 17:58:04.864] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.864] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:2] NoOp("PJSIP/100-00000000", "REDIRECTING(from-tag) is ") in new stack
[Apr  6 17:58:04.864] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(to-all) result is '"" <>'
[Apr  6 17:58:04.864] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.864] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:3] NoOp("PJSIP/100-00000000", "REDIRECTING(to-all) is "" <>") in new stack
[Apr  6 17:58:04.865] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(to-tag) result is ''
[Apr  6 17:58:04.865] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.865] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:4] NoOp("PJSIP/100-00000000", "REDIRECTING(to-tag) is ") in new stack
[Apr  6 17:58:04.865] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(count) result is '0'
[Apr  6 17:58:04.865] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.865] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:5] NoOp("PJSIP/100-00000000", "REDIRECTING(count) is 0") in new stack
[Apr  6 17:58:04.866] DEBUG[31557][C-00000000] pbx_variables.c: Function REDIRECTING(reason) result is 'unknown'
[Apr  6 17:58:04.866] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.866] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:6] NoOp("PJSIP/100-00000000", "REDIRECTING(reason) is unknown") in new stack
[Apr  6 17:58:04.866] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.866] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayredir:7] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.867] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.867] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displayall:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.868] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.868] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:3] Gosub("PJSIP/100-00000000", "set_interception,s,1(pjsip_a,200)") in new stack
[Apr  6 17:58:04.869] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to 'pjsip_a'
[Apr  6 17:58:04.869] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG2' to '200'
[Apr  6 17:58:04.869] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.869] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:1] NoOp("PJSIP/100-00000000", "Setting interception variables for context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.870] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.870] VERBOSE[31557][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
[Apr  6 17:58:04.871] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.871] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:3] Set("PJSIP/100-00000000", "__CONNECTED_LINE_SEND_SUB_ARGS=context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.871] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.871] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:4] Set("PJSIP/100-00000000", "__REDIRECTING_SEND_SUB=redirecting_send,s,1") in new stack
[Apr  6 17:58:04.872] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.872] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:5] Set("PJSIP/100-00000000", "__REDIRECTING_SEND_SUB_ARGS=context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.872] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.872] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:6] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLER_SEND_MACRO=connected_line_send") in new stack
[Apr  6 17:58:04.873] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.873] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:7] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLER_SEND_MACRO_ARGS=caller context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.873] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.874] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:8] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLEE_SEND_MACRO=connected_line_send") in new stack
[Apr  6 17:58:04.874] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.874] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:9] Set("PJSIP/100-00000000", "__CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS=CALLEE context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.875] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.875] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:10] Set("PJSIP/100-00000000", "__REDIRECTING_CALLER_SEND_MACRO=redirecting_send") in new stack
[Apr  6 17:58:04.875] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.875] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:11] Set("PJSIP/100-00000000", "__REDIRECTING_CALLER_SEND_MACRO_ARGS=caller context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.876] DEBUG[31462] threadpool.c: Increasing threadpool stasis-core's size by 1
[Apr  6 17:58:04.876] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.876] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:12] Set("PJSIP/100-00000000", "__REDIRECTING_CALLEE_SEND_MACRO=redirecting_send") in new stack
[Apr  6 17:58:04.876] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.876] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:13] Set("PJSIP/100-00000000", "__REDIRECTING_CALLEE_SEND_MACRO_ARGS=CALLEE context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.877] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.877] VERBOSE[31557][C-00000000] pbx.c: Executing [s@set_interception:14] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.877] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.878] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:4] Set("PJSIP/100-00000000", "CHANNEL(accountcode)=apple") in new stack
[Apr  6 17:58:04.878] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.878] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:5] Set("PJSIP/100-00000000", "CHANNEL(peeraccount)=orange") in new stack
[Apr  6 17:58:04.879] DEBUG[31557][C-00000000] pbx.c: Launching 'Macro'
[Apr  6 17:58:04.879] VERBOSE[31557][C-00000000] pbx.c: Executing [200@pjsip_a:6] Macro("PJSIP/100-00000000", "callit,PJSIP/200,30") in new stack
[Apr  6 17:58:04.880] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.880] VERBOSE[31557][C-00000000] pbx.c: Executing [s@macro-callit:1] NoOp("PJSIP/100-00000000", "Requested to call PJSIP/200,30,  CC_INTERFACES is ") in new stack
[Apr  6 17:58:04.881] DEBUG[31557][C-00000000] app_macro.c: Executed application: NoOp
[Apr  6 17:58:04.881] DEBUG[31557][C-00000000] pbx_variables.c: Function EXISTS() result is '0'
[Apr  6 17:58:04.881] DEBUG[31557][C-00000000] pbx_variables.c: Function IF(0?:PJSIP/200) result is 'PJSIP/200'
[Apr  6 17:58:04.881] DEBUG[31557][C-00000000] pbx.c: Launching 'Set'
[Apr  6 17:58:04.881] VERBOSE[31557][C-00000000] pbx.c: Executing [s@macro-callit:2] Set("PJSIP/100-00000000", "DESTS=PJSIP/200") in new stack
[Apr  6 17:58:04.882] DEBUG[31557][C-00000000] app_macro.c: Executed application: Set
[Apr  6 17:58:04.882] DEBUG[31557][C-00000000] pbx.c: Launching 'Dial'
[Apr  6 17:58:04.882] VERBOSE[31557][C-00000000] pbx.c: Executing [s@macro-callit:3] Dial("PJSIP/100-00000000", "PJSIP/200,30,") in new stack
[Apr  6 17:58:04.884] DEBUG[31551] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Apr  6 17:58:04.884] DEBUG[31551] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Apr  6 17:58:04.884] DEBUG[31551] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0)
[Apr  6 17:58:04.884] DEBUG[31551] config.c: extract uint from [0] in [0, 86400] gives [0](0)
[Apr  6 17:58:04.884] DEBUG[31551] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Apr  6 17:58:04.885] DEBUG[31557][C-00000000] channel.c: Channel 0xb4122590 'PJSIP/200-00000001' allocated
[Apr  6 17:58:04.885] VERBOSE[31476] cdr.c: 0x8a49278 - Created CDR for channel PJSIP/200-00000001
[Apr  6 17:58:04.885] VERBOSE[31476] cdr.c: 0x8a49278 - Transitioning CDR for PJSIP/200-00000001 from state NONE to Single
[Apr  6 17:58:04.886] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_CALLEE_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.886] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_CALLEE_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.886] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_CALLER_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.887] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_CALLER_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.887] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_CALLEE_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.887] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_CALLEE_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.887] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_CALLER_SEND_MACRO_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.888] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_CALLER_SEND_MACRO from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.888] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_SEND_SUB_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.888] DEBUG[31557][C-00000000] channel.c: Inheriting variable __REDIRECTING_SEND_SUB from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.888] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_SEND_SUB_ARGS from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.888] DEBUG[31557][C-00000000] channel.c: Inheriting variable __CONNECTED_LINE_SEND_SUB from PJSIP/100-00000000 to PJSIP/200-00000001.
[Apr  6 17:58:04.889] DEBUG[31551] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x89d9b18'
[Apr  6 17:58:04.889] DEBUG[31551] res_rtp_asterisk.c: Allocated port 19556 for RTP instance '0x89d9b18'
[Apr  6 17:58:04.889] DEBUG[31551] res_rtp_asterisk.c: Creating ICE session [::]:19556 (19556) for RTP instance '0x89d9b18'
[Apr  6 17:58:04.890] VERBOSE[31476] cdr.c: Dial Begin message for PJSIP/100-00000000, PJSIP/200-00000001: 1523055484.00890204
[Apr  6 17:58:04.890] VERBOSE[31476] cdr.c: 0x8ad8810 - Processing Dial Begin message for channel PJSIP/100-00000000, peer PJSIP/200-00000001
[Apr  6 17:58:04.890] VERBOSE[31476] cdr.c: 0x8ad8810 - Updated Party A PJSIP/100-00000000 snapshot
[Apr  6 17:58:04.890] VERBOSE[31476] cdr.c: 0x8ad8810 - Updated Party B PJSIP/200-00000001 snapshot
[Apr  6 17:58:04.890] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state Single to Dial
[Apr  6 17:58:04.890] VERBOSE[31557][C-00000000] app_dial.c: Called PJSIP/200
[Apr  6 17:58:04.890] VERBOSE[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) start
[Apr  6 17:58:04.890] DEBUG[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Original location: macro-callit,s,3
[Apr  6 17:58:04.890] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to 'context:pjsip_a exten:200'
[Apr  6 17:58:04.891] DEBUG[31557][C-00000000] app_stack.c: Gosub exited with status 0
[Apr  6 17:58:04.891] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.891] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pjsip_a exten:200") in new stack
[Apr  6 17:58:04.891] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.891] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Apr  6 17:58:04.891] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:04.891] DEBUG[31557][C-00000000] pbx_variables.c: Function CONNECTEDLINE(all) result is '"CfgSIP_20" <2200>'
[Apr  6 17:58:04.892] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.892] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack
[Apr  6 17:58:04.892] DEBUG[31557][C-00000000] pbx_variables.c: Function CONNECTEDLINE(tag) result is 'SIP-B'
[Apr  6 17:58:04.892] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.892] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack
[Apr  6 17:58:04.892] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.892] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.893] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:04.893] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Apr  6 17:58:04.893] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:04.893] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>'
[Apr  6 17:58:04.893] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.893] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Apr  6 17:58:04.894] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(tag) result is 'SIP-A'
[Apr  6 17:58:04.894] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:04.894] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Apr  6 17:58:04.894] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.894] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.894] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:04.894] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:04.895] DEBUG[31557][C-00000000] app_stack.c: Spawn extension (macro-callit,s,3) exited with -1 on 'PJSIP/100-00000000'
[Apr  6 17:58:04.895] VERBOSE[31557][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000'
[Apr  6 17:58:04.895] VERBOSE[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) complete GOSUB_RETVAL=
[Apr  6 17:58:04.895] DEBUG[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Ending location: macro-callit,s,3
[Apr  6 17:58:04.995] DEBUG[31551] rtp_engine.c: RTP instance '0x89d9b18' is setup and ready to go
[Apr  6 17:58:04.995] DEBUG[31551] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x89d9b18'
[Apr  6 17:58:04.995] DEBUG[31551] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x8ad1080'
[Apr  6 17:58:04.995] DEBUG[31551] res_rtp_asterisk.c: Allocated port 15340 for RTP instance '0x8ad1080'
[Apr  6 17:58:04.995] DEBUG[31551] res_rtp_asterisk.c: Creating ICE session [::]:15340 (15340) for RTP instance '0x8ad1080'
[Apr  6 17:58:05.100] DEBUG[31551] rtp_engine.c: RTP instance '0x8ad1080' is setup and ready to go
[Apr  6 17:58:05.100] DEBUG[31551] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x8ad1080'
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip_session.c: Method is INVITE
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:asterisk@10.24.21.234:5060
[Apr  6 17:58:05.101] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:05.102] VERBOSE[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) start
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Original location: macro-callit,s,3
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to 'context:pjsip_a exten:200'
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] app_stack.c: Gosub exited with status 0
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:05.102] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pjsip_a exten:200") in new stack
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:05.102] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] pbx_variables.c: Function CONNECTEDLINE(all) result is '"CfgSIP_20" <2200>'
[Apr  6 17:58:05.102] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:05.102] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "CfgSIP_20" <2200>") in new stack
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx_variables.c: Function CONNECTEDLINE(tag) result is 'SIP-B'
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:05.103] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:05.103] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx.c: Launching 'Gosub'
[Apr  6 17:58:05.103] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>'
[Apr  6 17:58:05.103] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:05.103] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Apr  6 17:58:05.104] DEBUG[31557][C-00000000] pbx_variables.c: Function CALLERID(tag) result is 'SIP-A'
[Apr  6 17:58:05.104] DEBUG[31557][C-00000000] pbx.c: Launching 'NoOp'
[Apr  6 17:58:05.104] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Apr  6 17:58:05.104] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:05.104] VERBOSE[31557][C-00000000] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:05.104] DEBUG[31557][C-00000000] pbx.c: Launching 'Return'
[Apr  6 17:58:05.104] VERBOSE[31557][C-00000000] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:05.106] DEBUG[31557][C-00000000] app_stack.c: Spawn extension (macro-callit,s,3) exited with -1 on 'PJSIP/100-00000000'
[Apr  6 17:58:05.106] VERBOSE[31557][C-00000000] app_stack.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/100-00000000'
[Apr  6 17:58:05.106] VERBOSE[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) complete GOSUB_RETVAL=
[Apr  6 17:58:05.106] DEBUG[31557][C-00000000] app_stack.c: PJSIP/100-00000000 Ending location: macro-callit,s,3
[Apr  6 17:58:05.107] DEBUG[31557][C-00000000] channel.c: PJSIP/100-00000000: Dropping redundant connected line update "CfgSIP_20" <2200>.
[Apr  6 17:58:05.108] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Response msg 100/INVITE/cseq=19950 (rdata0xb41000bc)
[Apr  6 17:58:05.108] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:05.108] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:05.108] DEBUG[31551] res_pjsip_session.c: Response is 100 Trying
[Apr  6 17:58:05.149] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Response msg 180/INVITE/cseq=19950 (rdata0xb42e23e4)
[Apr  6 17:58:05.149] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:05.150] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Apr  6 17:58:05.150] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:05.150] DEBUG[31551] res_pjsip_session.c: Response is 180 ringing
[Apr  6 17:58:05.150] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:05.150] DEBUG[31551] res_pjsip_session.c: Response is 180 ringing
[Apr  6 17:58:05.150] VERBOSE[31557][C-00000000] app_dial.c: PJSIP/200-00000001 is ringing
[Apr  6 17:58:05.150] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 200
[Apr  6 17:58:05.150] DEBUG[31473] devicestate.c: Changing state for PJSIP/200 - state 6 (Ringing)
[Apr  6 17:58:05.150] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 100
[Apr  6 17:58:05.150] DEBUG[31473] devicestate.c: Changing state for PJSIP/100 - state 2 (In use)
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing
[Apr  6 17:58:05.151] DEBUG[31535] app_queue.c: Removed May Flowers from pending_members
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:100@10.24.21.234
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234;user=phone
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:05.151] DEBUG[31535] app_queue.c: Device 'PJSIP/200' changed to state '6' (Ringing)
[Apr  6 17:58:05.151] DEBUG[31535] 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.
[Apr  6 17:58:05.151] DEBUG[31535] app_queue.c: Device 'Queue:ast150_avail' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip_pubsub.c: evsub 0xb4284364 state ACTIVE event USER sub_tree 0xb4b35700 sub_tree state Normal
[Apr  6 17:58:05.151] DEBUG[31552] res_pjsip_pubsub.c: Updating persistence for '200->200'  prune on restart: no
[Apr  6 17:58:05.157] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8ac1ea4 for Response msg 200/NOTIFY/cseq=23882 (rdata0xb41ca424)
[Apr  6 17:58:05.157] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000034 associated with dialog dlg0x8ac1ea4
[Apr  6 17:58:07.343] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Response msg 200/INVITE/cseq=19950 (rdata0xb41e4bcc)
[Apr  6 17:58:07.343] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:07.344] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89d9b18'
[Apr  6 17:58:07.344] DEBUG[31551] acl.c: For destination '10.24.16.18', our source address is '10.24.21.234'.
[Apr  6 17:58:07.344] DEBUG[31551] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x89d9b18'
[Apr  6 17:58:07.344] VERBOSE[31551] res_rtp_asterisk.c: 0x8b8ae78 -- Strict RTP learning after remote address set to: 10.24.16.18:4058
[Apr  6 17:58:07.344] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bd390
[Apr  6 17:58:07.344] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0xb60bd390
[Apr  6 17:58:07.344] DEBUG[31551] rtp_engine.c: Copying payload 0 (0x89e7598) from 0xb60bd390 to 0x89d9cc8
[Apr  6 17:58:07.344] DEBUG[31551] rtp_engine.c: Copying payload 96 (0x89f7e50) from 0xb60bd390 to 0x89d9cc8
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:07.344] DEBUG[31551] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:07.345] DEBUG[31551] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:07.346] VERBOSE[31557][C-00000000] app_dial.c: PJSIP/200-00000001 answered PJSIP/100-00000000
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:07.346] VERBOSE[31476] cdr.c: 0x8a49278 - Set answered time to 1523055487.346786
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:07.346] VERBOSE[31476] cdr.c: Dial End message for PJSIP/100-00000000, PJSIP/200-00000001: 1523055487.00346400
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:07.346] VERBOSE[31476] cdr.c: 0x8ad8810 - Processing Dial End message for channel PJSIP/100-00000000, peer PJSIP/200-00000001
[Apr  6 17:58:07.346] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state Dial to DialedPending
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:07.346] VERBOSE[31476] cdr.c: 0x8ad8810 - Set answered time to 1523055487.346939
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:07.346] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.347] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 200
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is ''
[Apr  6 17:58:07.347] DEBUG[31473] devicestate.c: Changing state for PJSIP/200 - state 2 (In use)
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:07.347] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 100
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:07.347] DEBUG[31473] devicestate.c: Changing state for PJSIP/100 - state 2 (In use)
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'AppDial'
[Apr  6 17:58:07.347] DEBUG[31552] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:07.347] DEBUG[31552] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xb4aee458'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE(AppDial) result is 'AppDial'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is '(Outgoing Line)'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function URIENCODE((Outgoing Line)) result is '(Outgoing%20Line)'
[Apr  6 17:58:07.347] DEBUG[31552] acl.c: For destination '10.24.17.232', our source address is '10.24.21.234'.
[Apr  6 17:58:07.347] DEBUG[31552] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb4aee458'
[Apr  6 17:58:07.347] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:07.348] VERBOSE[31552] res_rtp_asterisk.c: 0xb4276d70 -- Strict RTP learning after remote address set to: 10.24.17.232:2234
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb5e49570
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'orange'
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb5e49570
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb5e49570
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'apple'
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Don't have a default tx payload type 127 format for m type on 0xb5e49570
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Copying payload 0 (0xb45fa838) from 0xb5e49570 to 0xb4aee608
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Copying payload 8 (0xb45f8388) from 0xb5e49570 to 0xb4aee608
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Copying payload 18 (0xb458ea80) from 0xb5e49570 to 0xb4aee608
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.348] DEBUG[31552] rtp_engine.c: Copying payload 127 (0xb458f330) from 0xb5e49570 to 0xb4aee608
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.1) result is '1523055484.1'
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:07.348] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:100@10.24.21.234
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234;user=phone
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:07.348] DEBUG[31552] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip_pubsub.c: evsub 0xb4284364 state ACTIVE event USER sub_tree 0xb4b35700 sub_tree state Normal
[Apr  6 17:58:07.349] DEBUG[31552] res_pjsip_pubsub.c: Updating persistence for '200->200'  prune on restart: no
[Apr  6 17:58:07.349] DEBUG[31535] app_queue.c: Removed May Flowers from pending_members
[Apr  6 17:58:07.350] DEBUG[31535] app_queue.c: Device 'PJSIP/200' changed to state '2' (In use)
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_10'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_10) result is 'CfgSIP_10'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '1100'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '1100'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '200'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(s) result is 's'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(macro-callit) result is 'macro-callit'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/100-00000000) result is 'PJSIP%2F100-00000000'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'Dial'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(Dial) result is 'Dial'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'PJSIP/200,30,'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200,30,) result is 'PJSIP%2F200%2C30%2C'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:07.351] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'orange'
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:07.352] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Must have two channels.
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as two channels are required
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping.
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: calling simple_bridge technology constructor
[Apr  6 17:58:07.352] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: calling simple_bridge technology start
[Apr  6 17:58:07.353] DEBUG[31560][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread.
[Apr  6 17:58:07.353] DEBUG[31560][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8c3a8d0(PJSIP/200-00000001) is joining
[Apr  6 17:58:07.353] DEBUG[31560][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: pushing 0x8c3a8d0(PJSIP/200-00000001)
[Apr  6 17:58:07.353] VERBOSE[31560][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 joined 'simple_bridge' basic-bridge <21422ef6-ea78-4946-a644-d043d0a37da0>
[Apr  6 17:58:07.354] VERBOSE[31476] cdr.c: Bridge Enter message for channel PJSIP/200-00000001: 1523055487.00354025
[Apr  6 17:58:07.354] VERBOSE[31476] cdr.c: 0x8a49278 - Updating Party A PJSIP/200-00000001 snapshot
[Apr  6 17:58:07.354] VERBOSE[31476] cdr.c: 0x8a49278 - Processing bridge enter for PJSIP/200-00000001
[Apr  6 17:58:07.354] VERBOSE[31476] cdr.c: 0x8a49278 - Transitioning CDR for PJSIP/200-00000001 from state Single to Bridged
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is ''
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.354] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'AppDial'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(AppDial) result is 'AppDial'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is '(Outgoing Line)'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE((Outgoing Line)) result is '(Outgoing%20Line)'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'orange'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'apple'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"simple_bridge","bridge_id":"21422ef6-ea78-4946-a644-d043d0a37da0"}) result is '%7B%22bridge_technology%22%3A%22simple_bridge%22%2C%22bridge_id%22%3A%2221422ef6-ea78-4946-a644-d043d0a37da0%22%7D'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.1) result is '1523055484.1'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:07.355] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Must have two channels.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as two channels are required
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is already using the new technology.
[Apr  6 17:58:07.356] DEBUG[31560][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8c3a8d0(PJSIP/200-00000001) is joining simple_bridge technology
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8a09060(PJSIP/100-00000000) is joining
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: pushing 0x8a09060(PJSIP/100-00000000)
[Apr  6 17:58:07.357] VERBOSE[31557][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 joined 'simple_bridge' basic-bridge <21422ef6-ea78-4946-a644-d043d0a37da0>
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/200-00000001' is not DAHDI.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Channel 'PJSIP/200-00000001' not compatible.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0'.  Checking compatability for channels 'PJSIP/200-00000001' and 'PJSIP/100-00000000'
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as it was forbidden while getting details
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is already using the new technology.
[Apr  6 17:58:07.357] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8a09060(PJSIP/100-00000000) is joining simple_bridge technology
[Apr  6 17:58:07.358] VERBOSE[31476] cdr.c: Bridge Enter message for channel PJSIP/100-00000000: 1523055487.00357281
[Apr  6 17:58:07.358] VERBOSE[31476] cdr.c: 0x8ad8810 - Updating Party A PJSIP/100-00000000 snapshot
[Apr  6 17:58:07.358] VERBOSE[31476] cdr.c: 0x8ad8810 - Processing bridge enter for PJSIP/100-00000000
[Apr  6 17:58:07.358] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state DialedPending to Dial
[Apr  6 17:58:07.358] DEBUG[31476] cdr.c: Finalized CDR for PJSIP/200-00000001 - start 1523055484.885897 answer 1523055487.346786 end 1523055487.358490 dispo ANSWERED
[Apr  6 17:58:07.358] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state Dial to Bridged
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_10'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_10) result is 'CfgSIP_10'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '1100'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '1100'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:07.359] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '200'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(s) result is 's'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(macro-callit) result is 'macro-callit'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/100-00000000) result is 'PJSIP%2F100-00000000'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'Dial'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(Dial) result is 'Dial'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'PJSIP/200,30,'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200,30,) result is 'PJSIP%2F200%2C30%2C'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'orange'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is 'PJSIP/200-00000001'
[Apr  6 17:58:07.360] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:07.361] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"simple_bridge","bridge_id":"21422ef6-ea78-4946-a644-d043d0a37da0"}) result is '%7B%22bridge_technology%22%3A%22simple_bridge%22%2C%22bridge_id%22%3A%2221422ef6-ea78-4946-a644-d043d0a37da0%22%7D'
[Apr  6 17:58:07.361] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.361] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:07.361] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:07.361] VERBOSE[31560][C-00000000] res_rtp_asterisk.c: 0x8b8ae78 -- Strict RTP switching to RTP target address 10.24.16.18:4058 as source
[Apr  6 17:58:07.362] DEBUG[31557][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to ulaw
[Apr  6 17:58:07.362] DEBUG[31557][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xb4aee458'
[Apr  6 17:58:07.367] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0xb4b05c24 for Request msg ACK/cseq=1 (rdata0xb41f663c)
[Apr  6 17:58:07.367] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0xb4b05c24
[Apr  6 17:58:07.367] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:07.367] DEBUG[31551] res_pjsip_session.c: Method is ACK
[Apr  6 17:58:07.422] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8ac1ea4 for Response msg 200/NOTIFY/cseq=23883 (rdata0xb41640a4)
[Apr  6 17:58:07.422] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000034 associated with dialog dlg0x8ac1ea4
[Apr  6 17:58:07.496] VERBOSE[31557][C-00000000] res_rtp_asterisk.c: 0xb4276d70 -- Strict RTP switching to RTP target address 10.24.17.232:2234 as source
[Apr  6 17:58:07.496] DEBUG[31560][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to ulaw
[Apr  6 17:58:07.919] DEBUG[31560][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 10.24.16.18:4059
[Apr  6 17:58:11.229] DEBUG[31560][C-00000000] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 10.24.16.18:4059
[Apr  6 17:58:11.367] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Request msg INVITE/cseq=21945 (rdata0xb4175b14)
[Apr  6 17:58:11.367] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:11.368] DEBUG[31551] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:11.368] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89d9b18'
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 111 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 118 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Setting tx payload type 9 based on m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0xb60bd780
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 0 (0x8cfc838) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 8 (0x8a2b890) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 9 (0x8da1c48) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 18 (0x89d6d78) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 58 (0x8cd2320) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 96 (0xb425af18) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.368] DEBUG[31551] rtp_engine.c: Copying payload 111 (0x8a040b0) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.369] DEBUG[31551] rtp_engine.c: Copying payload 118 (0x88d4518) from 0xb60bd780 to 0x89d9cc8
[Apr  6 17:58:11.369] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/200-00000001' is not DAHDI.
[Apr  6 17:58:11.369] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Channel 'PJSIP/200-00000001' not compatible.
[Apr  6 17:58:11.369] DEBUG[31551] res_pjsip_session.c: Media stream 'audio' handled by audio
[Apr  6 17:58:11.369] DEBUG[31551] res_pjsip_session.c: Negotiating incoming SDP media stream 'video' using video SDP handler
[Apr  6 17:58:11.369] DEBUG[31551] res_pjsip_sdp_rtp.c: Media stream 'video' is already declined
[Apr  6 17:58:11.369] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89d9b18'
[Apr  6 17:58:11.369] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x8ad1080'
[Apr  6 17:58:11.369] DEBUG[31551] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Apr  6 17:58:11.369] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:11.369] DEBUG[31551] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:11.369] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89d9b18'
[Apr  6 17:58:11.369] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0'.  Checking compatability for channels 'PJSIP/200-00000001' and 'PJSIP/100-00000000'
[Apr  6 17:58:11.370] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as it was forbidden while getting details
[Apr  6 17:58:11.370] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:11.370] DEBUG[31551] acl.c: For destination '10.24.16.18', our source address is '10.24.21.234'.
[Apr  6 17:58:11.370] DEBUG[31560][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:11.370] DEBUG[31551] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x89d9b18'
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 111 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 118 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Setting tx payload type 9 based on m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0xb60bd2a0
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 0 (0xb42ca8d0) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 8 (0xb4c030f8) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 9 (0xb455ad38) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 18 (0xb45efe70) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 58 (0xb4548bb8) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 96 (0xb44fafa0) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 111 (0xb4259290) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.370] DEBUG[31551] rtp_engine.c: Copying payload 118 (0xb4258a88) from 0xb60bd2a0 to 0x89d9cc8
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:asterisk@10.24.21.234:5060
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:11.371] DEBUG[31551] res_pjsip_session.c: Method is INVITE
[Apr  6 17:58:11.370] DEBUG[31560][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Apr  6 17:58:11.372] DEBUG[31560][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:11.372] DEBUG[31560][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is already using the new technology.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Channel 'PJSIP/200-00000001' is not DAHDI.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Channel 'PJSIP/200-00000001' not compatible.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0'.  Checking compatability for channels 'PJSIP/200-00000001' and 'PJSIP/100-00000000'
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as it was forbidden while getting details
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:11.373] DEBUG[31560][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is already using the new technology.
[Apr  6 17:58:11.376] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.376] DEBUG[31535] 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.
[Apr  6 17:58:11.376] VERBOSE[31557][C-00000000] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/100-00000000'
[Apr  6 17:58:11.377] DEBUG[31557][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:11.395] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.397] DEBUG[31557][C-00000000] channel.c: Channel PJSIP/100-00000000 setting write format path: slin -> ulaw
[Apr  6 17:58:11.398] DEBUG[31557][C-00000000] res_musiconhold.c: PJSIP/100-00000000 Opened file 0 '/var/lib/asterisk/moh/reno_project-system'
[Apr  6 17:58:11.398] DEBUG[31557][C-00000000] res_rtp_asterisk.c: Difference is 928, ms is 136
[Apr  6 17:58:11.409] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Request msg ACK/cseq=21945 (rdata0xb4187584)
[Apr  6 17:58:11.409] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:11.415] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.435] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.455] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.495] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.515] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.535] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.555] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.575] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.595] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.615] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.635] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.655] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.675] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.695] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.715] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.735] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.745] DEBUG[31557][C-00000000] res_rtp_asterisk.c: Got RTCP report of 92 bytes from 10.24.17.232:2235
[Apr  6 17:58:11.755] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.775] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.795] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.815] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.835] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.855] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.875] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.895] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.915] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.935] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.955] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.975] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:11.995] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.015] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.035] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.055] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.075] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.095] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.115] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.135] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.155] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.175] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.195] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.215] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.235] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.255] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.275] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.295] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.315] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.335] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.355] VERBOSE[31557][C-00000000] res_rtp_asterisk.c: 0xb4276d70 -- Strict RTP learning complete - Locking on source address 10.24.17.232:2234
[Apr  6 17:58:12.355] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.375] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.395] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.415] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.435] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.455] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.495] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.515] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.535] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.555] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.575] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.595] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.615] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.635] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.655] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.675] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.695] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.715] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.735] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.755] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.775] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.795] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.815] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.835] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.855] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.875] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.895] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.915] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.935] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.955] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.975] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:12.995] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.015] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.035] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.055] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.075] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.095] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.115] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.135] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.155] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.175] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.195] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.215] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.235] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.255] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.275] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.295] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.315] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.335] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.355] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.375] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.395] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.415] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.435] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.450] DEBUG[31488] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=2792 (rdata0xb42e23d4)
[Apr  6 17:58:13.450] DEBUG[31488] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000040 to use for Request msg INVITE/cseq=2792 (rdata0xb42e23d4)
[Apr  6 17:58:13.450] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.16.18:5060 does not match identify 'test_identify_apply'
[Apr  6 17:58:13.450] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.16.18:5060 does not match identify 'piglet'
[Apr  6 17:58:13.450] DEBUG[31551] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.16.18:5060 does not match identify 'test_identify_multiple'
[Apr  6 17:58:13.450] DEBUG[31551] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '200' domain '10.24.21.234'
[Apr  6 17:58:13.450] DEBUG[31551] res_pjsip_endpoint_identifier_user.c: Identified by From username '200' domain '10.24.21.234'
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000040 to use for Request msg INVITE/cseq=2792 (rdata0xb41dbe94)
[Apr  6 17:58:13.451] VERBOSE[31551] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '10.24.21.234'
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:735@10.24.21.234
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:13.451] DEBUG[31551] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:13.452] DEBUG[31551] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x8a9da98'
[Apr  6 17:58:13.452] DEBUG[31551] res_rtp_asterisk.c: Allocated port 10316 for RTP instance '0x8a9da98'
[Apr  6 17:58:13.452] DEBUG[31551] res_rtp_asterisk.c: Creating ICE session [::]:10316 (10316) for RTP instance '0x8a9da98'
[Apr  6 17:58:13.455] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.495] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.515] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.535] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.555] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.556] DEBUG[31551] rtp_engine.c: RTP instance '0x8a9da98' is setup and ready to go
[Apr  6 17:58:13.556] DEBUG[31551] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x8a9da98'
[Apr  6 17:58:13.556] DEBUG[31551] rtp_engine.c: Setting tx payload type 111 based on m type on 0xb60bdae0
[Apr  6 17:58:13.556] DEBUG[31551] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb60bdae0
[Apr  6 17:58:13.556] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Setting tx payload type 118 based on m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Setting tx payload type 9 based on m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0xb60bdae0
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 0 (0x88c9718) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 8 (0x8998180) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 9 (0x8a258f8) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 18 (0x8d3dda0) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 58 (0x8aaaf80) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 96 (0x8aca1e0) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 111 (0x8b8dc18) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] rtp_engine.c: Copying payload 118 (0x8a06100) from 0xb60bdae0 to 0x8a9dc48
[Apr  6 17:58:13.557] DEBUG[31551] res_pjsip_session.c: Media stream 'audio' handled by audio
[Apr  6 17:58:13.557] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x8a9da98'
[Apr  6 17:58:13.557] DEBUG[31551] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Apr  6 17:58:13.557] DEBUG[31551] res_pjsip_session.c: Method is INVITE
[Apr  6 17:58:13.558] DEBUG[31551] channel.c: Channel 0x8b5a400 'PJSIP/200-00000002' allocated
[Apr  6 17:58:13.558] VERBOSE[31476] cdr.c: 0x8b5b150 - Created CDR for channel PJSIP/200-00000002
[Apr  6 17:58:13.558] DEBUG[31551] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/200-00000002
[Apr  6 17:58:13.558] VERBOSE[31476] cdr.c: 0x8b5b150 - Transitioning CDR for PJSIP/200-00000002 from state NONE to Single
[Apr  6 17:58:13.559] DEBUG[31561] logger.c: CALL_ID [C-00000001] created by thread.
[Apr  6 17:58:13.559] DEBUG[31561][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread.
[Apr  6 17:58:13.559] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.559] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:1] NoOp("PJSIP/200-00000002", "Extension 735 (pjsip_b)") in new stack
[Apr  6 17:58:13.560] DEBUG[31561][C-00000001] pbx.c: Launching 'Set'
[Apr  6 17:58:13.560] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:2] Set("PJSIP/200-00000002", "CONFBRIDGE(user,music_on_hold_when_empty)=yes") in new stack
[Apr  6 17:58:13.560] DEBUG[31561][C-00000001] pbx_variables.c: Function CONFBRIDGE_INFO(parties,rpm_testing) result is '0'
[Apr  6 17:58:13.560] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.560] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:3] NoOp("PJSIP/200-00000002", "CONFBRIDGE_INFO(parties,rpm_testing) is 0") in new stack
[Apr  6 17:58:13.561] DEBUG[31561][C-00000001] pbx_variables.c: Function CONFBRIDGE_INFO(admins,rpm_testing) result is '0'
[Apr  6 17:58:13.561] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.561] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:4] NoOp("PJSIP/200-00000002", "CONFBRIDGE_INFO(admins,rpm_testing) is 0") in new stack
[Apr  6 17:58:13.561] DEBUG[31561][C-00000001] pbx_variables.c: Function CONFBRIDGE_INFO(marked,rpm_testing) result is '0'
[Apr  6 17:58:13.561] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.562] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:5] NoOp("PJSIP/200-00000002", "CONFBRIDGE_INFO(marked,rpm_testing) is 0") in new stack
[Apr  6 17:58:13.562] DEBUG[31561][C-00000001] pbx_variables.c: Function CONFBRIDGE_INFO(locked,rpm_testing) result is '0'
[Apr  6 17:58:13.562] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.562] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:6] NoOp("PJSIP/200-00000002", "CONFBRIDGE_INFO(locked,rpm_testing) is 0") in new stack
[Apr  6 17:58:13.563] DEBUG[31561][C-00000001] pbx_variables.c: Function CONFBRIDGE_INFO(muted,rpm_testing) result is '0'
[Apr  6 17:58:13.563] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:13.563] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:7] NoOp("PJSIP/200-00000002", "CONFBRIDGE_INFO(muted,rpm_testing) is 0") in new stack
[Apr  6 17:58:13.563] DEBUG[31561][C-00000001] pbx.c: Launching 'ConfBridge'
[Apr  6 17:58:13.563] VERBOSE[31561][C-00000001] pbx.c: Executing [735@pjsip_b:8] ConfBridge("PJSIP/200-00000002", "rpm_testing,,,sample_user_menu") in new stack
[Apr  6 17:58:13.564] VERBOSE[31476] cdr.c: 0x8b5b150 - Set answered time to 1523055493.564207
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:13.564] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '735'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000002) result is 'PJSIP%2F200-00000002'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'ConfBridge'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(ConfBridge) result is 'ConfBridge'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'rpm_testing,,,sample_user_menu'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(rpm_testing,,,sample_user_menu) result is 'rpm_testing%2C%2C%2Csample_user_menu'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055493.6'
[Apr  6 17:58:13.565] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:13.566] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 200
[Apr  6 17:58:13.566] DEBUG[31473] devicestate.c: Changing state for PJSIP/200 - state 2 (In use)
[Apr  6 17:58:13.566] DEBUG[31551] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:13.566] DEBUG[31551] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x8a9da98'
[Apr  6 17:58:13.566] DEBUG[31551] acl.c: For destination '10.24.16.18', our source address is '10.24.21.234'.
[Apr  6 17:58:13.566] DEBUG[31551] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x8a9da98'
[Apr  6 17:58:13.567] VERBOSE[31551] res_rtp_asterisk.c: 0x8aafc40 -- Strict RTP learning after remote address set to: 10.24.16.18:4060
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 111 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 18 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 0 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 118 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 8 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Setting tx payload type 9 based on m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 58 format for m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0xb60bd570
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 0 (0x89f31f0) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 8 (0x8cc0918) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 9 (0x8a1adf0) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 18 (0x88da7c8) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 58 (0x88ef640) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 96 (0x8af0218) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 111 (0x8a42bc8) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] rtp_engine.c: Copying payload 118 (0x8c6cac8) from 0xb60bd570 to 0x8a9dc48
[Apr  6 17:58:13.567] DEBUG[31551] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Apr  6 17:58:13.567] DEBUG[31551] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Apr  6 17:58:13.567] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:13.567] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:735@10.24.21.234
[Apr  6 17:58:13.567] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:13.568] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Apr  6 17:58:13.575] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.595] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.610] DEBUG[31503] res_pjsip_registrar.c: Woke up at 1523055493  Interval: 30
[Apr  6 17:58:13.612] DEBUG[31503] res_pjsip_registrar.c: Expiring 0 contacts
[Apr  6 17:58:13.615] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.635] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.655] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.675] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.695] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.715] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.735] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.755] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.775] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.795] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.815] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.828] VERBOSE[31561][C-00000001] res_rtp_asterisk.c: 0x8aafc40 -- Strict RTP switching to RTP target address 10.24.16.18:4060 as source
[Apr  6 17:58:13.828] DEBUG[31561][C-00000001] app_confbridge.c: Trying to find conference bridge 'rpm_testing'
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge technology native_dahdi does not have any capabilities we want.
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge technology native_rtp does not have any capabilities we want.
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge technology simple_bridge does not have any capabilities we want.
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Chose bridge technology softmix
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: calling softmix technology constructor
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] bridge.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: calling softmix technology start
[Apr  6 17:58:13.829] DEBUG[31561][C-00000001] channel.c: Channel 0x8bd7e28 'CBAnn/rpm_testing-00000000;1' allocated
[Apr  6 17:58:13.830] DEBUG[31561][C-00000001] channel.c: Channel 0x8bdbe40 'CBAnn/rpm_testing-00000000;2' allocated
[Apr  6 17:58:13.830] DEBUG[31561][C-00000001] bridge_roles.c: Set role 'announcer'
[Apr  6 17:58:13.830] DEBUG[31561][C-00000001] app_confbridge.c: Created announcer channel 'CBAnn/rpm_testing-00000000;1' to conference bridge 'rpm_testing'
[Apr  6 17:58:13.830] DEBUG[31561][C-00000001] app_confbridge.c: Created conference 'rpm_testing' and linked to container.
[Apr  6 17:58:13.830] DEBUG[31535] app_queue.c: Device 'confbridge:rpm_testing' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Apr  6 17:58:13.831] DEBUG[31561][C-00000001] confbridge/conf_state.c: Changing conference 'rpm_testing' state from EMPTY to SINGLE
[Apr  6 17:58:13.831] DEBUG[31561][C-00000001] app_confbridge.c: User PJSIP/200-00000002 is muted: user:0 system:1.
[Apr  6 17:58:13.832] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting write format path: gsm -> ulaw
[Apr  6 17:58:13.833] DEBUG[31561][C-00000001] res_rtp_asterisk.c: Ooh, format changed from none to ulaw
[Apr  6 17:58:13.833] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:13.834] VERBOSE[31561][C-00000001] file.c: <PJSIP/200-00000002> Playing 'conf-onlyperson.gsm' (language 'en')
[Apr  6 17:58:13.834] DEBUG[31564] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: 0x8aefc68(CBAnn/rpm_testing-00000000;2) is joining
[Apr  6 17:58:13.834] DEBUG[31564] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: pushing 0x8aefc68(CBAnn/rpm_testing-00000000;2)
[Apr  6 17:58:13.834] DEBUG[31564] bridge_roles.c: Set role 'announcer'
[Apr  6 17:58:13.835] VERBOSE[31564] bridge_channel.c: Channel CBAnn/rpm_testing-00000000;2 joined 'softmix' base-bridge <bf66905c-99bc-44e2-97c7-652af7c04a6b>
[Apr  6 17:58:13.835] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.835] DEBUG[31564] bridge.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: 0x8aefc68(CBAnn/rpm_testing-00000000;2) is joining softmix technology
[Apr  6 17:58:13.835] DEBUG[31564] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Apr  6 17:58:13.836] DEBUG[31564] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Apr  6 17:58:13.836] DEBUG[31562] bridge_softmix.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: starting mixing thread
[Apr  6 17:58:13.855] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.869] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0xb428094c for Request msg ACK/cseq=2792 (rdata0xb41e4bcc)
[Apr  6 17:58:13.869] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000040 associated with dialog dlg0xb428094c
[Apr  6 17:58:13.870] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:13.870] DEBUG[31551] res_pjsip_session.c: Method is ACK
[Apr  6 17:58:13.875] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.895] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.915] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.935] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.955] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.966] DEBUG[31560][C-00000000] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 10.24.16.18:4059
[Apr  6 17:58:13.975] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:13.995] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.015] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.035] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.055] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.075] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.095] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.115] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.135] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.155] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.175] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.195] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.215] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.235] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.255] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.275] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.295] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.315] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.335] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.355] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.375] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.395] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.415] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.435] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.455] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.495] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.515] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.535] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.555] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.575] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.595] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.615] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.635] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.655] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.675] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.695] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.715] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.735] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.755] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.775] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.795] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.815] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.835] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.855] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.875] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.895] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.915] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.935] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.955] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.975] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:14.995] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.015] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.035] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.055] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.075] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.095] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.115] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.135] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.155] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.175] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.195] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.215] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.235] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.255] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.275] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.295] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.315] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.335] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.355] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.375] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.395] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.415] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.435] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.455] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.495] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.509] DEBUG[31561][C-00000001] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 10.24.16.18:4061
[Apr  6 17:58:15.515] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.535] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.555] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.575] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.595] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.615] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.635] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.655] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.675] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.695] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.715] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.735] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.755] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.775] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.795] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.815] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.835] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.855] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.875] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.895] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.915] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.934] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.955] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.974] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:15.994] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.014] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.034] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.054] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.074] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.094] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.114] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.134] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.154] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.174] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.194] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.214] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.234] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.254] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.274] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.294] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.314] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.334] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.354] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.374] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.394] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.414] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.434] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.454] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.475] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.494] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.514] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.534] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.554] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.574] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.594] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.614] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.634] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.654] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.674] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.694] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.714] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.734] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.745] DEBUG[31557][C-00000000] res_rtp_asterisk.c: Got RTCP report of 92 bytes from 10.24.17.232:2235
[Apr  6 17:58:16.754] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.774] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.794] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.814] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.834] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.854] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.874] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.894] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.914] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.934] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.954] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.974] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.994] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:16.994] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:16.994] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:16.994] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting write format path: ulaw -> ulaw
[Apr  6 17:58:16.994] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:16.995] VERBOSE[31561][C-00000001] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/200-00000002'
[Apr  6 17:58:16.996] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:16.996] DEBUG[31561][C-00000001] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: 0xb4a2f8b0(PJSIP/200-00000002) is joining
[Apr  6 17:58:16.996] DEBUG[31561][C-00000001] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: pushing 0xb4a2f8b0(PJSIP/200-00000002)
[Apr  6 17:58:16.996] VERBOSE[31561][C-00000001] bridge_channel.c: Channel PJSIP/200-00000002 joined 'softmix' base-bridge <bf66905c-99bc-44e2-97c7-652af7c04a6b>
[Apr  6 17:58:16.996] VERBOSE[31476] cdr.c: Bridge Enter message for channel PJSIP/200-00000002: 1523055496.00996847
[Apr  6 17:58:16.996] VERBOSE[31476] cdr.c: 0x8b5b150 - Updating Party A PJSIP/200-00000002 snapshot
[Apr  6 17:58:16.997] VERBOSE[31476] cdr.c: 0x8b5b150 - Processing bridge enter for PJSIP/200-00000002
[Apr  6 17:58:16.997] VERBOSE[31476] cdr.c: 0x8b5b150 - Transitioning CDR for PJSIP/200-00000002 from state Single to Bridged
[Apr  6 17:58:16.997] DEBUG[31476] cdr.c: Finalized CDR for PJSIP/200-00000002 - start 1523055493.558590 answer 1523055493.564207 end 1523055496.997060 dispo ANSWERED
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '735'
[Apr  6 17:58:16.997] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000002) result is 'PJSIP%2F200-00000002'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'ConfBridge'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(ConfBridge) result is 'ConfBridge'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'rpm_testing,,,sample_user_menu'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(rpm_testing,,,sample_user_menu) result is 'rpm_testing%2C%2C%2Csample_user_menu'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is ''
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is ''
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:16.998] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is 'CBAnn/rpm_testing-00000000;2'
[Apr  6 17:58:16.999] DEBUG[31479] pbx_variables.c: Function URIENCODE(CBAnn/rpm_testing-00000000;2) result is 'CBAnn%2Frpm_testing-00000000%3B2'
[Apr  6 17:58:16.999] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"softmix","bridge_id":"bf66905c-99bc-44e2-97c7-652af7c04a6b"}) result is '%7B%22bridge_technology%22%3A%22softmix%22%2C%22bridge_id%22%3A%22bf66905c-99bc-44e2-97c7-652af7c04a6b%22%7D'
[Apr  6 17:58:16.999] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:16.999] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055493.6'
[Apr  6 17:58:16.999] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:16.999] DEBUG[31561][C-00000001] bridge.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: 0xb4a2f8b0(PJSIP/200-00000002) is joining softmix technology
[Apr  6 17:58:17.000] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting read format path: ulaw -> slin
[Apr  6 17:58:17.000] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting write format path: slin -> ulaw
[Apr  6 17:58:17.000] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting write format path: ulaw -> ulaw
[Apr  6 17:58:17.000] DEBUG[31561][C-00000001] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Apr  6 17:58:17.000] DEBUG[31561][C-00000001] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Apr  6 17:58:17.003] DEBUG[31563] channel.c: Channel CBAnn/rpm_testing-00000000;1 setting write format path: gsm -> slin
[Apr  6 17:58:17.003] DEBUG[31563] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:17.003] VERBOSE[31563] file.c: <CBAnn/rpm_testing-00000000;1> Playing 'confbridge-join.gsm' (language 'en')
[Apr  6 17:58:17.014] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.017] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/200-00000002 setting write format path: slin -> ulaw
[Apr  6 17:58:17.018] DEBUG[31561][C-00000001] res_musiconhold.c: PJSIP/200-00000002 Opened file 0 '/var/lib/asterisk/moh/reno_project-system'
[Apr  6 17:58:17.034] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.054] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.074] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.094] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.114] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.134] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.154] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.174] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.194] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.214] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.234] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.254] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.274] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.294] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.314] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.334] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.354] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.374] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.383] DEBUG[31563] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:17.383] DEBUG[31563] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:17.383] DEBUG[31563] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:17.384] DEBUG[31563] channel.c: Channel CBAnn/rpm_testing-00000000;1 setting write format path: slin -> slin
[Apr  6 17:58:17.394] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.414] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.434] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.454] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.474] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.494] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.514] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.534] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.554] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.574] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.594] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.614] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.634] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.654] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.674] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.694] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.714] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.734] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.754] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.774] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.794] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.814] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.834] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.854] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.874] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.894] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.914] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.934] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.954] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.974] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:17.994] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.014] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.034] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.054] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.074] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.094] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.114] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.134] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.154] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.174] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.194] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.214] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.234] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.254] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.274] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.294] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.314] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.334] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.354] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.374] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.394] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.414] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.434] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.454] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.474] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.494] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.514] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.534] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.554] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.574] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.587] VERBOSE[31561][C-00000001] res_rtp_asterisk.c: 0x8aafc40 -- Strict RTP learning complete - Locking on source address 10.24.16.18:4060
[Apr  6 17:58:18.594] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.614] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.634] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.654] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.674] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.694] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.714] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.734] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.754] DEBUG[31560][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x89d9b18' so dropping frame
[Apr  6 17:58:18.755] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Request msg REFER/cseq=21946 (rdata0xb41d311c)
[Apr  6 17:58:18.755] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip_session.c: Method is REFER
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip_refer.c: Created progress monitor '0xb60bdbf8' for transfer occurring from channel 'PJSIP/200-00000001' and endpoint '200'
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip_refer.c: Accepting REFER request for progress monitor '0x8b5bf48'
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:18.755] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:asterisk@10.24.21.234:5060
[Apr  6 17:58:18.756] DEBUG[31551] res_pjsip_refer.c: Attended transfer from 'PJSIP/200-00000001' pushed to second channel serializer
[Apr  6 17:58:18.756] DEBUG[31551] res_pjsip_refer.c: Performing a REFER attended transfer - Transferer #1: PJSIP/200-00000001 Transferer #2: PJSIP/200-00000002
[Apr  6 17:58:18.756] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 100
[Apr  6 17:58:18.756] DEBUG[31473] devicestate.c: Changing state for PJSIP/100 - state 2 (In use)
[Apr  6 17:58:18.756] DEBUG[31535] 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.
[Apr  6 17:58:18.757] VERBOSE[31557][C-00000000] res_musiconhold.c: Stopped music on hold on PJSIP/100-00000000
[Apr  6 17:58:18.757] DEBUG[31557][C-00000000] channel.c: Channel PJSIP/100-00000000 setting write format path: ulaw -> ulaw
[Apr  6 17:58:18.757] DEBUG[31557][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:18.757] DEBUG[31551] bridge_channel.c: Setting 0x8c3a8d0(PJSIP/200-00000001) state from:0 to:2
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip_refer.c: Final response for REFER attended transfer - Transferer #1: PJSIP/200-00000001 Transferer #2: PJSIP/200-00000002 is '200'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip_refer.c: Subscription '0x8b826dc' is being terminated as a result of a NOTIFY, removing REFER progress structure early on progress monitor '0x8b5bf48'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip_refer.c: Sending initial 100 Trying NOTIFY for progress monitor '0x8b5bf48'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:asterisk@10.24.21.234:5060
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is ''
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip_refer.c: Sending NOTIFY with response '200' and state '5' on subscription '0x8b826dc' and progress monitor '0x8b5bf48'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'AppDial'
[Apr  6 17:58:18.758] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:18.758] DEBUG[31479] pbx_variables.c: Function URIENCODE(AppDial) result is 'AppDial'
[Apr  6 17:58:18.759] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:18.759] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is '(Outgoing Line)'
[Apr  6 17:58:18.759] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:asterisk@10.24.21.234:5060
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE((Outgoing Line)) result is '(Outgoing%20Line)'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'orange'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'apple'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge1_id":"21422ef6-ea78-4946-a644-d043d0a37da0","channel2_name":"PJSIP/200-00000002","channel2_uniqueid":"1523055493.6","transferee_channel_name":"PJSIP/100-00000000","app":"ConfBridge","transferee_channel_uniqueid":"1523055484.0","transfer_target_channel_name":"N/A","transfer_target_channel_uniqueid":"N/A"}) result is '%7B%22bridge1_id%22%3A%2221422ef6-ea78-4946-a644-d043d0a37da0%22%2C%22channel2_name%22%3A%22PJSIP%2F200-00000002%22%2C%22channel2_uniqueid%22%3A%221523055493.6%22%2C%22transferee_channel_name%22%3A%22PJSIP%2F100-00000000%22%2C%22app%22%3A%22ConfBridge%22%2C%22transferee_channel_uniqueid%22%3A%221523055484.0%22%2C%22transfer_target_channel_name%22%3A%22N%2FA%22%2C%22transfer_target_channel_uniqueid%22%3A%22N%2FA%22%7D'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.1) result is '1523055484.1'
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: pulling 0x8c3a8d0(PJSIP/200-00000001)
[Apr  6 17:58:18.759] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:18.759] VERBOSE[31560][C-00000000] bridge_channel.c: Channel PJSIP/200-00000001 left 'simple_bridge' basic-bridge <21422ef6-ea78-4946-a644-d043d0a37da0>
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8c3a8d0(PJSIP/200-00000001) is leaving simple_bridge technology
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] dahdi/bridge_native_dahdi.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: Cannot use native DAHDI.  Must have two channels.
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge_native_rtp.c: Bridge '21422ef6-ea78-4946-a644-d043d0a37da0' can not use native RTP bridge as two channels are required
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Apr  6 17:58:18.759] DEBUG[31560][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Apr  6 17:58:18.760] DEBUG[31560][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Apr  6 17:58:18.760] DEBUG[31560][C-00000000] bridge.c: Chose bridge technology simple_bridge
[Apr  6 17:58:18.760] DEBUG[31560][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is already using the new technology.
[Apr  6 17:58:18.760] VERBOSE[31476] cdr.c: Bridge Leave message for PJSIP/200-00000001: 1523055498.00759829
[Apr  6 17:58:18.760] VERBOSE[31476] cdr.c: 0x8a49278 - Processing Bridge Leave for PJSIP/200-00000001
[Apr  6 17:58:18.760] VERBOSE[31476] cdr.c: 0x8a49278 - Transitioning CDR for PJSIP/200-00000001 from state Bridged to Finalized
[Apr  6 17:58:18.760] DEBUG[31476] cdr.c: Finalized CDR for PJSIP/100-00000000 - start 1523055484.856531 answer 1523055487.346939 end 1523055498.760203 dispo ANSWERED
[Apr  6 17:58:18.760] DEBUG[31560][C-00000000] channel.c: Channel 0xb4122590 'PJSIP/200-00000001' hanging up.  Refs: 3
[Apr  6 17:58:18.760] DEBUG[31560][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Apr  6 17:58:18.760] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:18.761] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge_channel.c: Setting 0x8a09060(PJSIP/100-00000000) state from:0 to:1
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: pulling 0x8a09060(PJSIP/100-00000000)
[Apr  6 17:58:18.761] VERBOSE[31557][C-00000000] bridge_channel.c: Channel PJSIP/100-00000000 left 'simple_bridge' basic-bridge <21422ef6-ea78-4946-a644-d043d0a37da0>
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge_channel.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: 0x8a09060(PJSIP/100-00000000) is leaving simple_bridge technology
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: dissolving bridge with cause 16(Normal Clearing)
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: queueing action type:13 sub:1001
[Apr  6 17:58:18.761] DEBUG[31557][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0 is dissolved, not performing smart bridge operation.
[Apr  6 17:58:18.762] VERBOSE[31476] cdr.c: Bridge Leave message for PJSIP/100-00000000: 1523055498.00761906
[Apr  6 17:58:18.762] VERBOSE[31476] cdr.c: 0x8ad8810 - Processing Bridge Leave for PJSIP/100-00000000
[Apr  6 17:58:18.762] VERBOSE[31476] cdr.c: 0x8ad8810 - Transitioning CDR for PJSIP/100-00000000 from state Bridged to Finalized
[Apr  6 17:58:18.762] DEBUG[31472][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread.
[Apr  6 17:58:18.762] DEBUG[31472][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: actually destroying basic bridge, nobody wants it anymore
[Apr  6 17:58:18.762] DEBUG[31472][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: calling basic bridge destructor
[Apr  6 17:58:18.762] DEBUG[31472][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: calling simple_bridge technology stop
[Apr  6 17:58:18.762] DEBUG[31472][C-00000000] bridge.c: Bridge 21422ef6-ea78-4946-a644-d043d0a37da0: calling simple_bridge technology destructor
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is ''
[Apr  6 17:58:18.762] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'AppDial'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(AppDial) result is 'AppDial'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is '(Outgoing Line)'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE((Outgoing Line)) result is '(Outgoing%20Line)'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'orange'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'apple'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is 'PJSIP/100-00000000'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/100-00000000) result is 'PJSIP%2F100-00000000'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"simple_bridge","bridge_id":"21422ef6-ea78-4946-a644-d043d0a37da0"}) result is '%7B%22bridge_technology%22%3A%22simple_bridge%22%2C%22bridge_id%22%3A%2221422ef6-ea78-4946-a644-d043d0a37da0%22%7D'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.1) result is '1523055484.1'
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:18.763] DEBUG[31551] channel.c: Channel 0xb4122590 'PJSIP/200-00000001' destroying
[Apr  6 17:58:18.763] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:18.764] VERBOSE[31476] cdr.c: 0x8a49278 - Beginning finalize/dispatch for PJSIP/200-00000001
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_10'
[Apr  6 17:58:18.764] VERBOSE[31476] cdr.c: 0x8a49278 - Dispatching CDR for Party A PJSIP/200-00000001, Party B <none>
[Apr  6 17:58:18.764] DEBUG[31476] cdr.c: CDR for PJSIP/200-00000001 is dialed and has no Party B; discarding
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_10) result is 'CfgSIP_10'
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '1100'
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '1100'
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:18.764] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '200'
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE(s) result is 's'
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE(macro-callit) result is 'macro-callit'
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/100-00000000) result is 'PJSIP%2F100-00000000'
[Apr  6 17:58:18.765] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 200
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'Dial'
[Apr  6 17:58:18.765] DEBUG[31473] devicestate.c: Changing state for PJSIP/200 - state 2 (In use)
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function URIENCODE(Dial) result is 'Dial'
[Apr  6 17:58:18.765] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'PJSIP/200,30,'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200,30,) result is 'PJSIP%2F200%2C30%2C'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'orange'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"simple_bridge","bridge_id":"21422ef6-ea78-4946-a644-d043d0a37da0"}) result is '%7B%22bridge_technology%22%3A%22simple_bridge%22%2C%22bridge_id%22%3A%2221422ef6-ea78-4946-a644-d043d0a37da0%22%7D'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:18.766] VERBOSE[31557][C-00000000] res_musiconhold.c: Stopped music on hold on PJSIP/200-00000002
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:18.766] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:18.766] DEBUG[31557][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:18.766] DEBUG[31557][C-00000000] channel.c: Actually Masquerading PJSIP/100-00000000(6) into the structure of PJSIP/200-00000002(6)
[Apr  6 17:58:18.767] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:18.767] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:18.767] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:18.767] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.767] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:18.767] DEBUG[31557][C-00000000] channel.c: Channel PJSIP/100-00000000 setting write format path: slin -> ulaw
[Apr  6 17:58:18.767] DEBUG[31557][C-00000000] channel.c: Channel PJSIP/100-00000000 setting read format path: ulaw -> slin
[Apr  6 17:58:18.767] DEBUG[31557][C-00000000] channel.c: Putting channel PJSIP/100-00000000 in slin/slin formats
[Apr  6 17:58:18.767] VERBOSE[31476] cdr.c: 0xb426dfa8 - Created CDR for channel PJSIP/100-00000000
[Apr  6 17:58:18.767] VERBOSE[31476] cdr.c: 0xb426dfa8 - Transitioning CDR for PJSIP/100-00000000 from state NONE to Single
[Apr  6 17:58:18.767] VERBOSE[31476] cdr.c: 0xb426dfa8 - Set answered time to 1523055498.767957
[Apr  6 17:58:18.768] DEBUG[31462] threadpool.c: Increasing threadpool stasis-core's size by 1
[Apr  6 17:58:18.769] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.769] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.769] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.769] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is ''
[Apr  6 17:58:18.769] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000001) result is 'PJSIP%2F200-00000001'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'AppDial'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(AppDial) result is 'AppDial'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is '(Outgoing Line)'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE((Outgoing Line)) result is '(Outgoing%20Line)'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'orange'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'apple'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE({"dialstatus":"","hangupcause":16,"hangupsource":""}) result is '%7B%22dialstatus%22%3A%22%22%2C%22hangupcause%22%3A16%2C%22hangupsource%22%3A%22%22%7D'
[Apr  6 17:58:18.770] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.1) result is '1523055484.1'
[Apr  6 17:58:18.772] VERBOSE[31557][C-00000000] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/100-00000000'
[Apr  6 17:58:18.772] DEBUG[31557][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:18.772] DEBUG[31557][C-00000000] channel.c: Done Masquerading PJSIP/100-00000000 (6)
[Apr  6 17:58:18.772] VERBOSE[31561][C-00000001] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) start
[Apr  6 17:58:18.772] DEBUG[31561][C-00000001] app_stack.c: PJSIP/100-00000000 Original location: pjsip_b,735,8
[Apr  6 17:58:18.773] DEBUG[31561][C-00000001] app_stack.c: Setting 'ARG1' to 'context:pjsip_a exten:200'
[Apr  6 17:58:18.773] DEBUG[31561][C-00000001] app_stack.c: Gosub exited with status 0
[Apr  6 17:58:18.773] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:18.773] VERBOSE[31561][C-00000001] pbx.c: Executing [s@connected_line_send:1] NoOp("PJSIP/100-00000000", "Connected line send subroutine for context:pjsip_a exten:200") in new stack
[Apr  6 17:58:18.773] DEBUG[31561][C-00000001] pbx.c: Launching 'Gosub'
[Apr  6 17:58:18.773] VERBOSE[31561][C-00000001] pbx.c: Executing [s@connected_line_send:2] Gosub("PJSIP/100-00000000", "displaycolp,s,1") in new stack
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx_variables.c: Function CONNECTEDLINE(all) result is '"" <>'
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:18.774] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycolp:1] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(all) is "" <>") in new stack
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx_variables.c: Function CONNECTEDLINE(tag) result is 'SIP-B'
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:18.772] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:18.774] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycolp:2] NoOp("PJSIP/100-00000000", "CONNECTEDLINE(tag) is SIP-B") in new stack
[Apr  6 17:58:18.774] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx.c: Launching 'Return'
[Apr  6 17:58:18.774] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycolp:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:18.774] DEBUG[31561][C-00000001] pbx.c: Launching 'Gosub'
[Apr  6 17:58:18.774] VERBOSE[31561][C-00000001] pbx.c: Executing [s@connected_line_send:3] Gosub("PJSIP/100-00000000", "displaycli,s,1") in new stack
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] app_stack.c: Setting 'ARG1' to ''
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] pbx_variables.c: Function CALLERID(all) result is '"CfgSIP_10" <1100>'
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:18.775] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycli:1] NoOp("PJSIP/100-00000000", "CALLERID(all) is "CfgSIP_10" <1100>") in new stack
[Apr  6 17:58:18.775] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Response msg 200/NOTIFY/cseq=19951 (rdata0xb41e4bb4)
[Apr  6 17:58:18.775] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] pbx_variables.c: Function CALLERID(tag) result is 'SIP-A'
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] pbx.c: Launching 'NoOp'
[Apr  6 17:58:18.775] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycli:2] NoOp("PJSIP/100-00000000", "CALLERID(tag) is SIP-A") in new stack
[Apr  6 17:58:18.775] DEBUG[31561][C-00000001] pbx.c: Launching 'Return'
[Apr  6 17:58:18.775] VERBOSE[31561][C-00000001] pbx.c: Executing [s@displaycli:3] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:18.776] DEBUG[31561][C-00000001] pbx.c: Launching 'Return'
[Apr  6 17:58:18.776] VERBOSE[31561][C-00000001] pbx.c: Executing [s@connected_line_send:4] Return("PJSIP/100-00000000", "") in new stack
[Apr  6 17:58:18.776] DEBUG[31561][C-00000001] app_stack.c: Spawn extension (pjsip_b,735,8) exited with -1 on 'PJSIP/100-00000000'
[Apr  6 17:58:18.776] VERBOSE[31561][C-00000001] app_stack.c: Spawn extension (pjsip_b, 735, 8) exited non-zero on 'PJSIP/100-00000000'
[Apr  6 17:58:18.776] VERBOSE[31561][C-00000001] app_stack.c: PJSIP/100-00000000 Internal Gosub(connected_line_send,s,1(context:pjsip_a exten:200)) complete GOSUB_RETVAL=
[Apr  6 17:58:18.776] DEBUG[31561][C-00000001] app_stack.c: PJSIP/100-00000000 Ending location: pjsip_b,735,8
[Apr  6 17:58:18.776] DEBUG[31552] res_pjsip_session.c: Received response
[Apr  6 17:58:18.776] DEBUG[31552] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:18.776] DEBUG[31552] res_pjsip_session.c: NOTIFY received final response code 200
[Apr  6 17:58:18.776] DEBUG[31557][C-00000000] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Apr  6 17:58:18.776] DEBUG[31557][C-00000000] app_macro.c: Spawn extension (macro-callit,s,3) exited non-zero on 'PJSIP/200-00000002' in macro 'callit'
[Apr  6 17:58:18.776] VERBOSE[31557][C-00000000] app_macro.c: Spawn extension (macro-callit, s, 3) exited non-zero on 'PJSIP/200-00000002' in macro 'callit'
[Apr  6 17:58:18.777] DEBUG[31557][C-00000000] pbx.c: Spawn extension (pjsip_a,200,6) exited non-zero on 'PJSIP/200-00000002'
[Apr  6 17:58:18.778] VERBOSE[31557][C-00000000] pbx.c: Spawn extension (pjsip_a, 200, 6) exited non-zero on 'PJSIP/200-00000002'
[Apr  6 17:58:18.778] DEBUG[31557][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/200-00000002'
[Apr  6 17:58:18.778] DEBUG[31557][C-00000000] channel.c: Channel 0x8ad6060 'PJSIP/200-00000002' hanging up.  Refs: 2
[Apr  6 17:58:18.778] DEBUG[31557][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Apr  6 17:58:18.778] DEBUG[31551] res_pjsip_session.c: Method is BYE
[Apr  6 17:58:18.778] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:18.778] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:735@10.24.21.234
[Apr  6 17:58:18.778] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:18.779] DEBUG[31551] channel.c: Channel 0x8ad6060 'PJSIP/200-00000002' destroying
[Apr  6 17:58:18.779] VERBOSE[31476] cdr.c: 0x8b5b150 - Transitioning CDR for PJSIP/200-00000002 from state Bridged to Finalized
[Apr  6 17:58:18.779] VERBOSE[31476] cdr.c: 0x8b5b150 - Beginning finalize/dispatch for PJSIP/200-00000002
[Apr  6 17:58:18.779] VERBOSE[31476] cdr.c: 0x8b5b150 - Dispatching CDR for Party A PJSIP/200-00000002, Party B <none>
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CDR(clid) result is '"CfgSIP_20" <2200>'
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE("CfgSIP_20" <2200>) result is '"""CfgSIP_20"" <2200>"'
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CDR(src) result is '2200'
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(2200) result is '"2200"'
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CDR(dst) result is '200'
[Apr  6 17:58:18.779] DEBUG[31473] devicestate.c: No provider found, checking channel drivers for PJSIP - 200
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(200) result is '"200"'
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CDR(dcontext) result is 'pjsip_a'
[Apr  6 17:58:18.779] DEBUG[31473] devicestate.c: Changing state for PJSIP/200 - state 1 (Not in use)
[Apr  6 17:58:18.779] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(pjsip_a) result is '"pjsip_a"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(channel) result is 'PJSIP/200-00000002'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(PJSIP/200-00000002) result is '"PJSIP/200-00000002"'
[Apr  6 17:58:18.780] DEBUG[31535] app_queue.c: Removed May Flowers from pending_members
[Apr  6 17:58:18.780] DEBUG[31535] app_queue.c: Device 'PJSIP/200' changed to state '1' (Not in use)
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(dstchannel) result is ''
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE() result is '""'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(lastapp) result is 'Dial'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(Dial) result is '"Dial"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(lastdata) result is 'PJSIP/200,30,'
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Request: sip:200@10.24.16.18:5060;ob
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(PJSIP/200,30,) result is '"PJSIP/200,30,"'
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip/pjsip_message_filter.c: Sanitizing Contact header: sip:10.24.21.234:5060
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(start) result is '2018-04-06 17:58:13'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(2018-04-06 17:58:13) result is '"2018-04-06 17:58:13"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(answer) result is '2018-04-06 17:58:13'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(2018-04-06 17:58:13) result is '"2018-04-06 17:58:13"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(end) result is '2018-04-06 17:58:16'
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip_pubsub.c: evsub 0xb4284364 state ACTIVE event USER sub_tree 0xb4b35700 sub_tree state Normal
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(2018-04-06 17:58:16) result is '"2018-04-06 17:58:16"'
[Apr  6 17:58:18.780] DEBUG[31552] res_pjsip_pubsub.c: Updating persistence for '200->200'  prune on restart: no
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(duration) result is '3'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(3) result is '"3"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(billsec) result is '3'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(3) result is '"3"'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CDR(disposition) result is 'ANSWERED'
[Apr  6 17:58:18.780] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(ANSWERED) result is '"ANSWERED"'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(amaflags) result is 'DOCUMENTATION'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(DOCUMENTATION) result is '"DOCUMENTATION"'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(accountcode) result is 'apple'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(apple) result is '"apple"'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(uniqueid) result is '1523055493.6'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE(1523055493.6) result is '"1523055493.6"'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(userfield) result is ''
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE() result is '""'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(sequence) result is '2'
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CDR(WhoHungUp) result is ''
[Apr  6 17:58:18.781] DEBUG[31476] pbx_variables.c: Function CSV_QUOTE() result is '""'
[Apr  6 17:58:18.783] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:18.783] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:18.783] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '735'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_a) result is 'pjsip_a'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000002) result is 'PJSIP%2F200-00000002'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'orange'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.784] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:18.785] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.785] DEBUG[31479] pbx_variables.c: Function URIENCODE({"dialstatus":"","hangupcause":16,"hangupsource":""}) result is '%7B%22dialstatus%22%3A%22%22%2C%22hangupcause%22%3A16%2C%22hangupsource%22%3A%22%22%7D'
[Apr  6 17:58:18.785] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:18.785] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055493.6'
[Apr  6 17:58:18.785] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_20'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_20) result is 'CfgSIP_20'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '2200'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '2200'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(2200) result is '2200'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '735'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_a) result is 'pjsip_a'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/200-00000002) result is 'PJSIP%2F200-00000002'
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.786] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is 'orange'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE(orange) result is 'orange'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is ''
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055493.6'
[Apr  6 17:58:18.787] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055493.6) result is '1523055493.6'
[Apr  6 17:58:18.793] DEBUG[31561][C-00000001] res_musiconhold.c: PJSIP/100-00000000 Opened file 0 '/var/lib/asterisk/moh/reno_project-system'
[Apr  6 17:58:18.829] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Response msg 200/NOTIFY/cseq=19952 (rdata0xb419bc34)
[Apr  6 17:58:18.829] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:18.830] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:18.830] DEBUG[31551] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:18.830] DEBUG[31551] res_pjsip_session.c: NOTIFY received final response code 200
[Apr  6 17:58:18.839] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0xb428094c for Response msg 200/BYE/cseq=19478 (rdata0xb41d2e74)
[Apr  6 17:58:18.839] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000040 associated with dialog dlg0xb428094c
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: Received response
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: Response is 200 OK
[Apr  6 17:58:18.840] DEBUG[31551] res_pjsip_session.c: BYE received final response code 200
[Apr  6 17:58:18.840] DEBUG[31551] rtp_engine.c: Destroyed RTP instance '0x8a9da98'
[Apr  6 17:58:19.084] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8a41584 for Request msg BYE/cseq=21947 (rdata0xb42e21cc)
[Apr  6 17:58:19.084] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/200-0000006e associated with dialog dlg0x8a41584
[Apr  6 17:58:19.084] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.16.18;ob
[Apr  6 17:58:19.084] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:1100@10.24.21.234
[Apr  6 17:58:19.084] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Apr  6 17:58:19.084] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:19.084] DEBUG[31551] res_pjsip_session.c: Method is BYE
[Apr  6 17:58:19.085] DEBUG[31551] rtp_engine.c: Destroyed RTP instance '0x89d9b18'
[Apr  6 17:58:19.085] DEBUG[31551] rtp_engine.c: Destroyed RTP instance '0x8ad1080'
[Apr  6 17:58:19.098] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x8ac1ea4 for Response msg 200/NOTIFY/cseq=23884 (rdata0xb4137754)
[Apr  6 17:58:19.098] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000034 associated with dialog dlg0x8ac1ea4
[Apr  6 17:58:21.744] DEBUG[31561][C-00000001] res_rtp_asterisk.c: Got RTCP report of 92 bytes from 10.24.17.232:2235
[Apr  6 17:58:23.777] DEBUG[31551] res_pjsip_session.c: Destroying SIP session with endpoint 200
[Apr  6 17:58:23.841] DEBUG[31551] res_pjsip_session.c: Destroying SIP session with endpoint 200
[Apr  6 17:58:24.883] DEBUG[31488] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0xb4b05c24 for Request msg BYE/cseq=2 (rdata0xb41ad6a4)
[Apr  6 17:58:24.883] DEBUG[31488] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000002e associated with dialog dlg0xb4b05c24
[Apr  6 17:58:24.884] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:100@10.24.21.234
[Apr  6 17:58:24.884] DEBUG[31551] res_pjsip/pjsip_message_filter.c: Sanitizing From/To header: sip:200@10.24.21.234;user=phone
[Apr  6 17:58:24.884] DEBUG[31551] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Apr  6 17:58:24.884] DEBUG[31551] res_pjsip_session.c: Received request
[Apr  6 17:58:24.884] DEBUG[31551] res_pjsip_session.c: Method is BYE
[Apr  6 17:58:24.884] VERBOSE[31561][C-00000001] res_musiconhold.c: Stopped music on hold on PJSIP/100-00000000
[Apr  6 17:58:24.885] DEBUG[31561][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Apr  6 17:58:24.885] DEBUG[31561][C-00000001] bridge_channel.c: Setting 0xb4a2f8b0(PJSIP/100-00000000) state from:0 to:1
[Apr  6 17:58:24.885] DEBUG[31561][C-00000001] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: pulling 0xb4a2f8b0(PJSIP/100-00000000)
[Apr  6 17:58:24.885] VERBOSE[31561][C-00000001] bridge_channel.c: Channel PJSIP/100-00000000 left 'softmix' base-bridge <bf66905c-99bc-44e2-97c7-652af7c04a6b>
[Apr  6 17:58:24.885] DEBUG[31561][C-00000001] bridge_channel.c: Bridge bf66905c-99bc-44e2-97c7-652af7c04a6b: 0xb4a2f8b0(PJSIP/100-00000000) is leaving softmix technology
[Apr  6 17:58:24.886] VERBOSE[31476] cdr.c: Bridge Leave message for PJSIP/100-00000000: 1523055504.00885858
[Apr  6 17:58:24.886] VERBOSE[31476] cdr.c: 0xb426dfa8 - Processing Bridge Leave for PJSIP/100-00000000
[Apr  6 17:58:24.886] ERROR[31476] cdr.c: FRACK!, Failed assertion 0 (0)
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function CALLERID(name) result is 'CfgSIP_10'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function URIENCODE(CfgSIP_10) result is 'CfgSIP_10'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function CALLERID(num) result is '1100'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function CALLERID(ANI) result is '1100'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function URIENCODE(1100) result is '1100'
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function CALLERID(RDNIS) result is ''
[Apr  6 17:58:24.888] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CALLERID(DNID) result is '200'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(200) result is '200'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(735) result is '735'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(pjsip_b) result is 'pjsip_b'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(PJSIP/100-00000000) result is 'PJSIP%2F100-00000000'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(appname) result is 'ConfBridge'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(ConfBridge) result is 'ConfBridge'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(appdata) result is 'rpm_testing,,,sample_user_menu'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(rpm_testing,,,sample_user_menu) result is 'rpm_testing%2C%2C%2Csample_user_menu'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(amaflags) result is '3'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(3) result is '3'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(accountcode) result is 'apple'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(apple) result is 'apple'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(peeraccount) result is ''
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE() result is ''
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(peer) result is 'CBAnn/rpm_testing-00000000;2'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(CBAnn/rpm_testing-00000000;2) result is 'CBAnn%2Frpm_testing-00000000%3B2'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE({"bridge_technology":"softmix","bridge_id":"bf66905c-99bc-44e2-97c7-652af7c04a6b"}) result is '%7B%22bridge_technology%22%3A%22softmix%22%2C%22bridge_id%22%3A%22bf66905c-99bc-44e2-97c7-652af7c04a6b%22%7D'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function CHANNEL(linkedid) result is '1523055484.0'
[Apr  6 17:58:24.889] DEBUG[31479] pbx_variables.c: Function URIENCODE(1523055484.0) result is '1523055484.0'
[Apr  6 17:58:24.893] DEBUG[31561][C-00000001] bridge_channel.c: Bridge is returning 0xb4a2f8b0(PJSIP/100-00000000) to read format ulaw
[Apr  6 17:58:24.893] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/100-00000000 setting read format path: ulaw -> ulaw
[Apr  6 17:58:24.894] DEBUG[31561][C-00000001] bridge_channel.c: Bridge is returning 0xb4a2f8b0(PJSIP/100-00000000) to write format ulaw
[Apr  6 17:58:24.894] DEBUG[31561][C-00000001] channel.c: Channel PJSIP/100-00000000 setting write format path: ulaw -> ulaw
[Apr  6 17:58:24.895] DEBUG[31561][C-00000001] confbridge/conf_state.c: Changing conference 'rpm_testing' state from SINGLE to EMPTY
[Apr  6 17:58:24.897] DEBUG[31563] channel.c: Channel CBAnn/rpm_testing-00000000;1 setting write format path: gsm -> slin
[Apr  6 17:58:24.897] DEBUG[31535] app_queue.c: Device 'confbridge:rpm_testing' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Apr  6 17:58:24.897] DEBUG[31563] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Apr  6 17:58:24.897] VERBOSE[31563] file.c: <CBAnn/rpm_testing-00000000;1> Playing 'confbridge-leave.gsm' (language 'en')
[Apr  6 17:58:24.898] DEBUG[31561][C-00000001] app_confbridge.c: Destroying conference bridge 'rpm_testing'
[Apr  6 17:58:25.068] VERBOSE[31476] logger.c: Got 14 backtrace records
[Apr  6 17:58:25.068] VERBOSE[31476] logger.c: #0: [0x826f688] main/utils.c:2487 __ast_assert_failed() (0x826f60d+7B)
[Apr  6 17:58:25.068] VERBOSE[31476] logger.c: #1: [0x80ea3e4] main/cdr.c:1597 base_process_bridge_leave()
[Apr  6 17:58:25.068] VERBOSE[31476] logger.c: #2: [0x80ecd99] main/cdr.c:2435 handle_bridge_leave_message()
[Apr  6 17:58:25.068] VERBOSE[31476] logger.c: #3: [0x8246c47] main/stasis_message_router.c:204 router_dispatch()
[Apr  6 17:58:25.069] VERBOSE[31476] logger.c: #4: [0x823293e] main/stasis.c:437 subscription_invoke()