REAL CALL

<--- SIP read from UDP:67.231.X.X:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.241.X.X:5060;received=54.241.X.X;branch=z9hG4bK01152689;rport=5060
From:  <sip:+1866707zzzz@54.241.X.X>;tag=as792505fe
To: <sip:+1971238xxxx@67.231.X.X>;tag=gK08843a6c
Call-ID: 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060
CSeq: 102 INVITE
Record-Route: <sip:67.231.Y.Y:5060;lr;ftag=as792505fe>
Record-Route: <sip:67.231.X.X:5060;lr=on;ftag=as792505fe>
Accept: application/sdp
Contact: <sip:+1971238xxxx@67.231.w.w:5060>
Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
Server: YATE/3.0.0
Content-Length:  258
Content-Type: application/sdp

v=0
o=Sonus_UAC 2282 10956 IN IP4 67.231.w.w
s=SIP Media Capabilities
c=IN IP4 67.231.u.u
t=0 0
m=audio 18434 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=maxptime:20

<------------->
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 94]: Via: SIP/2.0/UDP 54.241.X.X:5060;received=54.241.X.X;branch=z9hG4bK01152689;rport=5060
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 55]: From:  <sip:+1866707zzzz@54.241.X.X>;tag=as792505fe
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 50]: To: <sip:+1971238xxxx@67.231.X.X>;tag=gK08843a6c
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 61]: Call-ID: 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 55]: Record-Route: <sip:67.231.Y.Y:5060;lr;ftag=as792505fe>
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 59]: Record-Route: <sip:67.231.X.X:5060;lr=on;ftag=as792505fe>
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 23]: Accept: application/sdp
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 45]: Contact: <sip:+1971238xxxx@67.231.w.w:5060>
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 41]: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 18]: Server: YATE/3.0.0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 12 [ 20]: Content-Length:  258
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 13 [ 29]: Content-Type: application/sdp
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 14 [  0]: 
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  0 [  3]: v=0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  1 [ 42]: o=Sonus_UAC 2282 10956 IN IP4 67.231.w.w
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  2 [ 24]: s=SIP Media Capabilities
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  3 [ 21]: c=IN IP4 67.231.u.u
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  4 [  5]: t=0 0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  5 [ 28]: m=audio 18434 RTP/AVP 18 101
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  6 [ 21]: a=rtpmap:18 G729/8000
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  7 [ 19]: a=fmtp:18 annexb=no
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  8 [ 33]: a=rtpmap:101 telephone-event/8000
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body  9 [ 15]: a=fmtp:101 0-15
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body 10 [ 10]: a=sendrecv
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:    Body 11 [ 13]: a=maxptime:20
--- (14 headers 12 lines) ---
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:4528 __sip_ack: Acked pending invite 102
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:22665 handle_response_invite: SIP response 200 to standard invite
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:10060 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:10866 process_sdp_o: Call 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060 responded to our reinvite without changing SDP version; ignoring SDP.
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:6679 update_call_counter: Updating call counter for outgoing call
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:16288 build_route: build_route: Record-Route hop: <sip:67.231.Y.Y:5060;lr;ftag=as792505fe>
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:16288 build_route: build_route: Record-Route hop: <sip:67.231.X.X:5060;lr=on;ftag=as792505fe>
list_route: hop: <sip:67.231.X.X:5060;lr=on;ftag=as792505fe>
list_route: hop: <sip:67.231.Y.Y:5060;lr;ftag=as792505fe>
set_destination: Parsing <sip:67.231.X.X:5060;lr=on;ftag=as792505fe> for address/port to send to
set_destination: set destination to 67.231.X.X:5060
Transmitting (NAT) to 67.231.X.X:5060:
ACK sip:+1971238xxxx@67.231.w.w:5060 SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK18299972;rport
Route: <sip:67.231.X.X:5060;lr=on;ftag=as792505fe>,<sip:67.231.Y.Y:5060;lr;ftag=as792505fe>
Max-Forwards: 70
From: "James" <sip:+1866707zzzz@54.241.X.X>;tag=as792505fe
To: <sip:+1971238xxxx@67.231.X.X>;tag=gK08843a6c
Contact: <sip:+1866707zzzz@54.241.X.X:5060>
Call-ID: 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX 11.5.0
Content-Length: 0

---
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:3874 __sip_xmit: Trying to put 'ACK sip:+19' onto UDP socket destined for 67.231.X.X:5060
    -- SIP/BANDWIDTH-00000124 answered SIP/ws-Opensips-00000123
[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/BANDWIDTH-00000124
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1971238xxxx
CallerIDName: 
ConnectedLineNum: +1866707zzzz
ConnectedLineName: James
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: rtp_engine.c:1805 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/ws-Opensips-00000123' with that of 'SIP/BANDWIDTH-00000124'
[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - BANDWIDTH
[Jul 24 21:30:57] DEBUG[32050]: chan_sip.c:29634 sip_devicestate: Checking device state for peer BANDWIDTH
[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:467 do_state_change: Changing state for SIP/BANDWIDTH - state 1 (Not in use)
[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:442 devstate_event: device 'SIP/BANDWIDTH' state '1'
[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: DIALEDPEERNAME
Value: SIP/BANDWIDTH-00000124
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: DIALEDPEERNUMBER
Value: BANDWIDTH/+1971238xxxx
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32087]: app_queue.c:1805 handle_statechange: Device 'SIP/BANDWIDTH' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000124
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000124
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000123
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/ws-Opensips-00000123
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: +1866707zzzz
CallerIDName: James
ConnectedLineNum: 
ConnectedLineName: 
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - ws-Opensips
[Jul 24 21:30:57] DEBUG[32050]: chan_sip.c:29634 sip_devicestate: Checking device state for peer ws-Opensips
[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:467 do_state_change: Changing state for SIP/ws-Opensips - state 1 (Not in use)
[Jul 24 21:30:57] DEBUG[32050]: devicestate.c:442 devstate_event: device 'SIP/ws-Opensips' state '1'
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:7271 sip_answer: SIP answering channel: SIP/ws-Opensips-00000123
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:13683 transmit_response_with_sdp: Setting framing from config on incoming call
[Jul 24 21:30:57] DEBUG[32087]: app_queue.c:1805 handle_statechange: Device 'SIP/ws-Opensips' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:13233 add_sdp: ** Our capability: (ulaw|opus) Video flag: True Text flag: True
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:13234 add_sdp: ** Our prefcodec: (nothing) 
Audio is at 15602
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: sip/sdp_crypto.c:310 sdp_crypto_offer: Crypto line: a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:HyuyvJDL5afEeJTWl6n5+uyjT7SNBma2Qk84F75+
Adding codec 100030 (opus) to SDP
Adding codec 100003 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:13371 add_sdp: -- Done with adding codecs to SDP
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:12677 add_ice_to_sdp: About to increment the port for the second srflx candidate by 1, as we assume rtcp attribute not present in SDP...
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:12682 add_ice_to_sdp: Incremented candidate port for the second srflx component-id (rtcp) by 1 and set to 15603
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:13569 add_sdp: Done building SDP. Settling with this capability: (ulaw|opus)

<--- Reliably Transmitting (NAT) to 54.236.X.X:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.236.Z.Z:5060;branch=z9hG4bKff5c.784a7ff3.0;received=54.236.X.X;rport=5060
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK5f363762511ad3be8958270ff7e708446ff8c09e;rport=5060
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK1962437
Record-Route: <sip:54.236.Z.Z;lr>
Record-Route: <sip:10.96.Y.Y:5060;transport=udp;lr;ovid=995789c8>
Record-Route: <sip:7e9bfee891@10.96.Y.Y:10080;transport=ws;lr;ovid=995789c8>
From: "James" <sip:1111@54.236.X.X>;tag=b8qq35jhfj
To: <sip:+1971238xxxx@54.236.X.X>;tag=as7be635fc
Call-ID: pfktrgig1fk1h5q07lu6
CSeq: 4735 INVITE
Server: Asterisk PBX 11.5.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:1971238xxxx@54.241.X.X:5060>
Content-Type: application/sdp
Content-Length: 842

v=0
o=root 788087117 788087118 IN IP4 54.241.X.X
s=Asterisk PBX 11.5.0
c=IN IP4 54.241.X.X
t=0 0
m=audio 15602 RTP/SAVPF 111 0 101
a=rtpmap:111 opus/48000/2
a=maxptime:60
a=fmtp:111 maxplaybackrate=16000; stereo=0; sprop-stereo=0; useinbandfec=0
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=ice-ufrag:3fa48a7d79dd6c34415ab8c823bb0165
a=ice-pwd:5696412769c3ab3d7b046f2d50c8b466
a=candidate:Habc87c8 1 UDP 2130706431 10.188.x.x 15602 typ host
a=candidate:S36f165cd 1 UDP 1694498815 54.241.X.X 15602 typ srflx
a=candidate:Habc87c8 2 UDP 2130706430 10.188.x.x 15603 typ host
a=candidate:S36f165cd 2 UDP 1694498814 54.241.X.X 15603 typ srflx
a=sendrecv
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:HyuyvJDL5afEeJTWl6n5+uyjT7SNBma2Qk84F75+

<------------>
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404467
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: chan_sip.c:3874 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 54.236.X.X:5060
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: features.c:4419 ast_bridge_call: bridge answer set, chan answer set
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: features.c:4240 clear_dialed_interfaces: Removing dialed interfaces datastore on SIP/BANDWIDTH-00000124 since we're bridging
[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: SIP/BANDWIDTH-00000124
Uniqueid: 1374701443.310
AccountCode: 
OldAccountCode: 

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: Bridge
Privilege: call,all
Bridgestate: Link
Bridgetype: core
Channel1: SIP/ws-Opensips-00000123
Channel2: SIP/BANDWIDTH-00000124
Uniqueid1: 1374701442.309
Uniqueid2: 1374701443.310
CallerID1: +1866707zzzz
CallerID2: 1971238xxxx

[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:30:57] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000124
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: BRIDGEPVTCALLID
Value: 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000124
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000123
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000124
Variable: BRIDGEPVTCALLID
Value: pfktrgig1fk1h5q07lu6
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000124
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000123
Variable: BRIDGEPVTCALLID
Value: 4b0efdb90e93d85b56b2c2d5682f0d49@54.241.X.X:5060
Uniqueid: 1374701442.309

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000124
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000123
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000124
Variable: BRIDGEPVTCALLID
Value: pfktrgig1fk1h5q07lu6
Uniqueid: 1374701443.310

[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:4118 retrans_pkt: SIP TIMER: Rescheduling retransmission #404467 (1) SIP/2.0 - 1
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:4138 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #404467)) 
Retransmitting #1 (NAT) to 54.236.X.X:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.236.Z.Z:5060;branch=z9hG4bKff5c.784a7ff3.0;received=54.236.X.X;rport=5060
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK5f363762511ad3be8958270ff7e708446ff8c09e;rport=5060
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK1962437
Record-Route: <sip:54.236.Z.Z;lr>
Record-Route: <sip:10.96.Y.Y:5060;transport=udp;lr;ovid=995789c8>
Record-Route: <sip:7e9bfee891@10.96.Y.Y:10080;transport=ws;lr;ovid=995789c8>
From: "James" <sip:1111@54.236.X.X>;tag=b8qq35jhfj
To: <sip:+1971238xxxx@54.236.X.X>;tag=as7be635fc
Call-ID: pfktrgig1fk1h5q07lu6
CSeq: 4735 INVITE
Server: Asterisk PBX 11.5.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:1971238xxxx@54.241.X.X:5060>
Content-Type: application/sdp
Content-Length: 842

v=0
o=root 788087117 788087118 IN IP4 54.241.X.X
s=Asterisk PBX 11.5.0
c=IN IP4 54.241.X.X
t=0 0
m=audio 15602 RTP/SAVPF 111 0 101
a=rtpmap:111 opus/48000/2
a=maxptime:60
a=fmtp:111 maxplaybackrate=16000; stereo=0; sprop-stereo=0; useinbandfec=0
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=ice-ufrag:3fa48a7d79dd6c34415ab8c823bb0165
a=ice-pwd:5696412769c3ab3d7b046f2d50c8b466
a=candidate:Habc87c8 1 UDP 2130706431 10.188.x.x 15602 typ host
a=candidate:S36f165cd 1 UDP 1694498815 54.241.X.X 15602 typ srflx
a=candidate:Habc87c8 2 UDP 2130706430 10.188.x.x 15603 typ host
a=candidate:S36f165cd 2 UDP 1694498814 54.241.X.X 15603 typ srflx
a=sendrecv
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:HyuyvJDL5afEeJTWl6n5+uyjT7SNBma2Qk84F75+

---
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 54.236.X.X:5060

<--- SIP read from UDP:54.236.Z.Z:5060 --->
ACK sip:1971238xxxx@54.241.X.X:5060 SIP/2.0
Via: SIP/2.0/UDP 54.236.Z.Z:5060;branch=z9hG4bKff5c.784a7ff3.2
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK5a50e74242ab57e44c1737bda3b0164afd66857f
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK4013717
Max-Forwards:  9
To: <sip:+1971238xxxx@54.236.X.X>;tag=as7be635fc
From: "James" <sip:1111@54.236.X.X>;tag=b8qq35jhfj
Call-ID: pfktrgig1fk1h5q07lu6
CSeq: 4735 ACK
Supported: path, outbound, gruu
User-Agent: JsSIP 0.3.0
Content-Length: 0

<------------->
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 47]: ACK sip:1971238xxxx@54.241.X.X:5060 SIP/2.0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 66]: Via: SIP/2.0/UDP 54.236.Z.Z:5060;branch=z9hG4bKff5c.784a7ff3.2
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [113]: Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK5a50e74242ab57e44c1737bda3b0164afd66857f
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 58]: Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK4013717
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 16]: Max-Forwards:  9
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 51]: To: <sip:+1971238xxxx@54.236.X.X>;tag=as7be635fc
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 54]: From: "James" <sip:1111@54.236.X.X>;tag=b8qq35jhfj
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 29]: Call-ID: pfktrgig1fk1h5q07lu6
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 14]: CSeq: 4735 ACK
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 31]: Supported: path, outbound, gruu
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 23]: User-Agent: JsSIP 0.3.0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 17]: Content-Length: 0
[Jul 24 21:30:57] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 12 [  0]: 
--- (12 headers 0 lines) ---
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:28176 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404467
[Jul 24 21:30:57] DEBUG[32062][C-000001b7]: chan_sip.c:4566 __sip_ack: Stopping retransmission on 'pfktrgig1fk1h5q07lu6' of Response 4735: Match Found
[Jul 24 21:30:58] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2689 ast_rtp_write: Ooh, format changed from unknown to g729
[Jul 24 21:30:58] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2726 ast_rtp_write: Created smoother: format: g729 ms: 20 len: 20
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 2cfe7bad434673962b8c131849f28bca@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:30:59] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.16.z.z', our source address is '10.188.x.x'.
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.16.z.z:5060 is not local, substituting externaddr
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '2cfe7bad434673962b8c131849f28bca@10.188.x.x:5060' to '1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060'
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK3a79f685;rport
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as4ba81d6f
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:30:59 GMT
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 67.16.z.z:5060:
OPTIONS sip:67.16.z.z SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK3a79f685;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as4ba81d6f
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:30:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404468
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 67.16.z.z:5060
[Jul 24 21:30:59] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701459.1289195520
SentRTP: 157425056
SentPackets: 66
SentOctets: 1320
ReportBlock:
FractionLost: 255
CumulativeLoss: 64881
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18323.3140 (sec)

[Jul 24 21:30:59] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701459.1293950976
SentRTP: 71040
SentPackets: 730
SentOctets: 87470
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0007
TheirLastSR: 0
DLSR: 18323.3150 (sec)

[Jul 24 21:30:59] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2549 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x7f0078084f48'
[Jul 24 21:30:59] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060
Really destroying SIP dialog '1a568e69475796fc37a0703b1d5e941b@54.241.X.X:5060' Method: OPTIONS
ip-10-188-135-200*CLI> fdsfdsg
No such command 'fdsfdsg' (type 'core show help fdsfdsg' for other possible commands)
ip-10-188-135-200*CLI> fds
No such command 'fds' (type 'core show help fds' for other possible commands)
ip-10-188-135-200*CLI> 
[Jul 24 21:31:04] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701464.1291464704
SentRTP: 157465056
SentPackets: 316
SentOctets: 6320
ReportBlock:
FractionLost: 2
CumulativeLoss: 64883
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18328.3150 (sec)

[Jul 24 21:31:04] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701464.1300283392
SentRTP: 311040
SentPackets: 978
SentOctets: 84494
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0009
TheirLastSR: 0
DLSR: 18328.3170 (sec)

[Jul 24 21:31:04] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2549 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x7f0078084f48'
[Jul 24 21:31:09] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701469.1293160448
SentRTP: 157505216
SentPackets: 567
SentOctets: 11340
ReportBlock:
FractionLost: 3
CumulativeLoss: 64886
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18333.3150 (sec)

[Jul 24 21:31:09] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701469.1322496000
SentRTP: 552000
SentPackets: 1226
SentOctets: 81518
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0007
TheirLastSR: 0
DLSR: 18333.3220 (sec)

[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 6e50c941656130e9278ac4372ad7ba1b@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:31:09] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.16.z.z', our source address is '10.188.x.x'.
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.16.z.z:5060 is not local, substituting externaddr
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '6e50c941656130e9278ac4372ad7ba1b@10.188.x.x:5060' to '2fc1c682329780d74719624b5f91e985@54.241.X.X:5060'
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 2fc1c682329780d74719624b5f91e985@54.241.X.X:5060
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK732e37b3;rport
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as2f4061f6
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 2fc1c682329780d74719624b5f91e985@54.241.X.X:5060
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:31:09 GMT
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 67.16.z.z:5060:
OPTIONS sip:67.16.z.z SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK732e37b3;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as2f4061f6
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 2fc1c682329780d74719624b5f91e985@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:31:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404474
[Jul 24 21:31:09] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 67.16.z.z:5060
[Jul 24 21:31:10] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 2fc1c682329780d74719624b5f91e985@54.241.X.X:5060
Really destroying SIP dialog '2fc1c682329780d74719624b5f91e985@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:31:14] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701474.1292820480
SentRTP: 157545216
SentPackets: 817
SentOctets: 16340
ReportBlock:
FractionLost: 8
CumulativeLoss: 64894
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18338.3150 (sec)

[Jul 24 21:31:14] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701474.1350905856
SentRTP: 792000
SentPackets: 1468
SentOctets: 78614
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0008
TheirLastSR: 0
DLSR: 18338.3290 (sec)

[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 11278c9b247cc6f415cb9d3448563a2a@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:31:14] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '202.71.134.11', our source address is '10.188.x.x'.
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 202.71.134.11:5060 is not local, substituting externaddr
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '11278c9b247cc6f415cb9d3448563a2a@10.188.x.x:5060' to '4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060'
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:202.71.134.11 SIP/2.0
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK5a05a039;rport
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as7fffb81a
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:202.71.134.11>
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:31:14 GMT
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 202.71.134.11:5060:
OPTIONS sip:202.71.134.11 SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK5a05a039;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as7fffb81a
To: <sip:202.71.134.11>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:31:14 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404478
[Jul 24 21:31:14] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 202.71.134.11:5060

<--- SIP read from UDP:202.71.134.11:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK5a05a039;rport
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as7fffb81a
Call-ID: 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
CSeq: 102 OPTIONS
To: <sip:202.71.134.11>;tag=abcdefg
Accept: application/sdp
Record-Route: <sip:nexge@202.71.134.11:5060>
Content-Length: 0

<------------->
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK5a05a039;rport
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as7fffb81a
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: Call-ID: 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 35]: To: <sip:202.71.134.11>;tag=abcdefg
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 23]: Accept: application/sdp
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 44]: Record-Route: <sip:nexge@202.71.134.11:5060>
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 17]: Content-Length: 0
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [  0]: 
--- (9 headers 0 lines) ---
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404478
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:31:15] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060
Really destroying SIP dialog '4a153a882a6cf9a9549e281755ee0825@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:31:19] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701479.1287872512
SentRTP: 157585376
SentPackets: 1068
SentOctets: 21360
ReportBlock:
FractionLost: 7
CumulativeLoss: 64901
IAJitter: 0.0007
TheirLastSR: 0
DLSR: 18343.3140 (sec)

[Jul 24 21:31:19] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701479.1378783232
SentRTP: 1032000
SentPackets: 1711
SentOctets: 75698
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18343.3360 (sec)

[Jul 24 21:31:19] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2549 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x7f0078084f48'
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 5168ef9b7a1818c364ac2c564d2e8325@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:31:20] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.16.z.z', our source address is '10.188.x.x'.
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.16.z.z:5060 is not local, substituting externaddr
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '5168ef9b7a1818c364ac2c564d2e8325@10.188.x.x:5060' to '722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060'
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK651b06a8;rport
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as5a0b9a79
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:31:20 GMT
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 67.16.z.z:5060:
OPTIONS sip:67.16.z.z SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK651b06a8;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as5a0b9a79
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:31:20 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404482
[Jul 24 21:31:20] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 67.16.z.z:5060
[Jul 24 21:31:21] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060
Really destroying SIP dialog '722c9e6309dfbdac7e75e03721aeed6d@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:31:24] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701484.1287929856
SentRTP: 157625376
SentPackets: 1318
SentOctets: 26360
ReportBlock:
FractionLost: 5
CumulativeLoss: 64906
IAJitter: 0.0006
TheirLastSR: 0
DLSR: 18348.3140 (sec)

[Jul 24 21:31:24] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701484.1386823680
SentRTP: 1272000
SentPackets: 1956
SentOctets: 72758
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0008
TheirLastSR: 0
DLSR: 18348.3380 (sec)

[Jul 24 21:31:24] DEBUG[31238][C-000001b7]: res_rtp_asterisk.c:2549 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x7f0078084f48'
[Jul 24 21:31:29] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 67.231.u.u:18435
OurSSRC: 1787204280
SentNTP: 1374701489.1293504512
SentRTP: 157665536
SentPackets: 1569
SentOctets: 31380
ReportBlock:
FractionLost: 4
CumulativeLoss: 64910
IAJitter: 0.0007
TheirLastSR: 0
DLSR: 18353.3150 (sec)

[Jul 24 21:31:29] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44166
OurSSRC: 738637595
SentNTP: 1374701489.1400610816
SentRTP: 1512960
SentPackets: 2203
SentOctets: 69794
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0009
TheirLastSR: 0
DLSR: 18353.3410 (sec)

[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 405c88a2615fe35a6ce4870c09ea0445@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:31:31] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.16.z.z', our source address is '10.188.x.x'.
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.16.z.z:5060 is not local, substituting externaddr
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '405c88a2615fe35a6ce4870c09ea0445@10.188.x.x:5060' to '4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060'
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK163b1860;rport
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as29043cad
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:31:31 GMT
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 67.16.z.z:5060:
OPTIONS sip:67.16.z.z SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK163b1860;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as29043cad
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:31:31 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404487
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 67.16.z.z:5060
[Jul 24 21:31:31] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060
Really destroying SIP dialog '4a1a470d3d05e54c20f1b3ad63797a0e@54.241.X.X:5060' Method: OPTIONS