[Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 1 INVITE (14) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b757-176c2f55-bbdaf82 (82) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Supported: replaces (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Contact: (54) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: Content-Type: application/sdp (29) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 11: Content-Length: 341 (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 12: (0) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: v=0 (3) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: o=rtp 1160034135682447000 1160034135682447000 IN IP4 10.69.255.246 (66) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: s=- (3) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: c=IN IP4 10.69.255.246 (22) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: t=0 0 (5) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: m=audio 5004 RTP/AVP 0 8 18 4 98 2 101 (38) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:98 g726-16/8000 (24) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 14 lines) --- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4158 sip_alloc: Allocating new SIP dialog for 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 - INVITE (With RTP) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:1624 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:1632 parse_sip_options: Found SIP option: -replaces- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:1638 parse_sip_options: Matched SIP option: replaces Sending to 10.69.255.246 : 5060 (NAT) Using INVITE request as basis request - 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:8747 check_user_full: Setting NAT on RTP to Off [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:8757 check_user_full: Setting NAT on UDPTL to Off Reliably Transmitting (no NAT) to 10.69.255.246:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b757-176c2f55-bbdaf82;received=10.69.255.246 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404";tag=as6dd400c9 Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="inspiredbroadcast.net", nonce="2782b52f" Content-Length: 0 --- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:1915 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #31 Scheduling destruction of SIP dialog '100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246' in 32000 ms (Method: INVITE) Found user 'tulip2' asterisk1*CLI> <-- SIP read from 10.69.255.246:5060: ACK sip:404@10.69.255.251;transport=UDP SIP/2.0 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404";tag=as6dd400c9 Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 1 ACK Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b757-176c2f55-bbdaf82 Max-Forwards: 70 Contact: Content-Length: 0 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: ACK sip:404@10.69.255.251;transport=UDP SIP/2.0 (47) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 (94) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: "404";tag=as6dd400c9 (47) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 (72) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 1 ACK (11) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b757-176c2f55-bbdaf82 (82) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Contact: (54) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Content-Length: 0 (17) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 Their Tag 100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 Our tag: as6dd400c9 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received ACK (6) - Command in SIP ACK [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:2013 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #31 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:2023 __sip_ack: Stopping retransmission on '100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246' of Response 1: Match Not Found asterisk1*CLI> <-- SIP read from 10.69.255.246:5060: INVITE sip:404@10.69.255.251;transport=UDP SIP/2.0 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404" Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 2 INVITE Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b758-176c3005-207a5f8e Max-Forwards: 70 Supported: replaces Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL Contact: Proxy-Authorization: Digest username="tulip2",realm="inspiredbroadcast.net",nonce="2782b52f",uri="sip:404@10.69.255.251;transport=UDP",response="83333f5ebd4e7e80147faf75e99d9b36",algorithm=MD5 Content-Type: application/sdp Content-Length: 341 v=0 o=rtp 1160034135682447000 1160034135682447000 IN IP4 10.69.255.246 s=- c=IN IP4 10.69.255.246 t=0 0 m=audio 5004 RTP/AVP 0 8 18 4 98 2 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:98 g726-16/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: INVITE sip:404@10.69.255.251;transport=UDP SIP/2.0 (50) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 (94) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: "404" (32) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 (72) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 2 INVITE (14) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b758-176c3005-207a5f8e (83) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Supported: replaces (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Contact: (54) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: Proxy-Authorization: Digest username="tulip2",realm="inspiredbroadcast.net",nonce="2782b52f",uri="sip:404@10.69.255.251;transport=UDP",response="83333f5ebd4e7e80147faf75e99d9b36",algorithm=MD5 (192) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 11: Content-Type: application/sdp (29) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 12: Content-Length: 341 (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 13: (0) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: v=0 (3) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: o=rtp 1160034135682447000 1160034135682447000 IN IP4 10.69.255.246 (66) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: s=- (3) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: c=IN IP4 10.69.255.246 (22) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: t=0 0 (5) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: m=audio 5004 RTP/AVP 0 8 18 4 98 2 101 (38) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:98 g726-16/8000 (24) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=fmtp:101 0-15 (15) --- (13 headers 14 lines) --- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 Their Tag 100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 Our tag: as6dd400c9 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.69.255.246 : 5060 (NAT) Using INVITE request as basis request - 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:8747 check_user_full: Setting NAT on RTP to Off [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:8757 check_user_full: Setting NAT on UDPTL to Off Found user 'tulip2' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 98 Found RTP audio format 2 Found RTP audio format 101 Peer audio RTP is at port 10.69.255.246:5004 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4703 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format G723 for ID 4 Found description format g726-16 for ID 98 Found description format g726-32 for ID 2 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4914 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc), peer - audio=0x90d (g723|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x80c (ulaw|alaw|g726) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.69.255.246:5004 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4984 process_sdp: We're settling with these formats: 0x80c (ulaw|alaw|g726) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:12937 handle_request_invite: Checking SIP call limits for device tulip2 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:2889 update_call_counter: Updating call counter for incoming call Looking for 404 in from-sip (domain 10.69.255.251) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:3655 sip_new: *** Our native formats are 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:3656 sip_new: *** Joint capabilities are 0x80c (ulaw|alaw|g726) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:3657 sip_new: *** Our capabilities are 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:3658 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:3681 sip_new: This channel will not be able to handle video. [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:7678 build_route: build_route: Contact hop: list_route: hop: [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:13008 handle_request_invite: SIP/tulip2-09037fc8: New call is still down.... Trying... Transmitting (no NAT) to 10.69.255.246:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b758-176c3005-207a5f8e;received=10.69.255.246 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404" Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- [Oct 5 08:42:16] DEBUG[27364]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip2-09037fc8 [Oct 5 08:42:16] DEBUG[27336]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip2 [Oct 5 08:42:16] DEBUG[27336]: chan_sip.c:14719 sip_devicestate: Checking device state for peer tulip2 [Oct 5 08:42:16] DEBUG[27336]: devicestate.c:287 do_state_change: Changing state for SIP/tulip2 - state 1 (Not in use) [Oct 5 08:42:16] DEBUG[27417]: pbx.c:1681 pbx_extension_helper: Launching 'Macro' -- Executing [404@from-sip:1] Macro("SIP/tulip2-09037fc8", "ext|SIP/tulip4") in new stack [Oct 5 08:42:16] DEBUG[27417]: pbx.c:1681 pbx_extension_helper: Launching 'Dial' -- Executing [s@macro-ext:1] Dial("SIP/tulip2-09037fc8", "SIP/tulip4|15") in new stack [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:14777 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4158 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2518 create_addr_from_peer: Our T38 capability (3840) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2528 create_addr_from_peer: Setting NAT on RTP to Off [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2542 create_addr_from_peer: Setting NAT on UDPTL to Off [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3655 sip_new: *** Our native formats are 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3656 sip_new: *** Joint capabilities are 0x0 (nothing) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3657 sip_new: *** Our capabilities are 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3658 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3660 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:3681 sip_new: This channel will not be able to handle video. [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:16328 sip_set_rtp_peer: Early remote bridge setting SIP '6c0b910e51f363171c85480a5124af77@10.69.255.251' - Sending media to 10.69.255.246 [Oct 5 08:42:16] DEBUG[27417]: rtp.c:1572 ast_rtp_make_compatible: Seeded SDP of 'SIP/tulip4-09049900' with that of 'SIP/tulip2-09037fc8' [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable STACK-macro-ext-s-1. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable ARG1. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable STACK-from-sip-404-1. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Oct 5 08:42:16] DEBUG[27417]: channel.c:3135 ast_channel_inherit_variables: Not copying variable SIPURI. [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2729 sip_call: Outgoing Call for tulip4 [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2889 update_call_counter: Updating call counter for outgoing call [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:2737 sip_call: Our T38 capability (3840), joint T38 capability (3840) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:5893 add_sdp: ** Our capability: 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc) Video flag: False [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:5894 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 10.69.255.251 port 23736 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x800 (g726) to SDP Adding codec 0x400 (ilbc) to SDP Adding codec 0x80 (lpc10) to SDP Adding codec 0x200 (speex) to SDP Adding codec 0x20 (adpcm) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:6046 add_sdp: -- Done with adding codecs to SDP [Oct 5 08:42:16] DEBUG[27417]: channel.c:2216 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=23) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:6085 add_sdp: Done building SDP. Settling with this capability: 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 0: INVITE sip:tulip4@10.69.255.242:5060 SIP/2.0 (44) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 1: Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK55e8a7ab;rport (64) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 2: From: "Tulip ATA port 2" ;tag=as5686b73f (63) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 3: To: (35) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 4: Contact: (32) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 5: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 (55) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 6: CSeq: 102 INVITE (16) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 8: Max-Forwards: 70 (16) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 9: Date: Thu, 05 Oct 2006 07:42:16 GMT (35) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 11: Supported: replaces (19) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 12: Content-Type: application/sdp (29) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 13: Content-Length: 508 (19) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4378 parse_request: Header 14: (0) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: v=0 (3) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: o=root 27299 27299 IN IP4 10.69.255.246 (39) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: s=session (9) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: c=IN IP4 10.69.255.246 (22) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: t=0 0 (5) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: m=audio 5004 RTP/AVP 0 8 3 2 97 7 110 5 101 (43) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=fmtp:97 mode=30 (17) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:7 LPC/8000 (19) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:110 speex/8000 (23) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=ptime:20 (10) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=fmtp:101 0-16 (15) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=silenceSupp:off - - - - (25) [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:4410 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.69.255.242:5060: INVITE sip:tulip4@10.69.255.242:5060 SIP/2.0 Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK55e8a7ab;rport From: "Tulip ATA port 2" ;tag=as5686b73f To: Contact: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 05 Oct 2006 07:42:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 508 v=0 o=root 27299 27299 IN IP4 10.69.255.246 s=session c=IN IP4 10.69.255.246 t=0 0 m=audio 5004 RTP/AVP 0 8 3 2 97 7 110 5 101 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:2 G726-32/8000 a=ptime:20 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:7 LPC/8000 a=ptime:20 a=rtpmap:110 speex/8000 a=ptime:20 a=rtpmap:5 DVI4/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Oct 5 08:42:16] DEBUG[27417]: chan_sip.c:1915 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 -- Called tulip4 asterisk1*CLI> <-- SIP read from 10.69.255.242:5060: SIP/2.0 180 Ringing From: "Tulip ATA port 2";tag=as5686b73f To: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK55e8a7ab Supported: replaces Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL Contact: Content-Length: 0 [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: "Tulip ATA port 2";tag=as5686b73f (62) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 (89) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 (55) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 102 INVITE (16) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK55e8a7ab (69) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Supported: replaces (19) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Contact: (40) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Content-Length: 0 (17) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 Their Tag Our tag: as5686b73f [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:2056 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #33 - INVITE (got response) [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:2065 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6c0b910e51f363171c85480a5124af77@10.69.255.251' Request 102: Found [Oct 5 08:42:16] DEBUG[27364]: chan_sip.c:11286 handle_response_invite: SIP response 180 to standard invite [Oct 5 08:42:16] DEBUG[27364]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip4-09049900 -- SIP/tulip4-09049900 is ringing [Oct 5 08:42:16] DEBUG[27417]: rtp.c:1507 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/tulip2-09037fc8' with that of 'SIP/tulip4-09049900' Transmitting (no NAT) to 10.69.255.246:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b758-176c3005-207a5f8e;received=10.69.255.246 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404";tag=as1ffecd59 Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- [Oct 5 08:42:16] DEBUG[27336]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip4 [Oct 5 08:42:16] DEBUG[27336]: chan_sip.c:14719 sip_devicestate: Checking device state for peer tulip4 [Oct 5 08:42:16] DEBUG[27336]: devicestate.c:287 do_state_change: Changing state for SIP/tulip4 - state 1 (Not in use) asterisk1*CLI> <-- SIP read from 10.69.255.242:5060: SIP/2.0 200 OK From: "Tulip ATA port 2";tag=as5686b73f To: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK55e8a7ab Supported: replaces Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL Contact: Content-Type: application/sdp Content-Length: 211 v=0 o=rtp 1160034136540156000 1160034136540156000 IN IP4 10.69.255.242 s=- c=IN IP4 10.69.255.242 t=0 0 m=audio 5004 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: SIP/2.0 200 OK (14) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: "Tulip ATA port 2";tag=as5686b73f (62) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 (89) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 (55) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 102 INVITE (16) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK55e8a7ab (69) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Supported: replaces (19) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Contact: (40) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Content-Type: application/sdp (29) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: Content-Length: 211 (19) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 11: (0) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: v=0 (3) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: o=rtp 1160034136540156000 1160034136540156000 IN IP4 10.69.255.242 (66) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: s=- (3) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: c=IN IP4 10.69.255.242 (22) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: t=0 0 (5) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: m=audio 5004 RTP/AVP 0 101 (26) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines) --- [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 Their Tag 100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Our tag: as5686b73f [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:2005 __sip_ack: Acked pending invite 102 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:2023 __sip_ack: Stopping retransmission on '6c0b910e51f363171c85480a5124af77@10.69.255.251' of Request 102: Match Not Found [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:11286 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 10.69.255.242:5004 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4703 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4914 process_sdp: T38 state changed to 0 on channel SIP/tulip4-09049900 Capabilities: us - 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc), peer - audio=0x4 (ulaw)/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.69.255.242:5004 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4984 process_sdp: We're settling with these formats: 0x4 (ulaw) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4991 process_sdp: We have an owner, now see if we need to change this call [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:2889 update_call_counter: Updating call counter for outgoing call [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:7678 build_route: build_route: Contact hop: list_route: hop: [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:5415 reqprep: Strict routing enforced for session 6c0b910e51f363171c85480a5124af77@10.69.255.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.69.255.242, port 5060 Transmitting (no NAT) to 10.69.255.242:5060: ACK sip:tulip4@10.69.255.242:5060 SIP/2.0 Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK71cbccc4;rport From: "Tulip ATA port 2" ;tag=as5686b73f To: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Contact: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Oct 5 08:42:18] DEBUG[27417]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip4-09049900 -- SIP/tulip4-09049900 answered SIP/tulip2-09037fc8 [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:16328 sip_set_rtp_peer: Early remote bridge setting SIP '100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246' - Sending media to 10.69.255.242 [Oct 5 08:42:18] DEBUG[27417]: rtp.c:1507 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/tulip2-09037fc8' with that of 'SIP/tulip4-09049900' [Oct 5 08:42:18] DEBUG[27417]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip2-09037fc8 [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:3337 sip_answer: SIP answering channel: SIP/tulip2-09037fc8 [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:6140 transmit_response_with_sdp: Setting framing from config on incoming call [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:5893 add_sdp: ** Our capability: 0x80c (ulaw|alaw|g726) Video flag: True [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:5894 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.69.255.251 port 8320 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x800 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:6046 add_sdp: -- Done with adding codecs to SDP [Oct 5 08:42:18] DEBUG[27417]: channel.c:2216 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=19) [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:6085 add_sdp: Done building SDP. Settling with this capability: 0x80c (ulaw|alaw|g726) Reliably Transmitting (no NAT) to 10.69.255.246:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b758-176c3005-207a5f8e;received=10.69.255.246 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404";tag=as1ffecd59 Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 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: 316 v=0 o=root 27299 27299 IN IP4 10.69.255.242 s=session c=IN IP4 10.69.255.242 t=0 0 m=audio 5004 RTP/AVP 0 8 2 101 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:2 G726-32/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Oct 5 08:42:18] DEBUG[27417]: chan_sip.c:1915 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 -- Native bridging SIP/tulip2-09037fc8 and SIP/tulip4-09049900 [Oct 5 08:42:18] DEBUG[27336]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip4 [Oct 5 08:42:18] DEBUG[27336]: chan_sip.c:14719 sip_devicestate: Checking device state for peer tulip4 [Oct 5 08:42:18] DEBUG[27336]: devicestate.c:287 do_state_change: Changing state for SIP/tulip4 - state 1 (Not in use) [Oct 5 08:42:18] DEBUG[27336]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip2 [Oct 5 08:42:18] DEBUG[27336]: chan_sip.c:14719 sip_devicestate: Checking device state for peer tulip2 [Oct 5 08:42:18] DEBUG[27336]: devicestate.c:287 do_state_change: Changing state for SIP/tulip2 - state 1 (Not in use) asterisk1*CLI> <-- SIP read from 10.69.255.246:5060: ACK sip:404@10.69.255.251 SIP/2.0 From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 To: "404";tag=as1ffecd59 Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 CSeq: 2 ACK Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b75a-176c39ec-33ef32c8 Max-Forwards: 70 Contact: Proxy-Authorization: Digest username="tulip2",realm="inspiredbroadcast.net",nonce="2782b52f",uri="sip:404@10.69.255.251;transport=UDP",response="83333f5ebd4e7e80147faf75e99d9b36",algorithm=MD5 Content-Length: 0 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: ACK sip:404@10.69.255.251 SIP/2.0 (33) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: "Line 2";tag=100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 (94) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: "404";tag=as1ffecd59 (47) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 (72) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 2 ACK (11) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.246:5060;rport;branch=z9hG4bK-4524b75a-176c39ec-33ef32c8 (83) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Contact: (54) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Proxy-Authorization: Digest username="tulip2",realm="inspiredbroadcast.net",nonce="2782b52f",uri="sip:404@10.69.255.251;transport=UDP",response="83333f5ebd4e7e80147faf75e99d9b36",algorithm=MD5 (192) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Content-Length: 0 (17) [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4206 find_call: = No match Their Call ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 Their Tag 100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Our tag: as5686b73f [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246 Their Tag 100f43e8-f6ff450a-13c4-4524b757-5fda52f0-4524b757 Our tag: as1ffecd59 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received ACK (6) - Command in SIP ACK [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:2013 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 [Oct 5 08:42:18] DEBUG[27364]: chan_sip.c:2023 __sip_ack: Stopping retransmission on '100f72e8-f6ff450a-13c4-4524b757-7443f49c-4524b757@10.69.255.246' of Response 2: Match Not Found asterisk1*CLI> <-- SIP read from 10.69.255.242:5060: INVITE sip:402@10.69.255.251 SIP/2.0 From: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 To: "Tulip ATA port 2";tag=as5686b73f Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 1 INVITE Via: SIP/2.0/UDP 10.69.255.242:5060;rport;branch=z9hG4bK-4524b75c-176c4206-2bf6c567 Max-Forwards: 70 Supported: replaces Contact: Content-Type: application/sdp Content-Length: 294 v=0 o=rtp 1160034136540156000 160034136540156000 IN IP4 10.69.255.242 s=- c=IN IP4 10.69.255.242 t=0 0 m=image 5004 UDPTL t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxMaxBuffer:1024 a=T38FaxMaxDatagram:238 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: INVITE sip:402@10.69.255.251 SIP/2.0 (36) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 (91) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: "Tulip ATA port 2";tag=as5686b73f (60) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 (55) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 1 INVITE (14) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.242:5060;rport;branch=z9hG4bK-4524b75c-176c4206-2bf6c567 (83) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Supported: replaces (19) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Contact: (40) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: Content-Type: application/sdp (29) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 10: Content-Length: 294 (19) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 11: (0) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: v=0 (3) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: o=rtp 1160034136540156000 160034136540156000 IN IP4 10.69.255.242 (65) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: s=- (3) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: c=IN IP4 10.69.255.242 (22) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: t=0 0 (5) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: m=image 5004 UDPTL t38 (22) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38FaxVersion:0 (17) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38MaxBitRate:14400 (21) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38FaxMaxBuffer:1024 (22) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38FaxMaxDatagram:238 (23) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4410 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (11 headers 12 lines) --- [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 Their Tag 100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Our tag: as5686b73f [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:1624 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:1632 parse_sip_options: Found SIP option: -replaces- [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:1638 parse_sip_options: Matched SIP option: replaces Sending to 10.69.255.242 : 5060 (NAT) Got T.38 offer in SDP in dialog 6c0b910e51f363171c85480a5124af77@10.69.255.251 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4633 process_sdp: T38 state changed to 4 on channel SIP/tulip4-09049900 Peer doesn't provide audio [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4699 process_sdp: Peer T.38 UDPTL is at port 10.69.255.242:5004 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4846 process_sdp: FaxVersion: 0 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4822 process_sdp: T38MaxBitRate: 14400 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4818 process_sdp: MaxBufferSize:1024 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4854 process_sdp: FaxMaxDatagram: 238 [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4879 process_sdp: RateMangement: transferredTCF [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4887 process_sdp: UDP EC: t38UDPRedundancy [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:4907 process_sdp: Our T38 capability = (3840), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0xeae (gsm|ulaw|alaw|g726|adpcm|lpc10|speex|ilbc), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Oct 5 08:42:20] NOTICE[27364]: chan_sip.c:4942 process_sdp: No compatible codecs, not accepting this offer! Transmitting (NAT) to 10.69.255.242:5060: SIP/2.0 488 Not acceptable here Via: SIP/2.0/UDP 10.69.255.242:5060;branch=z9hG4bK-4524b75c-176c4206-2bf6c567;received=10.69.255.242;rport=5060 From: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 To: "Tulip ATA port 2";tag=as5686b73f Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 --- [Oct 5 08:42:20] DEBUG[27364]: chan_sip.c:14339 sipsock_read: SIP message could not be handled, bad request: 6c0b910e51f363171c85480a5124af77@10.69.255.251 asterisk1*CLI> <-- SIP read from 10.69.255.242:5060: ACK sip:402@10.69.255.251 SIP/2.0 From: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 To: "Tulip ATA port 2";tag=as5686b73f Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 CSeq: 1 ACK Via: SIP/2.0/UDP 10.69.255.242:5060;rport;branch=z9hG4bK-4524b75c-176c4206-2bf6c567 Max-Forwards: 70 Contact: Content-Length: 0 [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 0: ACK sip:402@10.69.255.251 SIP/2.0 (33) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 1: From: ;tag=100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 (91) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 2: To: "Tulip ATA port 2";tag=as5686b73f (60) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 3: Call-ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 (55) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 4: CSeq: 1 ACK (11) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.242:5060;rport;branch=z9hG4bK-4524b75c-176c4206-2bf6c567 (83) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 6: Max-Forwards: 70 (16) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 7: Contact: (40) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 8: Content-Length: 0 (17) [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4378 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:4206 find_call: = Found Their Call ID: 6c0b910e51f363171c85480a5124af77@10.69.255.251 Their Tag 100f43e8-f2ff450a-13c4-4524b758-3b07ce97-4524b758 Our tag: as5686b73f [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:14130 handle_request: **** Received ACK (6) - Command in SIP ACK [Oct 5 08:42:21] DEBUG[27364]: chan_sip.c:2023 __sip_ack: Stopping retransmission on '6c0b910e51f363171c85480a5124af77@10.69.255.251' of Response 1: Match Found asterisk1*CLI> exit Executing last minute cleanups Asterisk ending (0).