<--- SIP read from 10.0.0.100:6592 ---> INVITE sip:303@10.0.0.3 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK1786ad19db134371b27921031b8b14fe To: From: ;tag=4402115000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 1 INVITE Contact: Max-Forwards: 70 Content-Type: application/sdp Content-Length: 229 v=0 o=- 2281 2 IN IP4 10.0.0.100 s=session c=IN IP4 10.0.0.100 t=0 0 m=audio 19173 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - <-------------> [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:303@10.0.0.3 SIP/2.0 (31) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK1786ad19db134371b27921031b8b14fe (79) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: (22) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=4402115000 (47) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 1 INVITE (14) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: Contact: (30) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Max-Forwards: 70 (16) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Content-Type: application/sdp (29) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Length: 229 (19) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: (0) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=- 2281 2 IN IP4 10.0.0.100 (28) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 10.0.0.100 (19) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 19173 RTP/AVP 0 101 (27) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: (0) --- (10 headers 12 lines) --- [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7397878d09e69df72eaacb5843abd84d@10.0.0.3 Their Tag as12d4f05a Our tag: as572fe62c [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 6bad60dd564f924b540f62135a631c92@10.0.0.3 Their Tag as688bbd1c Our tag: as7f44aa39 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 60e661d90bb34ccd496f171a3b6488c9@10.0.0.3 Their Tag as3c9fa39d Our tag: as3f836bf5 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 2f4129401b7127b740095d432bf0dbe9@10.0.0.3 Their Tag as5bec18c0 Our tag: as3c0385e1 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2738 do_setnat: Setting NAT on VRTP to Off [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for 2fbed449f234429bbd8a3b3dea1ec1de - INVITE (With RTP) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:15154 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.0.0.100 : 6592 (no NAT) Using INVITE request as basis request - 2fbed449f234429bbd8a3b3dea1ec1de [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2738 do_setnat: Setting NAT on VRTP to Off <--- Reliably Transmitting (no NAT) to 10.0.0.100:6592 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK1786ad19db134371b27921031b8b14fe;received=10.0.0.100 From: ;tag=4402115000 To: ;tag=as1c1e1a10 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="03cc9d6b" Content-Length: 0 <------------> [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #115 Scheduling destruction of SIP dialog '2fbed449f234429bbd8a3b3dea1ec1de' in 32000 ms (Method: INVITE) Found user 'seaviewtest' asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> ACK sip:303@10.0.0.3 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK1786ad19db134371b27921031b8b14fe To: ;tag=as1c1e1a10 From: ;tag=4402115000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 1 ACK Max-Forwards: 70 <-------------> [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: ACK sip:303@10.0.0.3 SIP/2.0 (28) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK1786ad19db134371b27921031b8b14fe (79) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=as1c1e1a10 (37) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=4402115000 (47) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 1 ACK (11) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: Max-Forwards: 70 (16) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: (0) --- (7 headers 0 lines) --- [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as1c1e1a10 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:15154 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2160 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #115 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '2fbed449f234429bbd8a3b3dea1ec1de' of Response 1: Match Not Found asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> INVITE sip:303@10.0.0.3 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK97191633e11243409e9fbb22364666aa To: From: ;tag=4403365000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 2 INVITE Contact: Max-Forwards: 70 Proxy-Authorization: Digest realm="asterisk",nonce="03cc9d6b",username="seaviewtest",response="19280ffa65ce34613c1179047565d3df",uri="sip:303@10.0.0.3",algorithm=md5 Content-Type: application/sdp Content-Length: 229 v=0 o=- 2281 2 IN IP4 10.0.0.100 s=session c=IN IP4 10.0.0.100 t=0 0 m=audio 19173 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - <-------------> [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:303@10.0.0.3 SIP/2.0 (31) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK97191633e11243409e9fbb22364666aa (79) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: (22) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=4403365000 (47) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 2 INVITE (14) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: Contact: (30) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Max-Forwards: 70 (16) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Proxy-Authorization: Digest realm="asterisk",nonce="03cc9d6b",username="seaviewtest",response="19280ffa65ce34613c1179047565d3df",uri="sip:303@10.0.0.3",algorithm=md5 (165) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Type: application/sdp (29) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 229 (19) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=- 2281 2 IN IP4 10.0.0.100 (28) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 10.0.0.100 (19) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 19173 RTP/AVP 0 101 (27) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: (0) --- (11 headers 12 lines) --- [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as1c1e1a10 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:15154 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.0.0.100 : 6592 (no NAT) Using INVITE request as basis request - 2fbed449f234429bbd8a3b3dea1ec1de [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2733 do_setnat: Setting NAT on RTP to Off [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:2738 do_setnat: Setting NAT on VRTP to Off Found user 'seaviewtest' Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 10.0.0.100:19173 Found audio description format PCMU for ID 0 Found audio description format G729 for ID 18 Found audio description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x104 (ulaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.0.0.100:19173 [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:13834 handle_request_invite: Checking SIP call limits for device seaviewtest [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for incoming call Looking for 303 in default (domain 10.0.0.3) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:3993 sip_new: *** Our native formats are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:3995 sip_new: *** Our capabilities are 0xc (ulaw|alaw) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:4019 sip_new: This channel will not be able to handle video. [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:8241 build_route: build_route: Contact hop: list_route: hop: [Jan 24 08:40:37] DEBUG[9416]: chan_sip.c:13913 handle_request_invite: SIP/seaviewtest-092eb2d8: New call is still down.... Trying... <--- Transmitting (no NAT) to 10.0.0.100:6592 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK97191633e11243409e9fbb22364666aa;received=10.0.0.100 From: ;tag=4403365000 To: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jan 24 08:40:37] DEBUG[9416]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/seaviewtest-092eb2d8 [Jan 24 08:40:37] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - seaviewtest [Jan 24 08:40:37] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer seaviewtest [Jan 24 08:40:37] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/seaviewtest - state 4 (Invalid) [Jan 24 08:40:37] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/seaviewtest' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jan 24 08:40:37] DEBUG[9470]: pbx.c:1831 pbx_extension_helper: Launching 'Dial' -- Executing [303@default:1] Dial("SIP/seaviewtest-092eb2d8", "SIP/3001@xx.xx.xx.54:5061") in new stack [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:15857 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3993 sip_new: *** Our native formats are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x0 (nothing) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3995 sip_new: *** Our capabilities are 0xc (ulaw|alaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3998 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4019 sip_new: This channel will not be able to handle video. [Jan 24 08:40:37] DEBUG[9470]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Jan 24 08:40:37] DEBUG[9470]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Jan 24 08:40:37] DEBUG[9470]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPURI. [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:2991 sip_call: Outgoing Call for 3001 [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:3006 sip_call: Our T38 capability (0), joint T38 capability (0) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:6421 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: False [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:37] DEBUG[9470]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:3001@xx.xx.xx.54:5061 SIP/2.0 (42) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK6511c987;rport (59) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 3: To: (33) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 4: Contact: (35) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 5: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 6: CSeq: 102 INVITE (16) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 9: Date: Thu, 24 Jan 2008 13:40:37 GMT (35) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 11: Supported: replaces (19) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 13: Content-Length: 254 (19) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4774 parse_request: Header 14: (0) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: o=root 9395 9395 IN IP4 10.0.0.3 (32) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: c=IN IP4 10.0.0.3 (17) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: m=audio 17142 RTP/AVP 0 8 101 (29) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:37] DEBUG[9470]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #117 -- Called 3001@xx.xx.xx.54:5061 [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 100 Trying (18) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK6511c987;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: (33) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 0 (17) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag Our tag: as3dd83222 [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:2203 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #117 - INVITE (got response) [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7072226b535106702335a31d499f2905@10.0.0.3' Request 102: Found [Jan 24 08:40:38] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 100 to standard invite [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK6511c987;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 0 (17) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag Our tag: as3dd83222 [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7072226b535106702335a31d499f2905@10.0.0.3' Request 102: Found [Jan 24 08:40:39] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 180 to standard invite [Jan 24 08:40:39] DEBUG[9416]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/xx.xx.xx.54:5061-093145d8 -- SIP/xx.xx.xx.54:5061-093145d8 is ringing asterisk1*CLI> <--- Transmitting (no NAT) to 10.0.0.100:6592 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK97191633e11243409e9fbb22364666aa;received=10.0.0.100 From: ;tag=4403365000 To: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jan 24 08:40:39] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - xx.xx.xx.54:5061 [Jan 24 08:40:39] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer xx.xx.xx.54:5061 [Jan 24 08:40:39] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/xx.xx.xx.54:5061 - state 6 (Ringing) [Jan 24 08:40:39] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/xx.xx.xx.54:5061' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK6511c987;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Type: application/sdp (29) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: Content-Length: 266 (19) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 12: (0) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=root 25747 25747 IN IP4 xx.xx.xx.54 (39) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.54 (22) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 17416 RTP/AVP 0 8 101 (29) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:2152 __sip_ack: Acked pending invite 102 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '7072226b535106702335a31d499f2905@10.0.0.3' of Request 102: Match Not Found [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 200 to standard invite [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:8241 build_route: build_route: Contact hop: [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:40] DEBUG[9470]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/xx.xx.xx.54:5061-093145d8 -- SIP/xx.xx.xx.54:5061-093145d8 answered SIP/seaviewtest-092eb2d8 [Jan 24 08:40:40] DEBUG[9470]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/seaviewtest-092eb2d8 [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:3647 sip_answer: SIP answering channel: SIP/seaviewtest-092eb2d8 [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:6657 transmit_response_with_sdp: Setting framing from config on incoming call [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:6421 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.3 port 19374 Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:40] DEBUG[9470]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) <--- Reliably Transmitting (no NAT) to 10.0.0.100:6592 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK97191633e11243409e9fbb22364666aa;received=10.0.0.100 From: ;tag=4403365000 To: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 230 v=0 o=root 9395 9395 IN IP4 10.0.0.3 s=session c=IN IP4 10.0.0.3 t=0 0 m=audio 19374 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Jan 24 08:40:40] DEBUG[9470]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #119 -- Packet2Packet bridging SIP/seaviewtest-092eb2d8 and SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:40] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - xx.xx.xx.54:5061 [Jan 24 08:40:40] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer xx.xx.xx.54:5061 [Jan 24 08:40:40] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/xx.xx.xx.54:5061 - state 2 (In use) [Jan 24 08:40:40] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - seaviewtest [Jan 24 08:40:40] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer seaviewtest [Jan 24 08:40:40] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/xx.xx.xx.54:5061' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 24 08:40:40] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/seaviewtest - state 4 (Invalid) [Jan 24 08:40:40] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/seaviewtest' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> ACK sip:303@10.0.0.3 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bKd79664abb9964679bc81427e3396df8c To: ;tag=as7ef33d32 From: ;tag=4403365000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 2 ACK Max-Forwards: 70 <-------------> [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: ACK sip:303@10.0.0.3 SIP/2.0 (28) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bKd79664abb9964679bc81427e3396df8c (79) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=as7ef33d32 (37) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=4403365000 (47) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 2 ACK (11) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: Max-Forwards: 70 (16) [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: (0) --- (7 headers 0 lines) --- [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as7ef33d32 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:15154 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:2160 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #119 [Jan 24 08:40:40] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '2fbed449f234429bbd8a3b3dea1ec1de' of Response 2: Match Not Found asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> REFER sip:303@10.0.0.3 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK226e944f3f934cc49a08b1a6f744e98f To: ;tag=as7ef33d32 From: ;tag=4403365000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 3 REFER Contact: Max-Forwards: 70 Proxy-Authorization: Digest realm="asterisk",nonce="03cc9d6b",username="seaviewtest",response="19280ffa65ce34613c1179047565d3df",uri="sip:303@10.0.0.3",algorithm=md5 Refer-To: Referred-By: <-------------> [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: REFER sip:303@10.0.0.3 SIP/2.0 (30) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK226e944f3f934cc49a08b1a6f744e98f (79) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=as7ef33d32 (37) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=4403365000 (47) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 3 REFER (13) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: Contact: (30) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Max-Forwards: 70 (16) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Proxy-Authorization: Digest realm="asterisk",nonce="03cc9d6b",username="seaviewtest",response="19280ffa65ce34613c1179047565d3df",uri="sip:303@10.0.0.3",algorithm=md5 (165) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Refer-To: (28) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Referred-By: (39) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as7ef33d32 [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:15154 handle_request: **** Received REFER (9) - Command in SIP REFER Call 2fbed449f234429bbd8a3b3dea1ec1de got a SIP call transfer from caller: (REFER)! SIP transfer to extension 304@default by seaviewtest@10.0.0.3 [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:14395 handle_request_refer: SIP blind transfer: Transferer channel SIP/seaviewtest-092eb2d8, transferee channel SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:14411 handle_request_refer: Got SIP transfer, applying to bridged peer 'SIP/xx.xx.xx.54:5061-093145d8' <--- Transmitting (no NAT) to 10.0.0.100:6592 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.0.0.100:6592;branch=z9hG4bK226e944f3f934cc49a08b1a6f744e98f;received=10.0.0.100 From: ;tag=4403365000 To: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 3 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:14449 handle_request_refer: chan1->name: SIP/seaviewtest-092eb2d8 [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 2fbed449f234429bbd8a3b3dea1ec1de set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.100, port 6592 Reliably Transmitting (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #120 [Jan 24 08:40:45] DEBUG[9416]: channel.c:3512 ast_channel_masquerade: Planning to masquerade channel SIP/xx.xx.xx.54:5061-093145d8 into the structure of AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:45] DEBUG[9416]: channel.c:3526 ast_channel_masquerade: Done planning to masquerade channel SIP/xx.xx.xx.54:5061-093145d8 into the structure of AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:45] DEBUG[9416]: channel.c:3637 ast_do_masquerade: Actually Masquerading SIP/xx.xx.xx.54:5061-093145d8(6) into the structure of AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8(6) [Jan 24 08:40:45] DEBUG[9416]: channel.c:3649 ast_do_masquerade: Got clone lock for masquerade on 'SIP/xx.xx.xx.54:5061-093145d8' at 0x9308858 [Jan 24 08:40:45] DEBUG[9416]: channel.c:3852 ast_do_masquerade: Putting channel SIP/xx.xx.xx.54:5061-093145d8 in 4/4 formats [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:3772 sip_fixup: SIP Fixup: New owner for dialogue 7072226b535106702335a31d499f2905@10.0.0.3: SIP/xx.xx.xx.54:5061-093145d8 (Old parent: AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8) [Jan 24 08:40:45] DEBUG[9416]: channel.c:3892 ast_do_masquerade: Released clone lock on 'AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8' [Jan 24 08:40:45] DEBUG[9416]: channel.c:3902 ast_do_masquerade: Done Masquerading SIP/xx.xx.xx.54:5061-093145d8 (6) [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:14511 handle_request_refer: Blind transfer succeeded. Telling transferer. [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 2fbed449f234429bbd8a3b3dea1ec1de set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.100, port 6592 Reliably Transmitting (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK757e67ff;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 16 SIP/2.0 200 Ok --- [Jan 24 08:40:45] DEBUG[9416]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #121 [Jan 24 08:40:45] DEBUG[9470]: rtp.c:3181 bridge_p2p_loop: Oooh, got a hangup [Jan 24 08:40:45] DEBUG[9470]: channel.c:4343 ast_channel_bridge: Returning from native bridge, channels: SIP/seaviewtest-092eb2d8, AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:45] DEBUG[9470]: channel.c:1794 ast_hangup: Hanging up zombie 'AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8' [Jan 24 08:40:45] DEBUG[9470]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel AsyncGoto/SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:45] DEBUG[9470]: rtp.c:1504 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Jan 24 08:40:45] DEBUG[9470]: app_dial.c:1736 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Jan 24 08:40:45] DEBUG[9470]: pbx.c:2427 __ast_pbx_run: Spawn extension (default,303,1) exited non-zero on 'SIP/seaviewtest-092eb2d8' == Spawn extension (default, 303, 1) exited non-zero on 'SIP/seaviewtest-092eb2d8' [Jan 24 08:40:45] DEBUG[9470]: channel.c:1570 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/seaviewtest-092eb2d8' [Jan 24 08:40:45] DEBUG[9470]: channel.c:1789 ast_hangup: Hanging up channel 'SIP/seaviewtest-092eb2d8' [Jan 24 08:40:45] DEBUG[9470]: chan_sip.c:3470 sip_hangup: SIP Transfer: Not hanging up right now... Rescheduling hangup for 2fbed449f234429bbd8a3b3dea1ec1de. Scheduling destruction of SIP dialog '2fbed449f234429bbd8a3b3dea1ec1de' in 32000 ms (Method: REFER) [Jan 24 08:40:45] DEBUG[9470]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/seaviewtest-092eb2d8 [Jan 24 08:40:45] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for AsyncGoto - SIP/xx.xx.xx.54:5061 [Jan 24 08:40:45] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for AsyncGoto/SIP/xx.xx.xx.54:5061 - state 4 (Invalid) [Jan 24 08:40:45] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - seaviewtest [Jan 24 08:40:45] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer seaviewtest [Jan 24 08:40:45] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'AsyncGoto/SIP/xx.xx.xx.54:5061' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jan 24 08:40:45] DEBUG[9471]: pbx.c:1831 pbx_extension_helper: Launching 'Dial' -- Executing [304@default:1] Dial("SIP/xx.xx.xx.54:5061-093145d8", "SIP/31074@xx.xx.xx.52:5061") in new stack [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:15857 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:4509 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jan 24 08:40:45] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/seaviewtest - state 4 (Invalid) [Jan 24 08:40:45] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/seaviewtest' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:3993 sip_new: *** Our native formats are 0x4 (ulaw) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:3994 sip_new: *** Joint capabilities are 0x0 (nothing) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:3995 sip_new: *** Our capabilities are 0xc (ulaw|alaw) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:3996 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:3998 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Jan 24 08:40:45] DEBUG[9471]: chan_sip.c:4019 sip_new: This channel will not be able to handle video. [Jan 24 08:40:45] DEBUG[9471]: rtp.c:1626 ast_rtp_make_compatible: Seeded SDP of 'SIP/xx.xx.xx.52:5061-0931ccd0' with that of 'SIP/xx.xx.xx.54:5061-093145d8' [Jan 24 08:40:45] DEBUG[9471]: channel.c:3566 ast_channel_inherit_variables: Copying soft-transferable variable SIPTRANSFER_REFERER. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3566 ast_channel_inherit_variables: Copying soft-transferable variable SIPTRANSFER. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3579 ast_channel_inherit_variables: Not copying variable BLINDTRANSFER. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3579 ast_channel_inherit_variables: Not copying variable BRIDGEPEER. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3579 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Jan 24 08:40:45] DEBUG[9471]: channel.c:3579 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:2984 sip_call: Call for 31074 transfered by seaviewtest@10.0.0.3 [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:2991 sip_call: Outgoing Call for 31074 [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:3006 sip_call: Our T38 capability (0), joint T38 capability (0) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:6421 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: False [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:46] DEBUG[9471]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:31074@xx.xx.xx.52:5061 SIP/2.0 (43) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK29c2acef;rport (59) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 3: To: (34) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag Our tag: as603e760b [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as7ef33d32 [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 4: Contact: (27) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 5: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 6: CSeq: 102 INVITE (16) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 9: Date: Thu, 24 Jan 2008 13:40:46 GMT (35) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 11: Supported: replaces (19) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 13: Content-Length: 254 (19) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 14: (0) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: o=root 9395 9395 IN IP4 10.0.0.3 (32) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: c=IN IP4 10.0.0.3 (17) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: m=audio 13368 RTP/AVP 0 8 101 (29) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK757e67ff To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 103 NOTIFY <-------------> [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK757e67ff (53) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 103 NOTIFY (16) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag Our tag: as603e760b [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4402115000 Our tag: as7ef33d32 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:2160 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #121 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '2fbed449f234429bbd8a3b3dea1ec1de' of Request 103: Match Not Found SIP Response message for INCOMING dialog NOTIFY arrived [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:46] DEBUG[9471]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #123 -- Called 31074@xx.xx.xx.52:5061 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 100 Trying (18) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK29c2acef;received=144.131.40.27;rport=60616 (88) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: (34) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Contact: (39) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Length: 0 (17) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: (0) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag Our tag: as603e760b [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:2203 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #123 - INVITE (got response) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '15e2aec55c76e8202489f3e2487eee9f@10.0.0.3' Request 102: Found [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 100 to standard invite [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (1) NOTIFY - 4 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #120)) Retransmitting #1 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag Our tag: as603e760b [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:46] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK29c2acef;received=144.131.40.27;rport=60616 (88) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0c6770b4 (49) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Contact: (39) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Length: 0 (17) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: (0) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag Our tag: as603e760b [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '15e2aec55c76e8202489f3e2487eee9f@10.0.0.3' Request 102: Found [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 180 to standard invite [Jan 24 08:40:47] DEBUG[9416]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/xx.xx.xx.52:5061-0931ccd0 -- SIP/xx.xx.xx.52:5061-0931ccd0 is ringing [Jan 24 08:40:47] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - xx.xx.xx.52:5061 [Jan 24 08:40:47] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer xx.xx.xx.52:5061 [Jan 24 08:40:47] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/xx.xx.xx.52:5061 - state 6 (Ringing) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:17508 sip_set_rtp_peer: Sending reinvite on SIP '7072226b535106702335a31d499f2905@10.0.0.3' - It's audio soon redirected to IP 10.0.0.3 [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:5871 reqprep: Strict routing enforced for session 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:6421 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:47] DEBUG[9471]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:1640 initialize_initreq: Initializing already initialized SIP dialog 7072226b535106702335a31d499f2905@10.0.0.3 (presumably reinvite) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:3001@xx.xx.xx.54:5061 SIP/2.0 (42) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK73d0763b;rport (59) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 4: Contact: (35) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 5: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 6: CSeq: 103 INVITE (16) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 10: Supported: replaces (19) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 13: Content-Length: 254 (19) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 14: (0) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: o=root 9395 9396 IN IP4 10.0.0.3 (32) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: c=IN IP4 10.0.0.3 (17) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: m=audio 17142 RTP/AVP 0 8 101 (29) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:47] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/xx.xx.xx.52:5061' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:47] DEBUG[9471]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #125 [Jan 24 08:40:47] DEBUG[9471]: rtp.c:1555 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/xx.xx.xx.54:5061-093145d8' with that of 'SIP/xx.xx.xx.52:5061-0931ccd0' [Jan 24 08:40:47] DEBUG[9471]: channel.c:2633 ast_indicate_data: Driver for channel 'SIP/xx.xx.xx.54:5061-093145d8' does not support indication 3, emulating it [Jan 24 08:40:47] DEBUG[9471]: channel.c:3069 set_format: Set channel SIP/xx.xx.xx.54:5061-093145d8 to write format slin [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (2) NOTIFY - 4 [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #120)) Retransmitting #2 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:47] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 100 Trying (18) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK73d0763b;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 103 INVITE (16) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 0 (17) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2203 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #125 - INVITE (got response) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7072226b535106702335a31d499f2905@10.0.0.3' Request 103: Found [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:11972 handle_response_invite: SIP response 100 to RE-invite on outgoing call 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK73d0763b;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 103 INVITE (16) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Type: application/sdp (29) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: Content-Length: 266 (19) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 12: (0) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=root 25747 25748 IN IP4 xx.xx.xx.54 (39) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.54 (22) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 17416 RTP/AVP 0 8 101 (29) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2152 __sip_ack: Acked pending invite 103 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '7072226b535106702335a31d499f2905@10.0.0.3' of Request 103: Match Not Found [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:11972 handle_response_invite: SIP response 200 to RE-invite on outgoing call 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:8180 build_route: build_route: Retaining previous route: [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK29c2acef;received=144.131.40.27;rport=60616 (88) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0c6770b4 (49) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Contact: (39) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Type: application/sdp (29) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 240 (19) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=root 3872 3872 IN IP4 xx.xx.xx.52 (37) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.52 (22) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 17286 RTP/AVP 0 8 101 (29) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2152 __sip_ack: Acked pending invite 102 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '15e2aec55c76e8202489f3e2487eee9f@10.0.0.3' of Request 102: Match Not Found [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:11974 handle_response_invite: SIP response 200 to standard invite [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/xx.xx.xx.52:5061-0931ccd0 [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:8241 build_route: build_route: Contact hop: [Jan 24 08:40:48] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 [Jan 24 08:40:48] DEBUG[9471]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/xx.xx.xx.52:5061-0931ccd0 -- SIP/xx.xx.xx.52:5061-0931ccd0 answered SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:17508 sip_set_rtp_peer: Sending reinvite on SIP '7072226b535106702335a31d499f2905@10.0.0.3' - It's audio soon redirected to IP xx.xx.xx.52 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:5871 reqprep: Strict routing enforced for session 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6421 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:48] DEBUG[9471]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:1640 initialize_initreq: Initializing already initialized SIP dialog 7072226b535106702335a31d499f2905@10.0.0.3 (presumably reinvite) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:3001@xx.xx.xx.54:5061 SIP/2.0 (42) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK1d5a4c1c;rport (59) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 4: Contact: (35) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 5: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 6: CSeq: 104 INVITE (16) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 10: Supported: replaces (19) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 13: Content-Length: 264 (19) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 14: (0) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: o=root 9395 9397 IN IP4 xx.xx.xx.52 (37) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.52 (22) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: m=audio 17286 RTP/AVP 0 8 101 (29) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #126 [Jan 24 08:40:48] DEBUG[9471]: rtp.c:1555 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/xx.xx.xx.54:5061-093145d8' with that of 'SIP/xx.xx.xx.52:5061-0931ccd0' [Jan 24 08:40:48] DEBUG[9471]: channel.c:3069 set_format: Set channel SIP/xx.xx.xx.54:5061-093145d8 to write format ulaw -- Native bridging SIP/xx.xx.xx.54:5061-093145d8 and SIP/xx.xx.xx.52:5061-0931ccd0 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:17508 sip_set_rtp_peer: Sending reinvite on SIP '15e2aec55c76e8202489f3e2487eee9f@10.0.0.3' - It's audio soon redirected to IP xx.xx.xx.54 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:5871 reqprep: Strict routing enforced for session 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6421 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6422 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6553 add_sdp: -- Done with adding codecs to SDP [Jan 24 08:40:48] DEBUG[9471]: channel.c:2579 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:6598 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:1640 initialize_initreq: Initializing already initialized SIP dialog 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (presumably reinvite) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 0: INVITE sip:31074@xx.xx.xx.52:5061 SIP/2.0 (43) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK049d2cd6;rport (59) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0c6770b4 (49) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 4: Contact: (27) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 5: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 6: CSeq: 103 INVITE (16) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 10: Supported: replaces (19) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 13: Content-Length: 264 (19) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4774 parse_request: Header 14: (0) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:48] DEBUG[9398]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - xx.xx.xx.52:5061 [Jan 24 08:40:48] DEBUG[9398]: chan_sip.c:15788 sip_devicestate: Checking device state for peer xx.xx.xx.52:5061 [Jan 24 08:40:48] DEBUG[9398]: channel.c:1086 channel_find_locked: Avoiding initial deadlock for channel '0x93087e0' [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: o=root 9395 9396 IN IP4 xx.xx.xx.54 (37) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.54 (22) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: m=audio 17416 RTP/AVP 0 8 101 (29) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:48] DEBUG[9398]: channel.c:1086 channel_find_locked: Avoiding initial deadlock for channel '0x93087e0' [Jan 24 08:40:48] DEBUG[9471]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #127 [Jan 24 08:40:48] DEBUG[9398]: devicestate.c:287 do_state_change: Changing state for SIP/xx.xx.xx.52:5061 - state 2 (In use) [Jan 24 08:40:48] DEBUG[9415]: app_queue.c:589 handle_statechange: Device 'SIP/xx.xx.xx.52:5061' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 100 Trying (18) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK1d5a4c1c;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 104 INVITE (16) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 0 (17) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2203 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #126 - INVITE (got response) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2212 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7072226b535106702335a31d499f2905@10.0.0.3' Request 104: Found [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:11972 handle_response_invite: SIP response 100 to RE-invite on outgoing call 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK1d5a4c1c;received=144.131.40.27;rport=60612 (88) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "seaviewtest" ;tag=as3dd83222 (61) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0e26aa0c (48) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 7072226b535106702335a31d499f2905@10.0.0.3 (50) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 104 INVITE (16) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Supported: replaces (19) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Contact: (38) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Type: application/sdp (29) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: Content-Length: 266 (19) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 12: (0) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=root 25747 25749 IN IP4 xx.xx.xx.54 (39) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.54 (22) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 17416 RTP/AVP 0 8 101 (29) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=ptime:20 (10) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=sendrecv (10) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2152 __sip_ack: Acked pending invite 104 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '7072226b535106702335a31d499f2905@10.0.0.3' of Request 104: Match Not Found [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:11972 handle_response_invite: SIP response 200 to RE-invite on outgoing call 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:8180 build_route: build_route: Retaining previous route: [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12106 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12111 handle_response_invite: T38 state changed to 0 on channel SIP [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12114 handle_response_invite: T38 state changed to 0 on channel SIP/xx.xx.xx.54:5061-093145d8 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 7072226b535106702335a31d499f2905@10.0.0.3 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK049d2cd6;received=144.131.40.27;rport=60616 (88) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: From: "303" ;tag=as603e760b (45) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: To: ;tag=as0c6770b4 (49) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 (50) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 103 INVITE (16) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: User-Agent: asterisk (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 8: Contact: (39) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 9: Content-Type: application/sdp (29) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 10: Content-Length: 240 (19) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 11: (0) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: v=0 (3) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: o=root 3872 3873 IN IP4 xx.xx.xx.52 (37) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: s=session (9) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: c=IN IP4 xx.xx.xx.52 (22) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: t=0 0 (5) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: m=audio 17286 RTP/AVP 0 8 101 (29) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4806 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2152 __sip_ack: Acked pending invite 103 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2160 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #127 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '15e2aec55c76e8202489f3e2487eee9f@10.0.0.3' of Request 103: Match Not Found [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:11972 handle_response_invite: SIP response 200 to RE-invite on outgoing call 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5388 process_sdp: T38 state changed to 0 on channel SIP/xx.xx.xx.52:5061-0931ccd0 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5468 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5475 process_sdp: We have an owner, now see if we need to change this call [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:3173 update_call_counter: Updating call counter for outgoing call [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:8180 build_route: build_route: Retaining previous route: [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12106 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12111 handle_response_invite: T38 state changed to 0 on channel SIP [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:12114 handle_response_invite: T38 state changed to 0 on channel SIP/xx.xx.xx.52:5061-0931ccd0 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (3) NOTIFY - 4 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #120)) Retransmitting #3 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:49] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (4) NOTIFY - 4 [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #120)) Retransmitting #4 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:53] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (5) NOTIFY - 4 [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #120)) Retransmitting #5 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:40:57] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:1908 retrans_pkt: SIP TIMER: Rescheduling retransmission #120 (6) NOTIFY - 4 [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:1922 retrans_pkt: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #120)) Retransmitting #6 (no NAT) to 10.0.0.100:6592: NOTIFY sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Contact: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=3 Subscription-state: active Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 21 SIP/2.0 183 Ringing --- asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 102 NOTIFY <-------------> [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK267c20da (53) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:41:01] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:41:05] WARNING[9416]: chan_sip.c:1944 retrans_pkt: Maximum retries exceeded on transmission 2fbed449f234429bbd8a3b3dea1ec1de for seqno 102 (Non-critical Request) [Jan 24 08:41:09] DEBUG[9412]: chan_iax2.c:8447 iax2_do_register: Allocate call number [Jan 24 08:41:09] DEBUG[9412]: chan_iax2.c:8453 iax2_do_register: Registration created on call 1 [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:2091 __sip_autodestruct: Auto destroying SIP dialog '2fbed449f234429bbd8a3b3dea1ec1de' [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:2098 __sip_autodestruct: Finally hanging up channel after transfer: 2fbed449f234429bbd8a3b3dea1ec1de [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:5871 reqprep: Strict routing enforced for session 2fbed449f234429bbd8a3b3dea1ec1de set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.100, port 6592 Reliably Transmitting (no NAT) to 10.0.0.100:6592: BYE sip:10.0.0.100:6592 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK2ae15778;rport From: ;tag=as7ef33d32 To: ;tag=4403365000 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:2041 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #128 Scheduling destruction of SIP dialog '2fbed449f234429bbd8a3b3dea1ec1de' in 32000 ms (Method: REFER) asterisk1*CLI> <--- SIP read from 10.0.0.100:6592 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK2ae15778 To: ;tag=4403365000 From: ;tag=as7ef33d32 Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de CSeq: 104 BYE <-------------> [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 0: SIP/2.0 200 Ok (14) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK2ae15778 (53) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 2: To: ;tag=4403365000 (45) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 3: From: ;tag=as7ef33d32 (39) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 4: Call-ID: 2fbed449f234429bbd8a3b3dea1ec1de (41) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 5: CSeq: 104 BYE (13) [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4774 parse_request: Header 6: (0) --- (6 headers 0 lines) --- [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 15e2aec55c76e8202489f3e2487eee9f@10.0.0.3 Their Tag as0c6770b4 Our tag: as603e760b [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4562 find_call: = No match Their Call ID: 7072226b535106702335a31d499f2905@10.0.0.3 Their Tag as0e26aa0c Our tag: as3dd83222 [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:4562 find_call: = Found Their Call ID: 2fbed449f234429bbd8a3b3dea1ec1de Their Tag 4403365000 Our tag: as7ef33d32 [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:2160 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #128 [Jan 24 08:41:17] DEBUG[9416]: chan_sip.c:2170 __sip_ack: Stopping retransmission on '2fbed449f234429bbd8a3b3dea1ec1de' of Request 104: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '2fbed449f234429bbd8a3b3dea1ec1de' Method: REFER asterisk1*CLI>