TO VOICEMAIL

<--- 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=z9hG4bK4b628679;rport=5060
From:  <sip:+1866707zzzz@54.241.X.X>;tag=as00e8891c
To: <sip:+1971238xxxx@67.231.X.X>;tag=gK02d455a8
Call-ID: 488209b33b5a887454a73e3413e29cd5@54.241.X.X:5060
CSeq: 102 INVITE
Record-Route: <sip:67.231.Y.Y:5060;lr;ftag=as00e8891c>
Record-Route: <sip:67.231.X.X:5060;lr=on;ftag=as00e8891c>
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:  259
Content-Type: application/sdp

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

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

[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: rtp_engine.c:1805 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/ws-Opensips-00000121' with that of 'SIP/BANDWIDTH-00000122'
[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - BANDWIDTH
[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32050]: chan_sip.c:29634 sip_devicestate: Checking device state for peer BANDWIDTH
[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:467 do_state_change: Changing state for SIP/BANDWIDTH - state 1 (Not in use)
[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:442 devstate_event: device 'SIP/BANDWIDTH' state '1'
[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: DIALEDPEERNAME
Value: SIP/BANDWIDTH-00000122
Uniqueid: 1374701220.307

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

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000122
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000122
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000121
Uniqueid: 1374701221.308

[Jul 24 21:27:27] 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:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:7271 sip_answer: SIP answering channel: SIP/ws-Opensips-00000121
[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - ws-Opensips
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:27:27] DEBUG[32050]: chan_sip.c:29634 sip_devicestate: Checking device state for peer ws-Opensips
[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/ws-Opensips-00000121
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: +1866707zzzz
CallerIDName: James
ConnectedLineNum: 
ConnectedLineName: 
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:467 do_state_change: Changing state for SIP/ws-Opensips - state 1 (Not in use)
[Jul 24 21:27:27] DEBUG[32050]: devicestate.c:442 devstate_event: device 'SIP/ws-Opensips' state '1'
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:13683 transmit_response_with_sdp: Setting framing from config on incoming call
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:13233 add_sdp: ** Our capability: (ulaw|opus) Video flag: True Text flag: True
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:13234 add_sdp: ** Our prefcodec: (nothing) 
Audio is at 15922
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: sip/sdp_crypto.c:310 sdp_crypto_offer: Crypto line: a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:zGmhE6XEnDiLyYAI2izYs7DLF4PDc073hn4fGYfc
[Jul 24 21:27:27] 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.
Adding codec 100030 (opus) to SDP
Adding codec 100003 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:13371 add_sdp: -- Done with adding codecs to SDP
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: 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:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:12682 add_ice_to_sdp: Incremented candidate port for the second srflx component-id (rtcp) by 1 and set to 15923
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: 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=z9hG4bK1d77.f2a8238.0;received=54.236.X.X;rport=5060
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK51b98943edcae23dac6029bd2ab60bd8cf04afef;rport=5060
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK6794704
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=pig78qlha2
To: <sip:+1971238xxxx@54.236.X.X>;tag=as2422d6b0
Call-ID: pfktr656uakq5enj6870
CSeq: 6449 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: 844

v=0
o=root 1934766056 1934766057 IN IP4 54.241.X.X
s=Asterisk PBX 11.5.0
c=IN IP4 54.241.X.X
t=0 0
m=audio 15922 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:7fe4c79066595956769acf425d81e1b3
a=ice-pwd:35d2695a277250485eff06c05d63c831
a=candidate:Habc87c8 1 UDP 2130706431 10.188.x.x 15922 typ host
a=candidate:S36f165cd 1 UDP 1694498815 54.241.X.X 15922 typ srflx
a=candidate:Habc87c8 2 UDP 2130706430 10.188.x.x 15923 typ host
a=candidate:S36f165cd 2 UDP 1694498814 54.241.X.X 15923 typ srflx
a=sendrecv
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:zGmhE6XEnDiLyYAI2izYs7DLF4PDc073hn4fGYfc

<------------>
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404340
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: 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:27:27] DEBUG[31074][C-000001b6]: features.c:4419 ast_bridge_call: bridge answer set, chan answer set
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: features.c:4240 clear_dialed_interfaces: Removing dialed interfaces datastore on SIP/BANDWIDTH-00000122 since we're bridging
[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: SIP/BANDWIDTH-00000122
Uniqueid: 1374701221.308
AccountCode: 
OldAccountCode: 

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: Bridge
Privilege: call,all
Bridgestate: Link
Bridgetype: core
Channel1: SIP/ws-Opensips-00000121
Channel2: SIP/BANDWIDTH-00000122
Uniqueid1: 1374701220.307
Uniqueid2: 1374701221.308
CallerID1: +1866707zzzz
CallerID2: 1971238xxxx

[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:27:27] DEBUG[31074][C-000001b6]: res_rtp_asterisk.c:2109 ast_rtp_update_source: Setting the marker bit due to a source update
[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000122
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: BRIDGEPVTCALLID
Value: 488209b33b5a887454a73e3413e29cd5@54.241.X.X:5060
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000122
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000121
Uniqueid: 1374701221.308

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000122
Variable: BRIDGEPVTCALLID
Value: pfktr656uakq5enj6870
Uniqueid: 1374701221.308

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: BRIDGEPEER
Value: SIP/BANDWIDTH-00000122
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/ws-Opensips-00000121
Variable: BRIDGEPVTCALLID
Value: 488209b33b5a887454a73e3413e29cd5@54.241.X.X:5060
Uniqueid: 1374701220.307

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000122
Variable: BRIDGEPEER
Value: SIP/ws-Opensips-00000121
Uniqueid: 1374701221.308

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/BANDWIDTH-00000122
Variable: BRIDGEPVTCALLID
Value: pfktr656uakq5enj6870
Uniqueid: 1374701221.308

[Jul 24 21:27:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701247.0312348672
SentRTP: 0
SentPackets: 1215
SentOctets: 160843
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18111.0760 (sec)

ip-10-188-135-200*CLI> 
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:4118 retrans_pkt: SIP TIMER: Rescheduling retransmission #404340 (1) SIP/2.0 - 1
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:4138 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #404340)) 
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=z9hG4bK1d77.f2a8238.0;received=54.236.X.X;rport=5060
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK51b98943edcae23dac6029bd2ab60bd8cf04afef;rport=5060
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK6794704
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=pig78qlha2
To: <sip:+1971238xxxx@54.236.X.X>;tag=as2422d6b0
Call-ID: pfktr656uakq5enj6870
CSeq: 6449 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: 844

v=0
o=root 1934766056 1934766057 IN IP4 54.241.X.X
s=Asterisk PBX 11.5.0
c=IN IP4 54.241.X.X
t=0 0
m=audio 15922 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:7fe4c79066595956769acf425d81e1b3
a=ice-pwd:35d2695a277250485eff06c05d63c831
a=candidate:Habc87c8 1 UDP 2130706431 10.188.x.x 15922 typ host
a=candidate:S36f165cd 1 UDP 1694498815 54.241.X.X 15922 typ srflx
a=candidate:Habc87c8 2 UDP 2130706430 10.188.x.x 15923 typ host
a=candidate:S36f165cd 2 UDP 1694498814 54.241.X.X 15923 typ srflx
a=sendrecv
a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:zGmhE6XEnDiLyYAI2izYs7DLF4PDc073hn4fGYfc

---
[Jul 24 21:27:27] 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
ip-10-188-135-200*CLI> 

<--- 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=z9hG4bK1d77.f2a8238.2
Via: SIP/2.0/UDP 10.96.Y.Y:5060;received=50.17.206.253;branch=z9hG4bK7d4da9812a86dd936f82457fe6460363cd4b9477
Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK122001
Max-Forwards:  9
To: <sip:+1971238xxxx@54.236.X.X>;tag=as2422d6b0
From: "James" <sip:1111@54.236.X.X>;tag=pig78qlha2
Call-ID: pfktr656uakq5enj6870
CSeq: 6449 ACK
Supported: path, outbound, gruu
User-Agent: JsSIP 0.3.0
Content-Length: 0

<------------->
[Jul 24 21:27:27] 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:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.236.Z.Z:5060;branch=z9hG4bK1d77.f2a8238.2
[Jul 24 21:27:27] 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=z9hG4bK7d4da9812a86dd936f82457fe6460363cd4b9477
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 57]: Via: SIP/2.0/WS ulqnj3q8u116.invalid;branch=z9hG4bK122001
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 16]: Max-Forwards:  9
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 51]: To: <sip:+1971238xxxx@54.236.X.X>;tag=as2422d6b0
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 54]: From: "James" <sip:1111@54.236.X.X>;tag=pig78qlha2
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 29]: Call-ID: pfktr656uakq5enj6870
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 14]: CSeq: 6449 ACK
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 31]: Supported: path, outbound, gruu
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 23]: User-Agent: JsSIP 0.3.0
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 17]: Content-Length: 0
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 12 [  0]: 
--- (12 headers 0 lines) ---
[Jul 24 21:27:27] DEBUG[32062][C-000001b6]: chan_sip.c:28176 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Jul 24 21:27:27] DEBUG[32062][C-000001b6]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404340
[Jul 24 21:27:27] DEBUG[32062][C-000001b6]: chan_sip.c:4566 __sip_ack: Stopping retransmission on 'pfktr656uakq5enj6870' of Response 6449: Match Found
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 3e93ae0a617c7b8f0ff3f84a56d0e8cf@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:27:27] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.16.z.z', our source address is '10.188.x.x'.
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.16.z.z:5060 is not local, substituting externaddr
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '3e93ae0a617c7b8f0ff3f84a56d0e8cf@10.188.x.x:5060' to '056b97095f7018543fdb97b21f71290a@54.241.X.X:5060'
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 056b97095f7018543fdb97b21f71290a@54.241.X.X:5060
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK3b54b7da;rport
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as1acef6af
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 056b97095f7018543fdb97b21f71290a@54.241.X.X:5060
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:27:27 GMT
[Jul 24 21:27:27] 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:27:27] 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=z9hG4bK3b54b7da;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as1acef6af
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 056b97095f7018543fdb97b21f71290a@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:27:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404341
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 67.16.z.z:5060
ip-10-188-135-200*CLI> 
ip-10-188-135-200*CLI> 
ip-10-188-135-200*CLI> 
[Jul 24 21:27:27] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 056b97095f7018543fdb97b21f71290a@54.241.X.X:5060
Really destroying SIP dialog '056b97095f7018543fdb97b21f71290a@54.241.X.X:5060' Method: OPTIONS
ip-10-188-135-200*CLI> 
ip-10-188-135-200*CLI> kjhgfdbjfgkdjbgdf
No such command 'kjhgfdbjfgkdjbgdf' (type 'core show help kjhgfdbjfgkdjbgdf' for other possible commands)
ip-10-188-135-200*CLI> hgfdhglfdk;hgfd
No such command 'hgfdhglfdk;hgfd' (type 'core show help hgfdhglfdk;hgfd' for other possible commands)
ip-10-188-135-200*CLI> hgfdklhgfd;h
No such command 'hgfdklhgfd;h' (type 'core show help hgfdklhgfd;h' for other possible commands)
[Jul 24 21:27:32] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701252.0311701504
SentRTP: 240000
SentPackets: 1461
SentOctets: 193389
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18116.0760 (sec)

[Jul 24 21:27:37] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701257.0312983552
SentRTP: 480000
SentPackets: 1704
SentOctets: 225491
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18121.0760 (sec)

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

---
[Jul 24 21:27:37] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404344
[Jul 24 21:27:37] 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:27:38] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 27cf3bae2391e43b457473d345f9e6cc@54.241.X.X:5060
Really destroying SIP dialog '27cf3bae2391e43b457473d345f9e6cc@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:27:42] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701262.0311934976
SentRTP: 720000
SentPackets: 1947
SentOctets: 257575
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18126.0760 (sec)

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

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

<--- SIP read from UDP:159.63.x.x:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK774cee15;rport=5060
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as2fa84a97
To: <sip:159.63.x.x>;tag=SD6ka8699-
Call-ID: 496238ef47d59f007fd799f562b0a707@54.241.X.X:5060
CSeq: 102 OPTIONS
Contact: <sip:ANONYMOUS@159.63.x.x:5060>
Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE,PUBLISH
Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
Supported: timer,replaces
Content-Length: 0

<------------->
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 70]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK774cee15;rport=5060
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as2fa84a97
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 38]: To: <sip:159.63.x.x>;tag=SD6ka8699-
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 61]: Call-ID: 496238ef47d59f007fd799f562b0a707@54.241.X.X:5060
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 43]: Contact: <sip:ANONYMOUS@159.63.x.x:5060>
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [102]: Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE,PUBLISH
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [101]: Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 25]: Supported: timer,replaces
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 10 [ 17]: Content-Length: 0
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [  0]: 
--- (11 headers 0 lines) ---
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404347
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '496238ef47d59f007fd799f562b0a707@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:27:43] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 496238ef47d59f007fd799f562b0a707@54.241.X.X:5060
Really destroying SIP dialog '496238ef47d59f007fd799f562b0a707@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 4192bf677711716045f0a06e285ca7d4@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:27:45] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '67.231.X.X', our source address is '10.188.x.x'.
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 67.231.X.X:5060 is not local, substituting externaddr
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '4192bf677711716045f0a06e285ca7d4@10.188.x.x:5060' to '1d4706930c1caad1047a75895c10713b@54.241.X.X:5060'
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 32]: OPTIONS sip:67.231.X.X SIP/2.0
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK78c4a83c;rport
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as17de06fd
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 22]: To: <sip:67.231.X.X>
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:27:45 GMT
[Jul 24 21:27:45] 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:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 67.231.X.X:5060:
OPTIONS sip:67.231.X.X SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK78c4a83c;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as17de06fd
To: <sip:67.231.X.X>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:27:45 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

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

<--- SIP read from UDP:67.231.X.X:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK78c4a83c;rport=5060
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as17de06fd
To: <sip:67.231.X.X>;tag=a31590ed27d48545292c590d77c85d1d.42f3
Call-ID: 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
CSeq: 102 OPTIONS
Server: Bandwidth.com CLEC
Content-Length: 0

<------------->
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 70]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK78c4a83c;rport=5060
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as17de06fd
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 64]: To: <sip:67.231.X.X>;tag=a31590ed27d48545292c590d77c85d1d.42f3
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 61]: Call-ID: 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 26]: Server: Bandwidth.com CLEC
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: Content-Length: 0
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [  0]: 
--- (8 headers 0 lines) ---
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404350
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '1d4706930c1caad1047a75895c10713b@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:27:45] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 1d4706930c1caad1047a75895c10713b@54.241.X.X:5060
Really destroying SIP dialog '1d4706930c1caad1047a75895c10713b@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 62e6f9b066d08d7f30a2c976568ea064@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:27:46] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '54.236.Z.Z', our source address is '10.188.x.x'.
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 54.236.Z.Z:5060 is not local, substituting externaddr
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '62e6f9b066d08d7f30a2c976568ea064@10.188.x.x:5060' to '7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060'
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 34]: OPTIONS sip:54.236.Z.Z SIP/2.0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK1ac7a134;rport
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as20dcb05c
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 24]: To: <sip:54.236.Z.Z>
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:27:46 GMT
[Jul 24 21:27:46] 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:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 54.236.Z.Z:5060:
OPTIONS sip:54.236.Z.Z SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK1ac7a134;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as20dcb05c
To: <sip:54.236.Z.Z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:27:46 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404353
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:3874 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 54.236.Z.Z:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 11a8d8bf01fe5247649db15216cfdeca@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:27:46] DEBUG[32062]: acl.c:979 ast_ouraddrfor: For destination '54.236.X.X', our source address is '10.188.x.x'.
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:3998 ast_sip_ouraddrfor: Target address 54.236.X.X:5060 is not local, substituting externaddr
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '11a8d8bf01fe5247649db15216cfdeca@10.188.x.x:5060' to '590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060'
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:54.236.X.X SIP/2.0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK2872d850;rport
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as0a9373a1
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:54.236.X.X>
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:27:46 GMT
[Jul 24 21:27:46] 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:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 54.236.X.X:5060:
OPTIONS sip:54.236.X.X SIP/2.0
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK2872d850;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as0a9373a1
To: <sip:54.236.X.X>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:27:46 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

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

<--- SIP read from UDP:54.236.Z.Z:5060 --->
SIP/2.0 200 ok
Via: SIP/2.0/UDP 54.241.X.X:5060;received=54.241.X.X;branch=z9hG4bK1ac7a134;rport=5060
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as20dcb05c
To: <sip:54.236.Z.Z>;tag=6a471b8c01049a5fad1c4eaaf6d3132b.b86b
Call-ID: 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
CSeq: 102 OPTIONS
Server: OpenSIPS (1.9.0-notls (x86_64/linux))
Content-Length: 0

<------------->
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 ok
[Jul 24 21:27:46] 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=z9hG4bK1ac7a134;rport=5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as20dcb05c
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 66]: To: <sip:54.236.Z.Z>;tag=6a471b8c01049a5fad1c4eaaf6d3132b.b86b
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 61]: Call-ID: 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 45]: Server: OpenSIPS (1.9.0-notls (x86_64/linux))
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: Content-Length: 0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [  0]: 
--- (8 headers 0 lines) ---
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404353
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060
Really destroying SIP dialog '7ec7974a71308ef92d5339d64a427268@54.241.X.X:5060' Method: OPTIONS

<--- SIP read from UDP:54.236.X.X:5060 --->
SIP/2.0 200 ok
Via: SIP/2.0/UDP 54.241.X.X:5060;received=54.241.X.X;branch=z9hG4bK2872d850;rport=5060
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as0a9373a1
To: <sip:54.236.X.X>;tag=6a471b8c01049a5fad1c4eaaf6d3132b.9899
Call-ID: 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
CSeq: 102 OPTIONS
Server: OpenSIPS (1.9.0-notls (x86_64/linux))
Content-Length: 0

<------------->
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 ok
[Jul 24 21:27:46] 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=z9hG4bK2872d850;rport=5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as0a9373a1
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 65]: To: <sip:54.236.X.X>;tag=6a471b8c01049a5fad1c4eaaf6d3132b.9899
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 61]: Call-ID: 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 45]: Server: OpenSIPS (1.9.0-notls (x86_64/linux))
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: Content-Length: 0
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [  0]: 
--- (8 headers 0 lines) ---
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404355
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:27:46] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060
Really destroying SIP dialog '590fdb6a0e9d309565cf0f276686e19a@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:27:47] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701267.0311189504
SentRTP: 960000
SentPackets: 2190
SentOctets: 289654
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18131.0750 (sec)

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

---
[Jul 24 21:27:48] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404359
[Jul 24 21:27:48] 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:27:49] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 38ee4429118b241e3d6a4ff23fb01cbb@54.241.X.X:5060
Really destroying SIP dialog '38ee4429118b241e3d6a4ff23fb01cbb@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:27:52] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701272.0310091776
SentRTP: 1200000
SentPackets: 2435
SentOctets: 322000
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18136.0750 (sec)

[Jul 24 21:27:57] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701277.0311177216
SentRTP: 1439040
SentPackets: 2681
SentOctets: 354475
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18141.0750 (sec)

[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 5058b0e63a8d8efe27cf908f5d1fef69@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:27: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:27: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:27:59] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '5058b0e63a8d8efe27cf908f5d1fef69@10.188.x.x:5060' to '54df91c67e43929956fe941d324c9328@54.241.X.X:5060'
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 54df91c67e43929956fe941d324c9328@54.241.X.X:5060
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK438c10c5;rport
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as73b86b44
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 54df91c67e43929956fe941d324c9328@54.241.X.X:5060
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:27:59 GMT
[Jul 24 21:27: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:27: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=z9hG4bK438c10c5;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as73b86b44
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 54df91c67e43929956fe941d324c9328@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:27:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:27:59] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404362
[Jul 24 21:27: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:27:59] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 54df91c67e43929956fe941d324c9328@54.241.X.X:5060
Really destroying SIP dialog '54df91c67e43929956fe941d324c9328@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:28:02] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701282.0310374400
SentRTP: 1680000
SentPackets: 2923
SentOctets: 386425
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18146.0750 (sec)

[Jul 24 21:28:07] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701287.0311726080
SentRTP: 1920000
SentPackets: 3166
SentOctets: 418517
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18151.0760 (sec)

[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 452a14eb2abbc3702d4f90be7e2af245@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:28: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:28: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:28:09] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '452a14eb2abbc3702d4f90be7e2af245@10.188.x.x:5060' to '490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060'
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK58df8ed3;rport
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as1ebed3ca
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:28:09 GMT
[Jul 24 21:28: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:28: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=z9hG4bK58df8ed3;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as1ebed3ca
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:28:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:28:09] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404365
[Jul 24 21:28: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:28:10] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060
Really destroying SIP dialog '490bea1279f5a9cf4ef6796a6018c34a@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:28:12] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701292.0312045568
SentRTP: 2160000
SentPackets: 3411
SentOctets: 450870
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18156.0760 (sec)

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

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

<--- SIP read from UDP:202.71.y.y:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK72e32d88;rport
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as67ab893d
Call-ID: 375b9d595c78fa0f7d3f4d4c059a40d1@54.241.X.X:5060
CSeq: 102 OPTIONS
To: <sip:202.71.y.y>;tag=abcdefg
Accept: application/sdp
Record-Route: <sip:nexge@202.71.y.y:5060>
Content-Length: 0

<------------->
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK72e32d88;rport
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as67ab893d
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: Call-ID: 375b9d595c78fa0f7d3f4d4c059a40d1@54.241.X.X:5060
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 35]: To: <sip:202.71.y.y>;tag=abcdefg
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 23]: Accept: application/sdp
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 44]: Record-Route: <sip:nexge@202.71.y.y:5060>
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 17]: Content-Length: 0
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [  0]: 
--- (9 headers 0 lines) ---
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:4533 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #404368
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:4566 __sip_ack: Stopping retransmission on '375b9d595c78fa0f7d3f4d4c059a40d1@54.241.X.X:5060' of Request 102: Match Found
[Jul 24 21:28:14] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 375b9d595c78fa0f7d3f4d4c059a40d1@54.241.X.X:5060
Really destroying SIP dialog '375b9d595c78fa0f7d3f4d4c059a40d1@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:28:17] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701297.0310734848
SentRTP: 2400000
SentPackets: 3656
SentOctets: 483220
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18161.0750 (sec)

[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:8781 sip_alloc: Allocating new SIP dialog for 4d5e2d1e7ee514f73614e750293ca746@10.188.x.x:5060 - OPTIONS (No RTP)
[Jul 24 21:28: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:28: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:28:20] DEBUG[32062]: chan_sip.c:4031 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 54.241.X.X:5060
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:8576 change_callid_pvt: SIP call-id changed from '4d5e2d1e7ee514f73614e750293ca746@10.188.x.x:5060' to '09674e551eba137b26e0aef1674afe81@54.241.X.X:5060'
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:3517 initialize_initreq: Initializing initreq for method OPTIONS - callid 09674e551eba137b26e0aef1674afe81@54.241.X.X:5060
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  0 [ 33]: OPTIONS sip:67.16.z.z SIP/2.0
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  1 [ 65]: Via: SIP/2.0/UDP 54.241.X.X:5060;branch=z9hG4bK388128dd;rport
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  3 [ 61]: From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as327f2c25
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  4 [ 23]: To: <sip:67.16.z.z>
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  5 [ 43]: Contact: <sip:asterisk@54.241.X.X:5060>
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  6 [ 61]: Call-ID: 09674e551eba137b26e0aef1674afe81@54.241.X.X:5060
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  8 [ 31]: User-Agent: Asterisk PBX 11.5.0
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:9628 parse_request:  Header  9 [ 35]: Date: Wed, 24 Jul 2013 21:28:20 GMT
[Jul 24 21:28: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:28: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=z9hG4bK388128dd;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@54.241.X.X>;tag=as327f2c25
To: <sip:67.16.z.z>
Contact: <sip:asterisk@54.241.X.X:5060>
Call-ID: 09674e551eba137b26e0aef1674afe81@54.241.X.X:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 11.5.0
Date: Wed, 24 Jul 2013 21:28:20 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

---
[Jul 24 21:28:20] DEBUG[32062]: chan_sip.c:4334 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #404371
[Jul 24 21:28: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:28:20] DEBUG[32062]: chan_sip.c:6827 sip_destroy: Destroying SIP dialog 09674e551eba137b26e0aef1674afe81@54.241.X.X:5060
Really destroying SIP dialog '09674e551eba137b26e0aef1674afe81@54.241.X.X:5060' Method: OPTIONS
[Jul 24 21:28:22] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701302.0310337536
SentRTP: 2640000
SentPackets: 3899
SentOctets: 515306
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18166.0750 (sec)

[Jul 24 21:28:27] DEBUG[32056]: manager.c:4787 match_filter: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 50.43.Y.Y:44867
OurSSRC: 680236968
SentNTP: 1374701307.0311635968
SentRTP: 2880000
SentPackets: 4143
SentOctets: 547526
ReportBlock:
FractionLost: 0
CumulativeLoss: 1
IAJitter: 0.0000
TheirLastSR: 0
DLSR: 18171.0760 (sec)

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

---