
<--- SIP read from UDP:192.168.17.4:5060 --->
INVITE sip:105@192.168.17.1 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-1f7c9442
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 101 INVITE
Max-Forwards: 70
Contact: Line 1 <sip:101@192.168.17.4:5060>
Expires: 240
User-Agent: Linksys/PAP2T-5.1.6(LS)
Content-Length: 442
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura, replaces
Content-Type: application/sdp

v=0
o=- 616807 616807 IN IP4 192.168.17.4
s=-
c=IN IP4 192.168.17.4
t=0 0
m=audio 16384 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
<------------->
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 35]: INVITE sip:105@192.168.17.1 SIP/2.0
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 58]: Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-1f7c9442
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 57]: From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 26]: To: <sip:105@192.168.17.1>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 39]: Call-ID: b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 101 INVITE
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 16]: Max-Forwards: 70
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 43]: Contact: Line 1 <sip:101@192.168.17.4:5060>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 12]: Expires: 240
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 19]: Content-Length: 442
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 11 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 12 [ 29]: Supported: x-sipura, replaces
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 13 [ 29]: Content-Type: application/sdp
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 14 [  0]: 
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  0 [  3]: v=0
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  1 [ 37]: o=- 616807 616807 IN IP4 192.168.17.4
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  2 [  3]: s=-
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  3 [ 21]: c=IN IP4 192.168.17.4
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  4 [  5]: t=0 0
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  5 [ 49]: m=audio 16384 RTP/AVP 0 2 4 8 18 96 97 98 100 101
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  6 [ 20]: a=rtpmap:0 PCMU/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  7 [ 23]: a=rtpmap:2 G726-32/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  8 [ 20]: a=rtpmap:4 G723/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  9 [ 20]: a=rtpmap:8 PCMA/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 10 [ 22]: a=rtpmap:18 G729a/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 11 [ 24]: a=rtpmap:96 G726-40/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 12 [ 24]: a=rtpmap:97 G726-24/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 13 [ 24]: a=rtpmap:98 G726-16/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 14 [ 21]: a=rtpmap:100 NSE/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 15 [ 18]: a=fmtp:100 192-193
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 16 [ 33]: a=rtpmap:101 telephone-event/8000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 17 [ 15]: a=fmtp:101 0-15
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:    Body 18 [ 10]: a=ptime:20
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8558 parse_request:    Body 19 [ 10]: a=sendrecv
--- (14 headers 20 lines) ---
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: b197e019-b79a12a1@192.168.17.4 (Checking From) --From tag 105641b97c61d81o0 --To-tag   
[Sep 23 12:02:05] DEBUG[840]: acl.c:736 ast_ouraddrfor: For destination '192.168.17.4', our source address is '192.168.17.1'.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7795 sip_alloc: Allocating new SIP dialog for b197e019-b79a12a1@192.168.17.4 - INVITE (No RTP)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:25254 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[Sep 23 12:02:05] DEBUG[840]: sip/reqresp_parser.c:1550 parse_sip_options: Begin: parsing SIP "Supported: x-sipura, replaces"
[Sep 23 12:02:05] DEBUG[840]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -x-sipura-
[Sep 23 12:02:05] DEBUG[840]: sip/reqresp_parser.c:1600 parse_sip_options: Found private SIP option, not supported: x-sipura
[Sep 23 12:02:05] DEBUG[840]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -replaces-
[Sep 23 12:02:05] DEBUG[840]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: replaces
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.4:5060' into...
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.4' and port '5060'.
Sending to 192.168.17.4:5060 (NAT)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:22643 handle_request_invite: Initializing initreq for method INVITE - callid b197e019-b79a12a1@192.168.17.4
Using INVITE request as basis request - b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.1' into...
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.1' and port ''.
Found peer '101' for '101' from 192.168.17.4:5060
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:350 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x8895ba8'
[Sep 23 12:02:05] DEBUG[840]: res_rtp_asterisk.c:556 ast_rtp_new: Allocated port 16592 for RTP instance '0x8895ba8'
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:359 ast_rtp_instance_new: RTP instance '0x8895ba8' is setup and ready to go
[Sep 23 12:02:05] DEBUG[840]: res_rtp_asterisk.c:2523 ast_rtp_prop_set: Setup RTCP on RTP instance '0x8895ba8'
  == Using SIP RTP CoS mark 5
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:5093 do_setnat: Setting NAT on RTP to On
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP o=- 616807 616807 IN IP4 192.168.17.4... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP s=-... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.4' into...
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.4' and port ''.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP c=IN IP4 192.168.17.4... OK.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
Found RTP audio format 0
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x41503e70
Found RTP audio format 2
Found RTP audio format 4
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 4 based on m type on 0x41503e70
Found RTP audio format 8
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x41503e70
Found RTP audio format 18
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 18 based on m type on 0x41503e70
Found RTP audio format 96
Found RTP audio format 97
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 97 based on m type on 0x41503e70
Found RTP audio format 98
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 98 based on m type on 0x41503e70
Found RTP audio format 100
Found RTP audio format 101
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x41503e70
Found audio description format PCMU for ID 0
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
Found audio description format G726-32 for ID 2
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK.
Found audio description format G723 for ID 4
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK.
Found audio description format PCMA for ID 8
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
Found audio description format G729a for ID 18
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 G729a/8000... OK.
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:608 ast_rtp_codecs_payloads_unset: Unsetting payload 96 on 0x41503e70
Found unknown media description format G726-40 for ID 96
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:96 G726-40/8000... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:608 ast_rtp_codecs_payloads_unset: Unsetting payload 97 on 0x41503e70
Found unknown media description format G726-24 for ID 97
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:97 G726-24/8000... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:608 ast_rtp_codecs_payloads_unset: Unsetting payload 98 on 0x41503e70
Found unknown media description format G726-16 for ID 98
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:98 G726-16/8000... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:608 ast_rtp_codecs_payloads_unset: Unsetting payload 100 on 0x41503e70
Found unknown media description format NSE for ID 100
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:100 NSE/8000... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=fmtp:100 192-193... UNSUPPORTED OR FAILED.
Found audio description format telephone-event for ID 101
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK.
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0x41503e70
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 2 on 0x41503e70
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 4 on 0x41503e70
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0x41503e70
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 18 on 0x41503e70
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x41503e70
Capabilities: us - 0x4 (ulaw), peer - audio=0x90d (g723|ulaw|alaw|g726|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[Sep 23 12:02:05] DEBUG[840]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x8895ba8'
Peer audio RTP is at port 192.168.17.4:16384
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 2 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 4 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 18 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x41503e70 to 0x8895d54
[Sep 23 12:02:05] DEBUG[840]: res_rtp_asterisk.c:2489 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x8895ba8'
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:9424 process_sdp: We're settling with these formats: 0x4 (ulaw)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:22780 handle_request_invite: Checking SIP call limits for device 101
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:5905 update_call_counter: Updating call counter for incoming call
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:6010 update_call_counter: Call from peer '101' is 1 out of 10
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.1' into...
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.1' and port ''.
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.1' into...
[Sep 23 12:02:05] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.1' and port ''.
Looking for 105 in DefaultDialPlan (domain 192.168.17.1)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7091 sip_new: *** Our native formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7092 sip_new: *** Joint capabilities are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7093 sip_new: *** Our capabilities are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7094 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:7124 sip_new: This channel will not be able to handle video.
[Sep 23 12:02:05] DEBUG[840]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Sep 23 12:02:05] DEBUG[840]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:14336 build_route: build_route: Contact hop: Line 1 <sip:101@192.168.17.4:5060>
list_route: hop: <sip:101@192.168.17.4:5060>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:23081 handle_request_invite: SIP/101-0000001e: New call is still down.... Trying... 

<--- Transmitting (NAT) to 192.168.17.4:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-1f7c9442;received=192.168.17.4;rport=5060
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 101 INVITE
Server: Asterisk PBX 1.8.15.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:105@192.168.17.1:5060>
Content-Length: 0


<------------>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.17.4:5060
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 101
[Sep 23 12:02:05] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 101
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/101 - state 2 (In use)
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/101' state '2'
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 101
[Sep 23 12:02:05] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 101
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/101 - state 2 (In use)
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/101' state '2'
[Sep 23 12:02:05] DEBUG[2889]: pbx.c:4247 pbx_extension_helper: Launching 'NoOp'
    -- Executing [105@DefaultDialPlan:1] NoOp("SIP/101-0000001e", "Test SLAtrunk") in new stack
[Sep 23 12:02:05] DEBUG[2889]: pbx.c:4247 pbx_extension_helper: Launching 'SLATrunk'
    -- Executing [105@DefaultDialPlan:2] SLATrunk("SIP/101-0000001e", "SLAtrunk1") in new stack
[Sep 23 12:02:05] DEBUG[2889]: devicestate.c:440 devstate_event: device 'SLA:SLAphone111_SLAtrunk1' state '6'
[Sep 23 12:02:05] DEBUG[2889]: devicestate.c:440 devstate_event: device 'SLA:SLAphone112_SLAtrunk1' state '6'
[Sep 23 12:02:05] DEBUG[2889]: chan_dahdi.c:13646 dahdi_request: Using channel -2
[Sep 23 12:02:05] DEBUG[2889]: channel.c:5175 set_format: Set channel DAHDI/pseudo-815145799 to read format slin
[Sep 23 12:02:05] DEBUG[2889]: channel.c:5175 set_format: Set channel DAHDI/pseudo-815145799 to write format slin
    -- Created MeetMe conference 1023 for conference 'SLA_SLAtrunk1'

<--- Transmitting (NAT) to 192.168.17.4:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-1f7c9442;received=192.168.17.4;rport=5060
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>;tag=as18959fef
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 101 INVITE
Server: Asterisk PBX 1.8.15.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:105@192.168.17.1:5060>
Content-Length: 0


<------------>
[Sep 23 12:02:05] DEBUG[2889]: chan_sip.c:3346 __sip_xmit: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.17.4:5060
[Sep 23 12:02:05] DEBUG[2889]: channel.c:4519 ast_indicate_data: Driver for channel 'SIP/101-0000001e' does not support indication 3, emulating it
[Sep 23 12:02:05] DEBUG[2889]: channel.c:5175 set_format: Set channel SIP/101-0000001e to write format slin
[Sep 23 12:02:05] DEBUG[2889]: channel.c:3516 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Sep 23 12:02:05] DEBUG[2889]: channel.c:4669 ast_prod: Prodding channel 'SIP/101-0000001e'
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:1330 ast_rtp_write: Received frame with no data for RTP instance '0x8895ba8' so dropping frame
[Sep 23 12:02:05] DEBUG[2889]: devicestate.c:440 devstate_event: device 'meetme:SLA_SLAtrunk1' state '2'
[Sep 23 12:02:05] DEBUG[2889]: channel.c:5175 set_format: Set channel SIP/101-0000001e to read format slin
[Sep 23 12:02:05] DEBUG[2889]: app_meetme.c:2683 conf_run: Placed channel SIP/101-0000001e in DAHDI conf 1023
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:26659 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7795 sip_alloc: Allocating new SIP dialog for 0ff78f7547730c4f2880388f7b16b06d@192.168.17.1:5060 - INVITE (No RTP)
[Sep 23 12:02:05] DEBUG[844]: rtp_engine.c:350 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x88bc528'
[Sep 23 12:02:05] DEBUG[844]: res_rtp_asterisk.c:556 ast_rtp_new: Allocated port 16556 for RTP instance '0x88bc528'
[Sep 23 12:02:05] DEBUG[844]: rtp_engine.c:359 ast_rtp_instance_new: RTP instance '0x88bc528' is setup and ready to go
[Sep 23 12:02:05] DEBUG[844]: res_rtp_asterisk.c:2523 ast_rtp_prop_set: Setup RTCP on RTP instance '0x88bc528'
  == Using SIP RTP CoS mark 5
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5093 do_setnat: Setting NAT on RTP to On
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3146 obproxy_get: OBPROXY: Not applying OBproxy to this call
[Sep 23 12:02:05] DEBUG[844]: acl.c:736 ast_ouraddrfor: For destination '192.168.17.141', our source address is '192.168.17.1'.
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7091 sip_new: *** Our native formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7092 sip_new: *** Joint capabilities are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7093 sip_new: *** Our capabilities are 0x1104 (ulaw|g729|g722) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7094 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7096 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7124 sip_new: This channel will not be able to handle video.
[Sep 23 12:02:05] DEBUG[844]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Sep 23 12:02:05] DEBUG[844]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable MEETMEUNIQUEID.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPURI.
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5638 sip_call: Outgoing Call for 111
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:6010 update_call_counter: Call to peer '111' is 1 out of 10
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11413 add_sdp: ** Our capability: 0x1104 (ulaw|g729|g722) Video flag: False Text flag: False
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11414 add_sdp: ** Our prefcodec: 0x4 (ulaw) 
Audio is at 16556
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x1000 (g722) to SDP
Adding codec 0x100 (g729) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11523 add_sdp: -- Done with adding codecs to SDP
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11709 add_sdp: Done building SDP. Settling with this capability: 0x1104 (ulaw|g729|g722)
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3075 initialize_initreq: Initializing initreq for method INVITE - callid 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  0 [ 42]: INVITE sip:111@192.168.17.141:5060 SIP/2.0
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  1 [ 63]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  3 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  4 [ 33]: To: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  5 [ 36]: Contact: <sip:101@192.168.17.1:5060>
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  6 [ 59]: Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  7 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  8 [ 33]: User-Agent: Asterisk PBX 1.8.15.0
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  9 [ 35]: Date: Sun, 23 Sep 2012 16:02:05 GMT
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 11 [ 26]: Supported: replaces, timer
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 12 [ 29]: Content-Type: application/sdp
Reliably Transmitting (NAT) to 192.168.17.141:5060:
INVITE sip:111@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>
Contact: <sip:101@192.168.17.1:5060>
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.8.15.0
Date: Sun, 23 Sep 2012 16:02:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 308

v=0
o=root 2054647882 2054647882 IN IP4 192.168.17.1
s=Asterisk PBX 1.8.15.0
c=IN IP4 192.168.17.1
t=0 0
m=audio 16556 RTP/AVP 0 9 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #561
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3346 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.17.141:5060
    -- Called 111
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:26659 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7795 sip_alloc: Allocating new SIP dialog for 784f1e994fbd10b56fe872230be460f0@192.168.17.1:5060 - INVITE (No RTP)
[Sep 23 12:02:05] DEBUG[844]: rtp_engine.c:350 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x8907000'
[Sep 23 12:02:05] DEBUG[844]: res_rtp_asterisk.c:556 ast_rtp_new: Allocated port 16632 for RTP instance '0x8907000'
[Sep 23 12:02:05] DEBUG[844]: rtp_engine.c:359 ast_rtp_instance_new: RTP instance '0x8907000' is setup and ready to go
[Sep 23 12:02:05] DEBUG[844]: res_rtp_asterisk.c:2523 ast_rtp_prop_set: Setup RTCP on RTP instance '0x8907000'
  == Using SIP RTP CoS mark 5
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5093 do_setnat: Setting NAT on RTP to On
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3146 obproxy_get: OBPROXY: Not applying OBproxy to this call
[Sep 23 12:02:05] DEBUG[844]: acl.c:736 ast_ouraddrfor: For destination '192.168.17.141', our source address is '192.168.17.1'.
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7091 sip_new: *** Our native formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7092 sip_new: *** Joint capabilities are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7093 sip_new: *** Our capabilities are 0x1104 (ulaw|g729|g722) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7094 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7096 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) 
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:7124 sip_new: This channel will not be able to handle video.
[Sep 23 12:02:05] DEBUG[844]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Sep 23 12:02:05] DEBUG[844]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable MEETMEUNIQUEID.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
[Sep 23 12:02:05] DEBUG[844]: channel.c:6152 ast_channel_inherit_variables: Not copying variable SIPURI.
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5638 sip_call: Outgoing Call for 112
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:6010 update_call_counter: Call to peer '112' is 1 out of 10
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11413 add_sdp: ** Our capability: 0x1104 (ulaw|g729|g722) Video flag: False Text flag: False
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11414 add_sdp: ** Our prefcodec: 0x4 (ulaw) 
Audio is at 16632
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x1000 (g722) to SDP
Adding codec 0x100 (g729) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11523 add_sdp: -- Done with adding codecs to SDP
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:11709 add_sdp: Done building SDP. Settling with this capability: 0x1104 (ulaw|g729|g722)
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3075 initialize_initreq: Initializing initreq for method INVITE - callid 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  0 [ 42]: INVITE sip:112@192.168.17.141:5060 SIP/2.0
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  1 [ 63]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  3 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  4 [ 33]: To: <sip:112@192.168.17.141:5060>
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  5 [ 36]: Contact: <sip:101@192.168.17.1:5060>
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  6 [ 59]: Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  7 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  8 [ 33]: User-Agent: Asterisk PBX 1.8.15.0
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header  9 [ 35]: Date: Sun, 23 Sep 2012 16:02:05 GMT
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 11 [ 26]: Supported: replaces, timer
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:8521 parse_request:  Header 12 [ 29]: Content-Type: application/sdp
Reliably Transmitting (NAT) to 192.168.17.141:5060:
INVITE sip:112@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>
Contact: <sip:101@192.168.17.1:5060>
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.8.15.0
Date: Sun, 23 Sep 2012 16:02:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 306

v=0
o=root 686702612 686702612 IN IP4 192.168.17.1
s=Asterisk PBX 1.8.15.0
c=IN IP4 192.168.17.1
t=0 0
m=audio 16632 RTP/AVP 0 9 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #563
[Sep 23 12:02:05] DEBUG[844]: chan_sip.c:3346 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.17.141:5060
    -- Called 112
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for DAHDI - pseudo
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for DAHDI/pseudo - state 2 (In use)
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:440 devstate_event: device 'DAHDI/pseudo' state '2'
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:05] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 6 (Ringing)
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '6'
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 112
[Sep 23 12:02:05] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 112
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/112 - state 6 (Ringing)
[Sep 23 12:02:05] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/112' state '6'
[Sep 23 12:02:05] DEBUG[2889]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Sep 23 12:02:05] DEBUG[2889]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Sep 23 12:02:05] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone111_SLAtrunk1@DialPlanSLA' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone112_SLAtrunk1@DialPlanSLA' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone111_SLAtrunk1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone112_SLAtrunk1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'meetme:SLA_SLAtrunk1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[2889]: res_timing_timerfd.c:206 timerfd_timer_ack: Expected to acknowledge 1 ticks but got 2 instead
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:1359 ast_rtp_write: Ooh, format changed from unknown to ulaw
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:1390 ast_rtp_write: Created smoother: format: ulaw ms: 20 len: 160
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:1255 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x8895ba8'
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'DAHDI/pseudo' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/112' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:111@192.168.17.141:5060>
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 18]: SIP/2.0 100 Trying
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:111@192.168.17.141:5060>;tag=2618545111
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060 (Checking To) --From tag as0e4cf224 --To-tag 2618545111  
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:4064 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #561 - INVITE (got response)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:4071 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' Request 102: Found
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 100 to standard invite
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>;tag=3407546346
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:112@192.168.17.141:5060>
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 18]: SIP/2.0 100 Trying
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:112@192.168.17.141:5060>;tag=3407546346
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:112@192.168.17.141:5060>
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060 (Checking To) --From tag as0ddea8e3 --To-tag 3407546346  
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:4064 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #563 - INVITE (got response)
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:4071 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' Request 102: Found
[Sep 23 12:02:05] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 100 to standard invite
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:05] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:111@192.168.17.141:5060>
Allow-Events: message-summary, refer, ua-profile
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 19]: SIP/2.0 180 Ringing
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:111@192.168.17.141:5060>;tag=2618545111
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 48]: Allow-Events: message-summary, refer, ua-profile
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 17]: Content-Length: 0
--- (10 headers 0 lines) ---
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060 (Checking To) --From tag as0e4cf224 --To-tag 2618545111  
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:4071 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' Request 102: Found
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 180 to standard invite
[Sep 23 12:02:06] DEBUG[840]: chan_sip.c:14336 build_route: build_route: Contact hop: <sip:111@192.168.17.141:5060>
list_route: hop: <sip:111@192.168.17.141:5060>
    -- SIP/111-0000001f is ringing
[Sep 23 12:02:06] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:06] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:06] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 6 (Ringing)
[Sep 23 12:02:06] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '6'
[Sep 23 12:02:06] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:06] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:7795 sip_alloc: Allocating new SIP dialog for 1b56dd2b2bf209f95029dc491c43da2c@192.168.17.1:5060 - OPTIONS (No RTP)
[Sep 23 12:02:07] DEBUG[840]: acl.c:736 ast_ouraddrfor: For destination '192.168.17.141', our source address is '192.168.17.1'.
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.17.1:5060
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:3075 initialize_initreq: Initializing initreq for method OPTIONS - callid 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 43]: OPTIONS sip:111@192.168.17.141:5060 SIP/2.0
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 63]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK15036c8a;rport
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 59]: From: "asterisk" <sip:asterisk@192.168.17.1>;tag=as281210d2
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 33]: To: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 41]: Contact: <sip:asterisk@192.168.17.1:5060>
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 59]: Call-ID: 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 33]: User-Agent: Asterisk PBX 1.8.15.0
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 35]: Date: Sun, 23 Sep 2012 16:02:07 GMT
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 192.168.17.141:5060:
OPTIONS sip:111@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK15036c8a;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@192.168.17.1>;tag=as281210d2
To: <sip:111@192.168.17.141:5060>
Contact: <sip:asterisk@192.168.17.1:5060>
Call-ID: 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.15.0
Date: Sun, 23 Sep 2012 16:02:07 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


---
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #566
[Sep 23 12:02:07] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.17.141:5060
[Sep 23 12:02:07] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 486 Busy Here
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK15036c8a;rport=5060
From: "asterisk" <sip:asterisk@192.168.17.1>;tag=as281210d2
To: <sip:111@192.168.17.141:5060>
Call-ID: 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
CSeq: 102 OPTIONS
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 21]: SIP/2.0 486 Busy Here
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK15036c8a;rport=5060
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 59]: From: "asterisk" <sip:asterisk@192.168.17.1>;tag=as281210d2
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 33]: To: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 17]: Content-Length: 0
--- (8 headers 0 lines) ---
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060 (Checking To) --From tag as281210d2 --To-tag   
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:3997 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #566
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '40c343333d735a7a540e1237567b98f1@192.168.17.1:5060' of Request 102: Match Found
[Sep 23 12:02:08] DEBUG[840]: chan_sip.c:6053 sip_destroy: Destroying SIP dialog 40c343333d735a7a540e1237567b98f1@192.168.17.1:5060
Really destroying SIP dialog '40c343333d735a7a540e1237567b98f1@192.168.17.1:5060' Method: OPTIONS
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[828]: res_jabber.c:1401 aji_recv: XML parsing successful
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:08] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:09] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>;tag=3407546346
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:112@192.168.17.141:5060>
Allow-Events: message-summary, refer, ua-profile
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 19]: SIP/2.0 180 Ringing
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:112@192.168.17.141:5060>;tag=3407546346
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:112@192.168.17.141:5060>
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 48]: Allow-Events: message-summary, refer, ua-profile
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 17]: Content-Length: 0
--- (10 headers 0 lines) ---
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060 (Checking To) --From tag as0ddea8e3 --To-tag 3407546346  
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:4071 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' Request 102: Found
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 180 to standard invite
[Sep 23 12:02:10] DEBUG[840]: chan_sip.c:14336 build_route: build_route: Contact hop: <sip:112@192.168.17.141:5060>
list_route: hop: <sip:112@192.168.17.141:5060>
    -- SIP/112-00000020 is ringing
[Sep 23 12:02:10] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 112
[Sep 23 12:02:10] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 112
[Sep 23 12:02:10] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/112 - state 6 (Ringing)
[Sep 23 12:02:10] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/112' state '6'
[Sep 23 12:02:10] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/112' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:10] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:11] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:12] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:13] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:14] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:111@192.168.17.141:5060>
Supported: replaces
Allow-Events: message-summary, refer, ua-profile
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 211

v=0
o=111 5018 21 IN IP4 192.168.17.141
s=Mapping
c=IN IP4 192.168.17.141
t=0 0
m=audio 5018 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
a=ptime:20
<------------->
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4fe6927f;rport=5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:111@192.168.17.141:5060>;tag=2618545111
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 19]: Supported: replaces
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 48]: Allow-Events: message-summary, refer, ua-profile
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 72]: Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 29]: Content-Type: application/sdp
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 11 [ 19]: Content-Length: 211
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 12 [  0]: 
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  0 [  3]: v=0
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  1 [ 35]: o=111 5018 21 IN IP4 192.168.17.141
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  2 [  9]: s=Mapping
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  3 [ 23]: c=IN IP4 192.168.17.141
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  4 [  5]: t=0 0
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  5 [ 26]: m=audio 5018 RTP/AVP 0 101
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  6 [ 20]: a=rtpmap:0 PCMU/8000
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  7 [ 33]: a=rtpmap:101 telephone-event/8000
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  8 [ 15]: a=fmtp:101 0-16
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:    Body  9 [ 10]: a=sendrecv
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8558 parse_request:    Body 10 [ 10]: a=ptime:20
--- (12 headers 11 lines) ---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060 (Checking To) --From tag as0e4cf224 --To-tag 2618545111  
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3992 __sip_ack: Acked pending invite 102
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' of Request 102: Match Found
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 200 to standard invite
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP o=111 5018 21 IN IP4 192.168.17.141... UNSUPPORTED OR FAILED.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP s=Mapping... UNSUPPORTED OR FAILED.
[Sep 23 12:02:14] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.141' into...
[Sep 23 12:02:14] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.141' and port ''.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP c=IN IP4 192.168.17.141... OK.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8908 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
Found RTP audio format 0
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x41504490
Found RTP audio format 101
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x41504490
Found audio description format PCMU for ID 0
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
Found audio description format telephone-event for ID 101
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9179 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK.
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0x41504490
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x41504490
Capabilities: us - 0x1104 (ulaw|g729|g722), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[Sep 23 12:02:14] DEBUG[840]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x88bc528'
Peer audio RTP is at port 192.168.17.141:5018
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x41504490 to 0x88bc6d4
[Sep 23 12:02:14] DEBUG[840]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x41504490 to 0x88bc6d4
[Sep 23 12:02:14] DEBUG[840]: res_rtp_asterisk.c:2489 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x88bc528'
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9424 process_sdp: We're settling with these formats: 0x4 (ulaw)
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:9429 process_sdp: We have an owner, now see if we need to change this call
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:14336 build_route: build_route: Contact hop: <sip:111@192.168.17.141:5060>
list_route: hop: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:10397 reqprep: Strict routing enforced for session 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
set_destination: Parsing <sip:111@192.168.17.141:5060> for address/port to send to
[Sep 23 12:02:14] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.141:5060' into...
[Sep 23 12:02:14] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.141' and port '5060'.
set_destination: set destination to 192.168.17.141:5060
Transmitting (NAT) to 192.168.17.141:5060:
ACK sip:111@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4e54d7ca;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Contact: <sip:101@192.168.17.1:5060>
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.8.15.0
Content-Length: 0


---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'ACK sip:111' onto UDP socket destined for 192.168.17.141:5060
[Sep 23 12:02:14] DEBUG[2889]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
    -- SIP/111-0000001f answered
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 2 (In use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '2'
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 2 (In use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '2'
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:6492 sip_answer: SIP answering channel: SIP/101-0000001e
[Sep 23 12:02:14] DEBUG[844]: res_rtp_asterisk.c:828 ast_rtp_update_source: Setting the marker bit due to a source update
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:11814 transmit_response_with_sdp: Setting framing from config on incoming call
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:11413 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:11414 add_sdp: ** Our prefcodec: 0x0 (nothing) 
Audio is at 16592
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:11523 add_sdp: -- Done with adding codecs to SDP
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:11709 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw)

<--- Reliably Transmitting (NAT) to 192.168.17.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-1f7c9442;received=192.168.17.4;rport=5060
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>;tag=as18959fef
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 101 INVITE
Server: Asterisk PBX 1.8.15.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:105@192.168.17.1:5060>
Content-Type: application/sdp
Content-Length: 233

v=0
o=root 21202047 21202047 IN IP4 192.168.17.1
s=Asterisk PBX 1.8.15.0
c=IN IP4 192.168.17.1
t=0 0
m=audio 16592 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #569
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:3346 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.17.4:5060
[Sep 23 12:02:14] DEBUG[844]: channel.c:5175 set_format: Set channel SIP/101-0000001e to write format ulaw
[Sep 23 12:02:14] DEBUG[844]: channel.c:3516 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 23 12:02:14] DEBUG[844]: channel.c:3207 ast_waitfor_nandfds: Thread 1097309040 Blocking 'SIP/101-0000001e', already blocked by thread 1104067440 in procedure ast_waitfor_nandfds
[Sep 23 12:02:14] WARNING[2889]: channel.c:4938 ast_write: Codec mismatch on channel SIP/101-0000001e setting write format to slin from ulaw native formats 0x4 (ulaw)
[Sep 23 12:02:14] DEBUG[2889]: channel.c:5175 set_format: Set channel SIP/101-0000001e to write format slin
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 101
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 101
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/101 - state 2 (In use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/101' state '2'
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/101' changed to state '2' (In use) but we don't care because they're not a member of any queue.

<--- SIP read from UDP:192.168.17.4:5060 --->
ACK sip:105@192.168.17.1:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-405847e1
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>;tag=as18959fef
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 101 ACK
Max-Forwards: 70
Contact: Line 1 <sip:101@192.168.17.4:5060>
User-Agent: Linksys/PAP2T-5.1.6(LS)
Content-Length: 0

<------------->
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 37]: ACK sip:105@192.168.17.1:5060 SIP/2.0
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 58]: Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-405847e1
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 57]: From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 41]: To: <sip:105@192.168.17.1>;tag=as18959fef
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 39]: Call-ID: b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 13]: CSeq: 101 ACK
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 16]: Max-Forwards: 70
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 43]: Contact: Line 1 <sip:101@192.168.17.4:5060>
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS)
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 17]: Content-Length: 0
--- (10 headers 0 lines) ---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: b197e019-b79a12a1@192.168.17.4 (Checking From) --From tag 105641b97c61d81o0 --To-tag as18959fef  
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:25254 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3997 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #569
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on 'b197e019-b79a12a1@192.168.17.4' of Response 101: Match Found
[Sep 23 12:02:14] DEBUG[844]: channel.c:2974 __ast_answer: Didn't receive a media frame from SIP/101-0000001e within 500 ms of answering. Continuing anyway
[Sep 23 12:02:14] DEBUG[844]: devicestate.c:440 devstate_event: device 'SLA:SLAphone111_SLAtrunk1' state '2'
[Sep 23 12:02:14] DEBUG[844]: devicestate.c:440 devstate_event: device 'SLA:SLAphone112_SLAtrunk1' state '2'
[Sep 23 12:02:14] DEBUG[2901]: channel.c:5175 set_format: Set channel SIP/111-0000001f to write format slin
[Sep 23 12:02:14] DEBUG[2901]: channel.c:5175 set_format: Set channel SIP/111-0000001f to read format slin
[Sep 23 12:02:14] DEBUG[2901]: app_meetme.c:2683 conf_run: Placed channel SIP/111-0000001f in DAHDI conf 1023
[Sep 23 12:02:14] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone111_SLAtrunk1@DialPlanSLA' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone112_SLAtrunk1@DialPlanSLA' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone111_SLAtrunk1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone112_SLAtrunk1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[2901]: dsp.c:475 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Sep 23 12:02:14] DEBUG[2901]: dsp.c:475 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Sep 23 12:02:14] DEBUG[844]: channel.c:2844 ast_hangup: Hanging up channel 'SIP/112-00000020'
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:6287 sip_hangup: Hangup call SIP/112-00000020, SIP callid 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:6292 sip_hangup: update_call_counter(112) - decrement call limit counter on hangup
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:5976 update_call_counter: Call to peer '112' removed from call limit 10
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:6306 sip_hangup: Hanging up channel in state Ringing (not UP)
[Sep 23 12:02:14] DEBUG[844]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x8907000'
Scheduling destruction of SIP dialog '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' in 6400 ms (Method: INVITE)
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:4071 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' Request 102: Found
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:10397 reqprep: Strict routing enforced for session 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
Reliably Transmitting (NAT) to 192.168.17.141:5060:
CANCEL sip:112@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 CANCEL
User-Agent: Asterisk PBX 1.8.15.0
Content-Length: 0


---
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #572
[Sep 23 12:02:14] DEBUG[844]: chan_sip.c:3346 __sip_xmit: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.17.141:5060
Scheduling destruction of SIP dialog '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' in 6400 ms (Method: INVITE)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 112
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 112
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/112 - state 1 (Not in use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/112' state '1'
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 112
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 112
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/112 - state 1 (Not in use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/112' state '1'
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:14] DEBUG[2901]: res_rtp_asterisk.c:1359 ast_rtp_write: Ooh, format changed from unknown to ulaw
[Sep 23 12:02:14] DEBUG[2901]: res_rtp_asterisk.c:1390 ast_rtp_write: Created smoother: format: ulaw ms: 20 len: 160

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>;tag=3407546346
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 CANCEL
Contact: <sip:112@192.168.17.141:5060>
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:112@192.168.17.141:5060>;tag=3407546346
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 CANCEL
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:112@192.168.17.141:5060>
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060 (Checking To) --From tag as0ddea8e3 --To-tag 3407546346  
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3992 __sip_ack: Acked pending invite 102
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3997 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #572
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' of Request 102: Match Found

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>;tag=3407546346
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 INVITE
Contact: <sip:112@192.168.17.141:5060>
User-Agent: C610A IP/42.072.00.000.000
Content-Length: 0

<------------->
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 29]: SIP/2.0 487 Request Cancelled
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport=5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:112@192.168.17.141:5060>;tag=3407546346
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 16]: CSeq: 102 INVITE
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:112@192.168.17.141:5060>
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060 (Checking To) --From tag as0ddea8e3 --To-tag 3407546346  
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' of Request 102: Match Found
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:20102 handle_response_invite: SIP response 487 to standard invite
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:10397 reqprep: Strict routing enforced for session 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
Transmitting (NAT) to 192.168.17.141:5060:
ACK sip:112@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK4a3b2d56;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0ddea8e3
To: <sip:112@192.168.17.141:5060>;tag=3407546346
Contact: <sip:101@192.168.17.1:5060>
Call-ID: 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.8.15.0
Content-Length: 0


---
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'ACK sip:112' onto UDP socket destined for 192.168.17.141:5060
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:14] DEBUG[840]: chan_sip.c:5976 update_call_counter: Call to peer '112' removed from call limit 10
Scheduling destruction of SIP dialog '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' in 6400 ms (Method: INVITE)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 112
[Sep 23 12:02:14] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 112
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/112 - state 1 (Not in use)
[Sep 23 12:02:14] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/112' state '1'
[Sep 23 12:02:14] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/112' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:7795 sip_alloc: Allocating new SIP dialog for 2038a6545b933052239b5fe25672ee41@192.168.17.1:5060 - OPTIONS (No RTP)
[Sep 23 12:02:20] DEBUG[840]: acl.c:736 ast_ouraddrfor: For destination '64.2.142.187', our source address is '24.128.119.26'.
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3498 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 24.128.119.26:5060
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3075 initialize_initreq: Initializing initreq for method OPTIONS - callid 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 41]: OPTIONS sip:outbound.vitelity.net SIP/2.0
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 64]: Via: SIP/2.0/UDP 24.128.119.26:5060;branch=z9hG4bK5a36e4f0;rport
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 57]: From: "asterisk" <sip:dkerr@24.128.119.26>;tag=as53cfbf4f
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 31]: To: <sip:outbound.vitelity.net>
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 39]: Contact: <sip:dkerr@24.128.119.26:5060>
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 60]: Call-ID: 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 33]: User-Agent: Asterisk PBX 1.8.15.0
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 35]: Date: Sun, 23 Sep 2012 16:02:20 GMT
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 64.2.142.187:5060:
OPTIONS sip:outbound.vitelity.net SIP/2.0
Via: SIP/2.0/UDP 24.128.119.26:5060;branch=z9hG4bK5a36e4f0;rport
Max-Forwards: 70
From: "asterisk" <sip:dkerr@24.128.119.26>;tag=as53cfbf4f
To: <sip:outbound.vitelity.net>
Contact: <sip:dkerr@24.128.119.26:5060>
Call-ID: 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.15.0
Date: Sun, 23 Sep 2012 16:02:20 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


---
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #575
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 64.2.142.187:5060

<--- SIP read from UDP:64.2.142.187:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 24.128.119.26:5060;branch=z9hG4bK5a36e4f0;received=24.128.119.26;rport=5060
From: "asterisk" <sip:dkerr@24.128.119.26>;tag=as53cfbf4f
To: <sip:outbound.vitelity.net>;tag=as3089cdb8
Call-ID: 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
CSeq: 102 OPTIONS
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Accept: application/sdp
Content-Length: 0

<------------->
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 21]: SIP/2.0 404 Not Found
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 92]: Via: SIP/2.0/UDP 24.128.119.26:5060;branch=z9hG4bK5a36e4f0;received=24.128.119.26;rport=5060
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 57]: From: "asterisk" <sip:dkerr@24.128.119.26>;tag=as53cfbf4f
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 46]: To: <sip:outbound.vitelity.net>;tag=as3089cdb8
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 60]: Call-ID: 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 22]: User-Agent: packetrino
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 19]: Supported: replaces
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 23]: Accept: application/sdp
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 17]: Content-Length: 0
--- (11 headers 0 lines) ---
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060 (Checking To) --From tag as53cfbf4f --To-tag as3089cdb8  
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3997 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #575
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060' of Request 102: Match Found
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:6053 sip_destroy: Destroying SIP dialog 252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060
Really destroying SIP dialog '252abbc4624f87c229a4d4bc6a014a0d@24.128.119.26:5060' Method: OPTIONS
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:3886 __sip_autodestruct: Auto destroying SIP dialog '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060'
[Sep 23 12:02:20] DEBUG[840]: chan_sip.c:6053 sip_destroy: Destroying SIP dialog 532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060
Really destroying SIP dialog '532ba0017d31b194373a2ba53497d6ac@192.168.17.1:5060' Method: INVITE
[Sep 23 12:02:20] DEBUG[840]: rtp_engine.c:298 instance_destructor: Destroyed RTP instance '0x8907000'

<--- SIP read from UDP:192.168.17.4:5060 --->
BYE sip:105@192.168.17.1:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-600b93b2
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>;tag=as18959fef
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 102 BYE
Max-Forwards: 70
User-Agent: Linksys/PAP2T-5.1.6(LS)
Content-Length: 0

<------------->
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 37]: BYE sip:105@192.168.17.1:5060 SIP/2.0
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 58]: Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-600b93b2
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 57]: From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 41]: To: <sip:105@192.168.17.1>;tag=as18959fef
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 39]: Call-ID: b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 13]: CSeq: 102 BYE
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 16]: Max-Forwards: 70
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS)
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: b197e019-b79a12a1@192.168.17.4 (Checking From) --From tag 105641b97c61d81o0 --To-tag as18959fef  
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:25254 handle_incoming: **** Received BYE (8) - Command in SIP BYE
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:23954 handle_request_bye: Initializing initreq for method BYE - callid b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:21] DEBUG[840]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.4:5060' into...
[Sep 23 12:02:21] DEBUG[840]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.4' and port '5060'.
Sending to 192.168.17.4:5060 (NAT)
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:3088 sip_alreadygone: Setting SIP_ALREADYGONE on dialog b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:21] DEBUG[840]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x8895ba8'
Scheduling destruction of SIP dialog 'b197e019-b79a12a1@192.168.17.4' in 6400 ms (Method: BYE)
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:24056 handle_request_bye: Received bye, issuing owner hangup

<--- Transmitting (NAT) to 192.168.17.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.17.4:5060;branch=z9hG4bK-600b93b2;received=192.168.17.4;rport=5060
From: Line 1 <sip:101@192.168.17.1>;tag=105641b97c61d81o0
To: <sip:105@192.168.17.1>;tag=as18959fef
Call-ID: b197e019-b79a12a1@192.168.17.4
CSeq: 102 BYE
Server: Asterisk PBX 1.8.15.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<------------>
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:3346 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.17.4:5060
[Sep 23 12:02:21] DEBUG[2889]: devicestate.c:440 devstate_event: device 'SLA:SLAphone111_SLAtrunk1' state '1'
[Sep 23 12:02:21] DEBUG[2889]: devicestate.c:440 devstate_event: device 'SLA:SLAphone112_SLAtrunk1' state '1'
[Sep 23 12:02:21] DEBUG[2889]: pbx.c:5039 __ast_pbx_run: Extension 105, priority 2 returned normally even though call was hung up
[Sep 23 12:02:21] DEBUG[2889]: channel.c:2695 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/101-0000001e'
[Sep 23 12:02:21] DEBUG[2889]: pbx.c:4247 pbx_extension_helper: Launching 'Hangup'
    -- Executing [h@DefaultDialPlan:1] Hangup("SIP/101-0000001e", "") in new stack
[Sep 23 12:02:21] DEBUG[2889]: pbx.c:5243 __ast_pbx_run: Spawn extension (DefaultDialPlan,h,1) exited non-zero on 'SIP/101-0000001e'
  == Spawn extension (DefaultDialPlan, h, 1) exited non-zero on 'SIP/101-0000001e'
[Sep 23 12:02:21] DEBUG[2889]: channel.c:2844 ast_hangup: Hanging up channel 'SIP/101-0000001e'
[Sep 23 12:02:21] DEBUG[2889]: chan_sip.c:6287 sip_hangup: Hangup call SIP/101-0000001e, SIP callid b197e019-b79a12a1@192.168.17.4
[Sep 23 12:02:21] DEBUG[2889]: chan_sip.c:6292 sip_hangup: update_call_counter(101) - decrement call limit counter on hangup
[Sep 23 12:02:21] DEBUG[2889]: chan_sip.c:5905 update_call_counter: Updating call counter for incoming call
[Sep 23 12:02:21] DEBUG[2889]: chan_sip.c:5976 update_call_counter: Call from peer '101' removed from call limit 10
[Sep 23 12:02:21] DEBUG[2889]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x8895ba8'
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 101
[Sep 23 12:02:21] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 101
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/101 - state 1 (Not in use)
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/101' state '1'
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 101
[Sep 23 12:02:21] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 101
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/101 - state 1 (Not in use)
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/101' state '1'
[Sep 23 12:02:21] DEBUG[2901]: devicestate.c:440 devstate_event: device 'meetme:SLA_SLAtrunk1' state '1'
[Sep 23 12:02:21] DEBUG[2901]: channel.c:2844 ast_hangup: Hanging up channel 'DAHDI/pseudo-815145799'
[Sep 23 12:02:21] DEBUG[2901]: chan_dahdi.c:6149 dahdi_hangup: dahdi_hangup(DAHDI/pseudo-815145799)
[Sep 23 12:02:21] DEBUG[2901]: chan_dahdi.c:6316 dahdi_hangup: Hangup: channel: -2 index = 0, normal = 28, callwait = -1, thirdcall = -1
[Sep 23 12:02:21] DEBUG[2901]: chan_dahdi.c:6757 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/pseudo-815145799
[Sep 23 12:02:21] DEBUG[2901]: chan_dahdi.c:4874 update_conf: Updated conferencing on -2, with 0 conference users
    -- Hungup 'DAHDI/pseudo-815145799'
[Sep 23 12:02:21] WARNING[2901]: app_meetme.c:4558 admin_exec: Conference number 'SLA_SLAtrunk1' not found!
  == Setting global variable 'MEETMEADMINSTATUS' to 'NOTFOUND'
[Sep 23 12:02:21] DEBUG[2901]: devicestate.c:440 devstate_event: device 'SLA:SLAphone111_SLAtrunk1' state '1'
[Sep 23 12:02:21] DEBUG[2901]: devicestate.c:440 devstate_event: device 'SLA:SLAphone112_SLAtrunk1' state '1'
[Sep 23 12:02:21] DEBUG[2901]: channel.c:2844 ast_hangup: Hanging up channel 'SIP/111-0000001f'
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:6287 sip_hangup: Hangup call SIP/111-0000001f, SIP callid 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:6292 sip_hangup: update_call_counter(111) - decrement call limit counter on hangup
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:5905 update_call_counter: Updating call counter for outgoing call
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:5976 update_call_counter: Call to peer '111' removed from call limit 10
[Sep 23 12:02:21] DEBUG[2901]: res_rtp_asterisk.c:2563 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x88bc528'
Scheduling destruction of SIP dialog '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' in 6400 ms (Method: INVITE)
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:10397 reqprep: Strict routing enforced for session 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
set_destination: Parsing <sip:111@192.168.17.141:5060> for address/port to send to
[Sep 23 12:02:21] DEBUG[2901]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.17.141:5060' into...
[Sep 23 12:02:21] DEBUG[2901]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.17.141' and port '5060'.
set_destination: set destination to 192.168.17.141:5060
Reliably Transmitting (NAT) to 192.168.17.141:5060:
BYE sip:111@192.168.17.141:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK139323fd;rport
Max-Forwards: 70
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 103 BYE
User-Agent: Asterisk PBX 1.8.15.0
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:3801 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #580
[Sep 23 12:02:21] DEBUG[2901]: chan_sip.c:3346 __sip_xmit: Trying to put 'BYE sip:111' onto UDP socket destined for 192.168.17.141:5060
[Sep 23 12:02:21] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone111_SLAtrunk1@DialPlanSLA' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[823]: app_queue.c:1585 extension_state_cb: Extension 'SLAphone112_SLAtrunk1@DialPlanSLA' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone111_SLAtrunk1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone112_SLAtrunk1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for DAHDI - pseudo
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for DAHDI/pseudo - state 0 (Unknown)
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:440 devstate_event: device 'DAHDI/pseudo' state '0'
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:21] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 1 (Not in use)
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '1'
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:342 _ast_device_state: No provider found, checking channel drivers for SIP - 111
[Sep 23 12:02:21] DEBUG[822]: chan_sip.c:26559 sip_devicestate: Checking device state for peer 111
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:460 do_state_change: Changing state for SIP/111 - state 1 (Not in use)
[Sep 23 12:02:21] DEBUG[822]: devicestate.c:440 devstate_event: device 'SIP/111' state '1'
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/101' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/101' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'meetme:SLA_SLAtrunk1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone111_SLAtrunk1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SLA:SLAphone112_SLAtrunk1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'DAHDI/pseudo' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 23 12:02:21] DEBUG[859]: app_queue.c:1490 handle_statechange: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.

<--- SIP read from UDP:192.168.17.141:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK139323fd;rport=5060
From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
To: <sip:111@192.168.17.141:5060>;tag=2618545111
Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
CSeq: 103 BYE
Contact: <sip:111@192.168.17.141:5060>
Supported: replaces
User-Agent: C610A IP/42.072.00.000.000
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0

<------------->
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  1 [ 68]: Via: SIP/2.0/UDP 192.168.17.1:5060;branch=z9hG4bK139323fd;rport=5060
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  2 [ 52]: From: "Line 1" <sip:101@192.168.17.1>;tag=as0e4cf224
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  3 [ 48]: To: <sip:111@192.168.17.141:5060>;tag=2618545111
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  4 [ 59]: Call-ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  5 [ 13]: CSeq: 103 BYE
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  6 [ 38]: Contact: <sip:111@192.168.17.141:5060>
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  7 [ 19]: Supported: replaces
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  8 [ 38]: User-Agent: C610A IP/42.072.00.000.000
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header  9 [ 72]: Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8521 parse_request:  Header 10 [ 17]: Content-Length: 0
--- (11 headers 0 lines) ---
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:8115 find_call: = Looking for  Call ID: 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060 (Checking To) --From tag as0e4cf224 --To-tag 2618545111  
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:3997 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #580
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:4030 __sip_ack: Stopping retransmission on '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' of Request 103: Match Found
[Sep 23 12:02:21] DEBUG[840]: chan_sip.c:6053 sip_destroy: Destroying SIP dialog 40a207e7407c207e50099ddc786103c3@192.168.17.1:5060
Really destroying SIP dialog '40a207e7407c207e50099ddc786103c3@192.168.17.1:5060' Method: INVITE
[Sep 23 12:02:21] DEBUG[840]: rtp_engine.c:298 instance_destructor: Destroyed RTP instance '0x88bc528'
pbx*CLI>