[Mar 14 16:08:24] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-0000000d on transaction tsx0x7f3ac400f368
[Mar 14 16:08:24] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: PJSIP tsx response received
[Mar 14 16:08:24] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Cancelling timer
[Mar 14 16:08:24] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Timer cancelled
[Mar 14 16:08:24] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:24] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:24] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:24] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Callbacks executed
[Mar 14 16:08:24] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: wrapper destroyed
[Mar 14 16:08:24] DEBUG[49] res_pjsip/pjsip_configuration.c: Contact 145/sip:424242145@206.126.62.175:5060 status didn't change: Reachable, RTT: 28.667 msec
[Mar 14 16:08:26] DEBUG[63] manager.c: Running action 'ExtensionStateList'
[Mar 14 16:08:26] DEBUG[63] manager.c: Running action 'PJSIPShowRegistrationInboundContactStatuses'
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:26] DEBUG[63] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Wrapper created
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Set timer to 20000 msec
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:26] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:26] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:26] DEBUG[43] res_pjsip/pjsip_distributor.c: No dialog serializer for response Response msg 200/OPTIONS/cseq=40342 (rdata0x25294f8). Using request transaction as basis
[Mar 14 16:08:26] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-0000000e on transaction tsx0x7f3ac000b498
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: PJSIP tsx response received
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Cancelling timer
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Timer cancelled
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Callbacks executed
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: wrapper destroyed
[Mar 14 16:08:26] DEBUG[49] res_pjsip/pjsip_configuration.c: Contact 144/sip:424242144@206.126.62.175:5060 status didn't change: Reachable, RTT: 35.925 msec
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Wrapper created
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Set timer to 20000 msec
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:26] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:26] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:26] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:26] DEBUG[43] res_pjsip/pjsip_distributor.c: No dialog serializer for response Response msg 200/OPTIONS/cseq=8187 (rdata0x25294f8). Using request transaction as basis
[Mar 14 16:08:26] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-0000000f on transaction tsx0x7f3ac00104f8
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: PJSIP tsx response received
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Cancelling timer
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Timer cancelled
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:26] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: Callbacks executed
[Mar 14 16:08:26] DEBUG[44] res_pjsip.c: 0x7f3ac40672e8: wrapper destroyed
[Mar 14 16:08:26] DEBUG[49] res_pjsip/pjsip_configuration.c: Contact 142/sip:424242142@206.126.62.175:5060 status didn't change: Reachable, RTT: 22.752 msec
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=71 (rdata0x25294f8)
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000043 to use for Request msg INVITE/cseq=71 (rdata0x25294f8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against
[Mar 14 16:08:27] DEBUG[44] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '142' domain 'sip.primevox.net'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_endpoint_identifier_user.c: Identified by From username '142' domain 'sip.primevox.net'
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000043 to use for Request msg INVITE/cseq=71 (rdata0x25206d8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: none
Uniqueid: none
Variable: SIPDOMAIN
Value: 206.126.62.178


[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f3ac403f3d8'
[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Allocated port 17036 for RTP instance '0x7f3ac403f3d8'
[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Creating ICE session [::]:17036 (17036) for RTP instance '0x7f3ac403f3d8'
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: RTP instance '0x7f3ac403f3d8' is setup and ready to go
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'd24d6d931b44' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'd24d6d931b44' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f3ac403f3d8'
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 123 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 97 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Don't have a default tx payload type 2 format for m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7f3ac4053020) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 2 (0x7f3ac401d7d0) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x7f3ac403e870) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7f3ac40441d0) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 97 (0x7f3ac401d780) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0x2340b30) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Crossover copying tx to rx payload mapping 123 (0x7f3ac402d5e0) from 0x7f3add5763b0 to 0x7f3add5763b0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 0 (0x7f3ac4053020) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 2 (0x7f3ac401d7d0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 9 (0x7f3ac403e870) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 18 (0x7f3ac40441d0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 97 (0x7f3ac401d780) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 101 (0x2340b30) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying rx payload mapping 123 (0x7f3ac402d5e0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 0 (0x7f3ac4053020) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 2 (0x7f3ac401d7d0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 9 (0x7f3ac403e870) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 18 (0x7f3ac40441d0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 97 (0x7f3ac401d780) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 101 (0x2340b30) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Copying tx payload mapping 123 (0x7f3ac402d5e0) from 0x7f3add5763b0 to 0x7f3ac403f5a0
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Media stream 'audio' handled by audio
[Mar 14 16:08:27] DEBUG[44] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142()'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is INCOMING
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142()'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current transaction state is Proceeding
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is INCOMING
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Method is INVITE
[Mar 14 16:08:27] DEBUG[16] threadpool.c: Increasing threadpool stasis-core's size by 1
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newchannel
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.26
Linkedid: 1489507707.26


[Mar 14 16:08:27] DEBUG[44] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/142-0000000c
[Mar 14 16:08:27] DEBUG[228][C-00000008] pbx.c: Launching 'NoOp'
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Extension: *42
Application: NoOp
AppData: 


[Mar 14 16:08:27] DEBUG[228][C-00000008] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[Mar 14 16:08:27] DEBUG[228][C-00000008] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:27] DEBUG[228][C-00000008] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[Mar 14 16:08:27] DEBUG[228][C-00000008] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[Mar 14 16:08:27] DEBUG[228][C-00000008] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[Mar 14 16:08:27] DEBUG[228][C-00000008] pbx_variables.c: Function PJSIP_DIAL_CONTACTS(143) result is 'PJSIP/143/sip:424242143@206.126.62.175:5060'
[Mar 14 16:08:27] DEBUG[228][C-00000008] pbx.c: Launching 'Dial'
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Extension: *42
Application: Dial
AppData: PJSIP/143/sip:424242143@206.126.62.175:5060


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALSTATUS
Value: 


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDPEERNUMBER
Value: 


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDPEERNAME
Value: 


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: ANSWEREDTIME
Value: 


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDTIME
Value: 


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newchannel
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: s
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: s
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: DIALEDPEERNUMBER
Value: 143/sip:424242143@206.126.62.175:5060


[Mar 14 16:08:27] DEBUG[16] threadpool.c: Increasing threadpool stasis-core's size by 1
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Extension: *42
Application: AppDial
AppData: (Outgoing Line)


[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: NewConnectedLine
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Allocated port 19960 for RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Creating ICE session [::]:19960 (19960) for RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: DialBegin
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
DestChannel: PJSIP/143-0000000d
DestChannelState: 0
DestChannelStateDesc: Down
DestCallerIDNum: 143
DestCallerIDName: PBX 143
DestConnectedLineNum: 142
DestConnectedLineName: PBX 142
DestLanguage: en
DestAccountCode: 
DestContext: from-internal
DestExten: *42
DestPriority: 1
DestUniqueid: 1489507707.27
DestLinkedid: 1489507707.26
DialString: 143/sip:424242143@206.126.62.175:5060


[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: NewConnectedLine
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26


[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] rtp_engine.c: RTP instance '0x7f3ac406a8a8' is setup and ready to go
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'd24d6d931b44' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'd24d6d931b44' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting 'fe80::42:acff:fe11:2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host 'fe80::42:acff:fe11:2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Method is INVITE
[Mar 14 16:08:27] DEBUG[228][C-00000008] channel.c: PJSIP/142-0000000c: Dropping redundant connected line update "PBX 143" <143>.
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is CALLING
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f3ac0000c38
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current transaction state is Calling
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is CALLING
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3abc0062d8 for Response msg 100/INVITE/cseq=4022 (rdata0x25294f8)
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/143-0000007e on dialog dlg0x7f3abc0062d8
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f3ac0000c38
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current transaction state is Proceeding
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is CALLING
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Response is 100 trying -- your call is important to us
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3abc0062d8 for Response msg 180/INVITE/cseq=4022 (rdata0x25294f8)
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/143-0000007e on dialog dlg0x7f3abc0062d8
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is EARLY
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Response is 180 Ringing
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f3ac0000c38
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current transaction state is Proceeding
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is EARLY
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Response is 180 Ringing
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: Newstate
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:27] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 143
[Mar 14 16:08:27] DEBUG[27] devicestate.c: Changing state for PJSIP/143 - state 6 (Ringing)
[Mar 14 16:08:27] DEBUG[31] app_queue.c: Extension '143@from-internal' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/143
State: RINGING


[Mar 14 16:08:27] DEBUG[74] app_queue.c: Device 'PJSIP/143' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 143
Context: from-internal
Hint: PJSIP/143
Status: 8
StatusText: Ringing


[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing
[Mar 14 16:08:27] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 142
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: DialState
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
DestChannel: PJSIP/143-0000000d
DestChannelState: 5
DestChannelStateDesc: Ringing
DestCallerIDNum: 143
DestCallerIDName: PBX 143
DestConnectedLineNum: 142
DestConnectedLineName: PBX 142
DestLanguage: en
DestAccountCode: 
DestContext: from-internal
DestExten: *42
DestPriority: 1
DestUniqueid: 1489507707.27
DestLinkedid: 1489507707.26
DialStatus: RINGING


[Mar 14 16:08:27] DEBUG[27] devicestate.c: Changing state for PJSIP/142 - state 2 (In use)
[Mar 14 16:08:27] DEBUG[209] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:27] DEBUG[209] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:27] DEBUG[209] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:27] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:27] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/142
State: INUSE


[Mar 14 16:08:27] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:27] DEBUG[74] app_queue.c: Device 'PJSIP/142' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:27] DEBUG[209] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:27] DEBUG[209] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:27] DEBUG[209] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is EARLY
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Mar 14 16:08:27] DEBUG[209] res_pjsip_pubsub.c: on_evsub_state called with state ACTIVE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current transaction state is Proceeding
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:27] DEBUG[31] app_queue.c: Extension '142@from-internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:27] DEBUG[44] res_pjsip_session.c: The current inv state is EARLY
[Mar 14 16:08:27] DEBUG[63] manager.c: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 142
Context: from-internal
Hint: PJSIP/142
Status: 1
StatusText: InUse


[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3ac4034998 for Response msg 200/NOTIFY/cseq=25860 (rdata0x25294f8)
[Mar 14 16:08:27] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000037 on dialog dlg0x7f3ac4034998
[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3abc0062d8 for Response msg 200/INVITE/cseq=4022 (rdata0x25294f8)
[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/143-0000007e on dialog dlg0x7f3abc0062d8
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONNECTING
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Response is 200 OK
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Mar 14 16:08:28] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:28] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:28] DEBUG[44] acl.c: For destination '206.126.62.175', our source address is '172.17.0.2'.
[Mar 14 16:08:28] DEBUG[44] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f3add575c20
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f3add575c20
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 0 (0x7f3ac403a190) from 0x7f3add575c20 to 0x7f3ac406aa70
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 101 (0x2340b30) from 0x7f3add575c20 to 0x7f3ac406aa70
[Mar 14 16:08:28] DEBUG[44] channel.c: Channel PJSIP/143-0000000d setting read format path: ulaw -> opus
[Mar 14 16:08:28] DEBUG[44] channel.c: Channel PJSIP/143-0000000d setting write format path: opus -> ulaw
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Mar 14 16:08:28] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:28] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:28] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:28] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:28] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac0000c38)
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f3ac0000c38
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current transaction state is Terminated
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Response is 200 OK
[Mar 14 16:08:28] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 143
[Mar 14 16:08:28] DEBUG[27] devicestate.c: Changing state for PJSIP/143 - state 2 (In use)
[Mar 14 16:08:28] DEBUG[74] app_queue.c: Device 'PJSIP/143' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:28] DEBUG[31] app_queue.c: Extension '143@from-internal' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:28] DEBUG[228][C-00000008] channel.c: Channel PJSIP/143-0000000d setting read format path: ulaw -> ulaw
[Mar 14 16:08:28] DEBUG[228][C-00000008] channel.c: Channel PJSIP/142-0000000c setting write format path: ulaw -> ulaw
[Mar 14 16:08:28] DEBUG[228][C-00000008] channel.c: Channel PJSIP/142-0000000c setting read format path: ulaw -> ulaw
[Mar 14 16:08:28] DEBUG[228][C-00000008] channel.c: Channel PJSIP/143-0000000d setting write format path: ulaw -> ulaw
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: Newstate
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 143
Context: from-internal
Hint: PJSIP/143
Status: 1
StatusText: InUse


[Mar 14 16:08:28] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 142
[Mar 14 16:08:28] DEBUG[27] devicestate.c: Changing state for PJSIP/142 - state 2 (In use)
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALSTATUS
Value: ANSWER


[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler
[Mar 14 16:08:28] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:28] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDPEERNAME
Value: PJSIP/143-0000000d


[Mar 14 16:08:28] DEBUG[44] acl.c: For destination '206.126.62.175', our source address is '172.17.0.2'.
[Mar 14 16:08:28] DEBUG[44] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f3ac403f3d8'
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 123 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/143
State: INUSE


[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 97 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDPEERNUMBER
Value: 143/sip:424242143@206.126.62.175:5060


[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Don't have a default tx payload type 2 format for m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f3add575df0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 0 (0x7f3ac4075e40) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 2 (0x7f3ac40771c0) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 9 (0x7f3ac40763d0) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 18 (0x7f3ac4076380) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: DialEnd
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
DestChannel: PJSIP/143-0000000d
DestChannelState: 6
DestChannelStateDesc: Up
DestCallerIDNum: 143
DestCallerIDName: PBX 143
DestConnectedLineNum: 142
DestConnectedLineName: PBX 142
DestLanguage: en
DestAccountCode: 
DestContext: from-internal
DestExten: 
DestPriority: 1
DestUniqueid: 1489507707.27
DestLinkedid: 1489507707.26
DialStatus: ANSWER


[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 97 (0x7f3ac4076490) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 101 (0x2340b30) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[44] rtp_engine.c: Copying tx payload mapping 123 (0x7f3ac4074080) from 0x7f3add575df0 to 0x7f3ac403f5a0
[Mar 14 16:08:28] DEBUG[209] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler
[Mar 14 16:08:28] DEBUG[209] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:28] DEBUG[209] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[Mar 14 16:08:28] DEBUG[209] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:28] DEBUG[209] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:28] DEBUG[209] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: Newstate
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26


[Mar 14 16:08:28] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:28] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:28] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:28] DEBUG[44] netsock2.c: Splitting '172.17.0.2' into...
[Mar 14 16:08:28] DEBUG[44] netsock2.c: ...host '172.17.0.2' and port ''.
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:28] DEBUG[209] res_pjsip_pubsub.c: on_evsub_state called with state ACTIVE
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONNECTING
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f3ac40228a8)
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current transaction state is Completed
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONNECTING
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge_native_rtp.c: Bridge '87d439e5-5cde-4642-92a3-a9c247d091ed' can not use native RTP bridge as two channels are required
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Chose bridge technology simple_bridge
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling simple_bridge technology constructor
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling simple_bridge technology start
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeCreate
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: simple_bridge
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 0
BridgeVideoSourceMode: none


[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b34013268(PJSIP/143-0000000d) is joining
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: pushing 0x7f3b34013268(PJSIP/143-0000000d)
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge_native_rtp.c: Bridge '87d439e5-5cde-4642-92a3-a9c247d091ed' can not use native RTP bridge as two channels are required
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Chose bridge technology simple_bridge
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is already using the new technology.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Extension: 
Application: AppDial
AppData: (Outgoing Line)


[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b34013268(PJSIP/143-0000000d) is joining simple_bridge technology
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeEnter
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: simple_bridge
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 1
BridgeVideoSourceMode: none
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b340048b8(PJSIP/142-0000000c) is joining
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: pushing 0x7f3b340048b8(PJSIP/142-0000000c)
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[30] cdr.c: Finalized CDR for PJSIP/143-0000000d - start 1489507707.277347 answer 1489507708.654081 end 1489507708.655636 dispo ANSWERED
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Chose bridge technology native_rtp
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling native_rtp technology constructor
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: moving 0x7f3b34013268(PJSIP/143-0000000d) to dummy bridge temporarily
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b34013268(PJSIP/143-0000000d) is leaving simple_bridge technology (dummy)
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling simple_bridge technology stop
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b340048b8(PJSIP/142-0000000c) is joining native_rtp technology
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b34013268(PJSIP/143-0000000d) is joining native_rtp technology
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling native_rtp technology start
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling simple_bridge technology destructor
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeEnter
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: simple_bridge
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 2
BridgeVideoSourceMode: none
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/143-0000000d


[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 09b7240a-2f6f-4999-b088-b39ef4700dec


[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Chose bridge technology native_rtp
[Mar 14 16:08:28] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is already using the new technology.
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/142-0000000c


[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Chose bridge technology native_rtp
[Mar 14 16:08:28] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is already using the new technology.
[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 1083502748-5060-26@BJC.BGI.B.EI


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/143-0000000d


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 09b7240a-2f6f-4999-b088-b39ef4700dec


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/142-0000000c


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 1083502748-5060-26@BJC.BGI.B.EI


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/143-0000000d


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 09b7240a-2f6f-4999-b088-b39ef4700dec


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/142-0000000c


[Mar 14 16:08:28] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 1083502748-5060-26@BJC.BGI.B.EI


[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3ac4034998 for Response msg 200/NOTIFY/cseq=25861 (rdata0x25294f8)
[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000037 on dialog dlg0x7f3ac4034998
[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3ac4018278 for Request msg ACK/cseq=71 (rdata0x25294f8)
[Mar 14 16:08:28] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000043 on dialog dlg0x7f3ac4018278
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current transaction state is Terminated
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The transaction state change event is USER
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONNECTING
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Received request
[Mar 14 16:08:28] DEBUG[44] res_pjsip_session.c: Method is ACK
[Mar 14 16:08:29] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1489507709 seconds since RTP was last sent on instance 0x7f3ac406a8a8. Sending keepalive
[Mar 14 16:08:29] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1489507709 seconds since RTP was last sent on instance 0x7f3ac403f3d8. Sending keepalive
[Mar 14 16:08:29] DEBUG[230][C-00000008] res_rtp_asterisk.c: 0x7f3ac405eee0 -- Probation learning mode pass with source address 206.126.62.175:16160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: 0x7f3ac4058df0 -- Probation learning mode pass with source address 206.126.62.175:19150
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[228][C-00000008] chan_pjsip.c: Oooh, got a frame with format of opus on channel 'PJSIP/142-0000000c' when we're sending 'ulaw', switching to match
[Mar 14 16:08:29] DEBUG[228][C-00000008] channel.c: Channel PJSIP/142-0000000c setting write format path: ulaw -> opus
[Mar 14 16:08:29] DEBUG[228][C-00000008] channel.c: Channel PJSIP/142-0000000c setting read format path: opus -> opus
[Mar 14 16:08:29] DEBUG[228][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Mar 14 16:08:29] DEBUG[228][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Mar 14 16:08:29] DEBUG[228][C-00000008] bridge.c: Chose bridge technology native_rtp
[Mar 14 16:08:29] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is already using the new technology.
[Mar 14 16:08:29] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/143-0000000d


[Mar 14 16:08:29] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 09b7240a-2f6f-4999-b088-b39ef4700dec


[Mar 14 16:08:29] DEBUG[230][C-00000008] channel.c: Channel PJSIP/143-0000000d changing write format from ulaw to opus, native formats (ulaw)
[Mar 14 16:08:29] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: PJSIP/142-0000000c


[Mar 14 16:08:29] DEBUG[230][C-00000008] channel.c: Channel PJSIP/143-0000000d setting write format path: opus -> ulaw
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[230][C-00000008] res_rtp_asterisk.c: Ooh, format changed from none to ulaw
[Mar 14 16:08:29] DEBUG[230][C-00000008] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7f3ac406a8a8'
[Mar 14 16:08:29] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 1083502748-5060-26@BJC.BGI.B.EI


[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:29] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:29] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 0 seconds since RTP was last sent on instance 0x7f3ac406a8a8. Not sending keepalive
[Mar 14 16:08:30] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 0 seconds since RTP was last sent on instance 0x7f3ac403f3d8. Not sending keepalive
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[58] res_pjsip_registrar_expire.c: Woke up at 1489507710  Interval: 30
[Mar 14 16:08:30] DEBUG[58] res_pjsip_registrar_expire.c: Expiring 0 contacts
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:30] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:30] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 0 seconds since RTP was last sent on instance 0x7f3ac406a8a8. Not sending keepalive
[Mar 14 16:08:31] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 0 seconds since RTP was last sent on instance 0x7f3ac403f3d8. Not sending keepalive
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: Wrapper created
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: Set timer to 20000 msec
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:31] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:31] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: No dialog serializer for response Response msg 200/OPTIONS/cseq=15220 (rdata0x25294f8). Using request transaction as basis
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000011 on transaction tsx0x7f3ac00104f8
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: PJSIP tsx response received
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: Cancelling timer
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: Timer cancelled
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: Callbacks executed
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac40300f8: wrapper destroyed
[Mar 14 16:08:31] DEBUG[49] res_pjsip/pjsip_configuration.c: Contact 100/sip:424242100@206.126.62.175:5060 status didn't change: Reachable, RTT: 34.991 msec
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[228][C-00000008] res_rtp_asterisk.c: Unsupported payload type received 
[Mar 14 16:08:31] DEBUG[230][C-00000008] translate.c: Sample size different 960 vs 160
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3abc0062d8 for Request msg BYE/cseq=2 (rdata0x25294f8)
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/143-0000007e on dialog dlg0x7f3abc0062d8
[Mar 14 16:08:31] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:31] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f3ac000b498
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current transaction state is Completed
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current inv state is DISCONNCTD
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Received request
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Method is BYE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '143(PJSIP/143-0000000d)'
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f3ac000b498
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current transaction state is Completed
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current inv state is DISCONNCTD
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: HangupRequest
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_channel.c: Setting 0x7f3b34013268(PJSIP/143-0000000d) state from:0 to:1
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: 


[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: pulling 0x7f3b34013268(PJSIP/143-0000000d)
[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b34013268(PJSIP/143-0000000d) is leaving native_rtp technology
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 


[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_native_rtp.c: Discontinued RTP bridging of 'PJSIP/142-0000000c' and 'PJSIP/143-0000000d' - media will flow through Asterisk core
[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: dissolving bridge with cause 16(Normal Clearing)
[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_channel.c: Setting 0x7f3b340048b8(PJSIP/142-0000000c) state from:0 to:2
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPEER
Value: 


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: BRIDGEPVTCALLID
Value: 


[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: queueing action type:13 sub:1001
[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is dissolved, not performing smart bridge operation.
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeLeave
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: native_rtp
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 1
BridgeVideoSourceMode: none
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26


[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: pulling 0x7f3b340048b8(PJSIP/142-0000000c)
[Mar 14 16:08:31] DEBUG[230][C-00000008] bridge_channel.c: Bridge is returning 0x7f3b34013268(PJSIP/143-0000000d) to write format ulaw
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge_channel.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: 0x7f3b340048b8(PJSIP/142-0000000c) is leaving native_rtp technology
[Mar 14 16:08:31] DEBUG[230][C-00000008] channel.c: Channel PJSIP/143-0000000d setting write format path: ulaw -> ulaw
[Mar 14 16:08:31] DEBUG[230][C-00000008] channel.c: Hanging up channel 'PJSIP/143-0000000d'
[Mar 14 16:08:31] DEBUG[230][C-00000008] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed is dissolved, not performing smart bridge operation.
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeLeave
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: native_rtp
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 0
BridgeVideoSourceMode: none
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26


[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge_channel.c: Bridge is returning 0x7f3b340048b8(PJSIP/142-0000000c) to read format ulaw
[Mar 14 16:08:31] DEBUG[30] cdr.c: Finalized CDR for PJSIP/142-0000000c - start 1489507707.276159 answer 1489507708.654765 end 1489507711.863692 dispo ANSWERED
[Mar 14 16:08:31] DEBUG[228][C-00000008] channel.c: Channel PJSIP/142-0000000c setting read format path: ulaw -> ulaw
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: actually destroying basic bridge, nobody wants it anymore
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling basic bridge destructor
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling native_rtp technology stop
[Mar 14 16:08:31] DEBUG[228][C-00000008] bridge.c: Bridge 87d439e5-5cde-4642-92a3-a9c247d091ed: calling native_rtp technology destructor
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: BridgeDestroy
Privilege: call,all
BridgeUniqueid: 87d439e5-5cde-4642-92a3-a9c247d091ed
BridgeType: basic
BridgeTechnology: native_rtp
BridgeCreator: <unknown>
BridgeName: <unknown>
BridgeNumChannels: 0
BridgeVideoSourceMode: none


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: ANSWEREDTIME
Value: 3


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALEDTIME
Value: 4


[Mar 14 16:08:31] DEBUG[228][C-00000008] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Mar 14 16:08:31] DEBUG[228][C-00000008] pbx.c: Spawn extension (from-internal,*42,2) exited non-zero on 'PJSIP/142-0000000c'
[Mar 14 16:08:31] DEBUG[228][C-00000008] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/142-0000000c'
[Mar 14 16:08:31] DEBUG[30] cdr.c: CDR for PJSIP/143-0000000d is dialed and has no Party B; discarding
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Variable: DIALSTATUS
Value: ANSWER


[Mar 14 16:08:31] DEBUG[228][C-00000008] channel.c: Soft-Hanging (0x80) up channel 'PJSIP/142-0000000c'
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: Hangup
Privilege: call,all
Channel: PJSIP/143-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 143
CallerIDName: PBX 143
ConnectedLineNum: 142
ConnectedLineName: PBX 142
Language: en
AccountCode: 
Context: from-internal
Exten: 
Priority: 1
Uniqueid: 1489507707.27
Linkedid: 1489507707.26
Cause: 16
Cause-txt: Normal Clearing


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: SoftHangupRequest
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: *42
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Cause: 16


[Mar 14 16:08:31] DEBUG[228][C-00000008] pbx_variables.c: Function CHANNEL(rtcp,all_loss) result is 'minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;'
[Mar 14 16:08:31] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 143
[Mar 14 16:08:31] DEBUG[27] devicestate.c: Changing state for PJSIP/143 - state 1 (Not in use)
[Mar 14 16:08:31] DEBUG[228][C-00000008] pbx_variables.c: Function CHANNEL(rtcp,all_jitter) result is 'minrxjitter=0.000038;maxrxjitter=0.003326;avgrxjitter=0.001646;stdevrxjitter=7138885154608124848560394222472834105800044242116879552908487233216372147344507541920867183328724516444569600.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;'
[Mar 14 16:08:31] DEBUG[228][C-00000008] pbx.c: Launching 'Set'
[Mar 14 16:08:31] DEBUG[74] app_queue.c: Device 'PJSIP/143' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:31] DEBUG[31] app_queue.c: Extension '143@from-internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/143
State: NOT_INUSE


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 143
Context: from-internal
Hint: PJSIP/143
Status: 0
StatusText: Idle


[Mar 14 16:08:31] DEBUG[228][C-00000008] channel.c: Hanging up channel 'PJSIP/142-0000000c'
[Mar 14 16:08:31] DEBUG[228][C-00000008] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP)
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: Newexten
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: h
Priority: 1
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Extension: h
Application: Set
AppData: CDR(cdr_rtcp_audio_qos)=minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;minrxjitter=0.000038;maxrxjitter=0.003326;avgrxjitter=0.001646;stdevrxjitter=7138885154608124848560394222472834105800044242116879552908487233216372147344507541920867183328724516444569600.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;


[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: Method is BYE
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:31] DEBUG[209] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:31] DEBUG[209] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:31] DEBUG[209] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:31] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:31] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:31] DEBUG[44] res_pjsip_pubsub.c: on_evsub_state called with state ACTIVE
[Mar 14 16:08:31] DEBUG[209] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:31] DEBUG[209] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The state change pertains to the endpoint '142(PJSIP/142-0000000c)'
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The current transaction state is Calling
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The transaction state change event is TX_MSG
[Mar 14 16:08:31] DEBUG[209] res_pjsip_session.c: The current inv state is CONFIRMED
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: Hangup
Privilege: call,all
Channel: PJSIP/142-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 142
CallerIDName: PBX 142
ConnectedLineNum: 143
ConnectedLineName: PBX 143
Language: en
AccountCode: 
Context: from-internal
Exten: h
Priority: 2
Uniqueid: 1489507707.26
Linkedid: 1489507707.26
Cause: 16
Cause-txt: Normal Clearing


[Mar 14 16:08:31] DEBUG[27] devicestate.c: No provider found, checking channel drivers for PJSIP - 142
[Mar 14 16:08:31] DEBUG[27] devicestate.c: Changing state for PJSIP/142 - state 1 (Not in use)
[Mar 14 16:08:31] DEBUG[74] app_queue.c: Device 'PJSIP/142' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/142
State: NOT_INUSE


[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: ExtensionStatus
Privilege: call,all
Exten: 142
Context: from-internal
Hint: PJSIP/142
Status: 0
StatusText: Idle


[Mar 14 16:08:31] DEBUG[31] app_queue.c: Extension '142@from-internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Mar 14 16:08:31] DEBUG[30] res_odbc.c: Reusing ODBC handle 0x7f3abc01e8b8 from class 'cdrconnection'
[Mar 14 16:08:31] DEBUG[30] cdr_adaptive_odbc.c: Executing [INSERT INTO cdr_log (unique_id, tstamp_start, tstamp_end, answer_status) VALUES ('1489507707.26', '2017-03-14 16:08:27', '2017-03-14 16:08:31', '8')]
[Mar 14 16:08:31] DEBUG[30] res_odbc.c: Releasing ODBC handle 0x7f3abc01e8b8 into pool
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(uniqueid) result is '1489507707.26'
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(start) result is '2017-03-14 16:08:27'
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(end) result is '2017-03-14 16:08:31'
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(disposition) result is 'ANSWERED'
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_direction) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_application) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_inbound_did) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_inbound_from_phonenumber) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_inbound_from_callerid) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_inbound_to_extension) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_outbound_did) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_outbound_dialed_phonenumber) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_outbound_from_extension) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_internal_from_extension) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_internal_to_extension) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_record_file_location) result is ''
[Mar 14 16:08:31] DEBUG[30] pbx_variables.c: Function CDR(cdr_rtcp_audio_qos) result is 'minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;minrxjitter=0.000038;maxrxjitter=0.003326;avgrxjitter=0.001646;stdevrxjitter=7138885154608124848560394222472834105800044242116879552908487233216372147344507541920867183328724516444569600.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;'
[Mar 14 16:08:31] DEBUG[63] manager.c: Examining AMI event:
Event: Cdr
Privilege: cdr,all
AccountCode: 
Source: 142
Destination: *42
DestinationContext: from-internal
CallerID: "PBX 142" <142>
Channel: PJSIP/142-0000000c
DestinationChannel: PJSIP/143-0000000d
LastApplication: Dial
LastData: PJSIP/143/sip:424242143@206.126.62.175:5060
StartTime: 2017-03-14 16:08:27
AnswerTime: 2017-03-14 16:08:28
EndTime: 2017-03-14 16:08:31
Duration: 4
BillableSeconds: 3
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1489507707.26
UserField: 
unique_id: 1489507707.26
tstamp_start: 2017-03-14 16:08:27
tstamp_end: 2017-03-14 16:08:31
answer_status: ANSWERED
direction: 
application: 
inbound_did: 
inbound_from_phonenumber: 
inbound_from_callerid: 
inbound_to_extension: 
outbound_did: 
outbound_dialed_phonenumber: 
outbound_from_extension: 
internal_from_extension: 
internal_to_extension: 
record_file_location: 
rtcp_audio_qos: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;minrxjitter=0.000038;maxrxjitter=0.003326;avgrxjitter=0.001646;stdevrxjitter=7138885154608124848560394222472834105800044242116879552908487233216372147344507541920867183328724516444569600.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;


[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3ac4034998 for Response msg 200/NOTIFY/cseq=25862 (rdata0x25294f8)
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000037 on dialog dlg0x7f3ac4034998
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: Wrapper created
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: Set timer to 20000 msec
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '206.126.62.175'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Transport type for target '206.126.62.175' is 'UDP'
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_resolver.c: Target '206.126.62.175' is an IP address, skipping resolution
[Mar 14 16:08:31] DEBUG[44] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to 172.17.0.2:5060
[Mar 14 16:08:31] DEBUG[44] netsock2.c: Splitting '206.126.62.175' into...
[Mar 14 16:08:31] DEBUG[44] netsock2.c: ...host '206.126.62.175' and port ''.
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f3ac4018278 for Response msg 200/BYE/cseq=31781 (rdata0x25294f8)
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000043 on dialog dlg0x7f3ac4018278
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142()'
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: There is no transaction involved in this state change
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current inv state is DISCONNCTD
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Source of transaction state change is RX_MSG
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Response is 200 OK
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The state change pertains to the endpoint '142()'
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f3ac40228a8
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current transaction state is Completed
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The transaction state change event is RX_MSG
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: The current inv state is DISCONNCTD
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Received response
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: Response is 200 OK
[Mar 14 16:08:31] DEBUG[44] res_pjsip_session.c: BYE received final response code 200
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: No dialog serializer for response Response msg 200/OPTIONS/cseq=26301 (rdata0x25294f8). Using request transaction as basis
[Mar 14 16:08:31] DEBUG[43] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000012 on transaction tsx0x7f3ac0000c38
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: PJSIP tsx response received
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: Cancelling timer
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: Timer cancelled
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[Mar 14 16:08:31] DEBUG[44] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: Callbacks executed
[Mar 14 16:08:31] DEBUG[44] res_pjsip.c: 0x7f3ac401a158: wrapper destroyed
[Mar 14 16:08:31] DEBUG[49] res_pjsip/pjsip_configuration.c: Contact 143/sip:424242143@206.126.62.175:5060 status didn't change: Reachable, RTT: 24.556 msec
[Mar 14 16:08:32] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1 seconds since RTP was last sent on instance 0x7f3ac406a8a8. Sending keepalive
[Mar 14 16:08:32] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1 seconds since RTP was last sent on instance 0x7f3ac403f3d8. Sending keepalive
[Mar 14 16:08:33] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1 seconds since RTP was last sent on instance 0x7f3ac406a8a8. Sending keepalive
[Mar 14 16:08:33] DEBUG[57] res_pjsip_sdp_rtp.c: It has been 1 seconds since RTP was last sent on instance 0x7f3ac403f3d8. Sending keepalive