sip debug peer tulip3 SIP Debugging Enabled for IP: 10.69.255.230:5060 The 'sip debug' command is deprecated and will be removed in a future release. Please use 'sip set debug' instead. *CLI> [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: INVITE sip:403@10.69.255.251:5060;transport=UDP SIP/2.0 (55) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "tulip1";tag=100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 (94) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: "403" (37) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 (72) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 1 INVITE (14) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.229:5060;rport;branch=z9hG4bK-45cb4074-a1f3c878-5f4a57c0 (83) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Supported: replaces (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Contact: (54) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: Content-Type: application/sdp (29) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 11: Content-Length: 193 (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 12: (0) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: v=0 (3) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: o=rtp 1170948999 1170948999 IN IP4 10.69.255.229 (48) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: s=- (3) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: c=IN IP4 10.69.255.229 (22) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: t=0 0 (5) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: m=audio 5004 RTP/AVP 0 101 (26) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=fmtp:101 0-15 (15) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4358 find_call: = No match Their Call ID: 195c159e0e96715a788140bb20522d82@127.0.0.1 Their Tag 968ada9c3ffba887db8ff01d701887bd.6f43 Our tag: as0379966f [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4358 find_call: = No match Their Call ID: 55b95bb674fbc3ce6ec07fe54c9e6dd8@127.0.0.1 Their Tag 968ada9c3ffba887db8ff01d701887bd.ed4b Our tag: as069d2462 [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2576 do_setnat: Setting NAT on RTP to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2586 do_setnat: Setting NAT on UDPTL to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4307 sip_alloc: Allocating new SIP dialog for 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 - INVITE (With RTP) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:14582 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:1681 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:1689 parse_sip_options: Found SIP option: -replaces- [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:1695 parse_sip_options: Matched SIP option: replaces [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2576 do_setnat: Setting NAT on RTP to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2586 do_setnat: Setting NAT on UDPTL to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:1976 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #30 [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: ACK sip:403@10.69.255.251:5060;transport=UDP SIP/2.0 (52) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "tulip1";tag=100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 (94) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: "403";tag=as3a84f87b (52) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 (72) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 1 ACK (11) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.229:5060;rport;branch=z9hG4bK-45cb4074-a1f3c878-5f4a57c0 (83) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Contact: (54) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Content-Length: 0 (17) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: (0) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 Their Tag 100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 Our tag: as3a84f87b [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:14582 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2080 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #30 [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2090 __sip_ack: Stopping retransmission on '100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229' of Response 1: Match Not Found [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: INVITE sip:403@10.69.255.251:5060;transport=UDP SIP/2.0 (55) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "tulip1";tag=100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 (94) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: "403" (37) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 (72) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 2 INVITE (14) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.229:5060;rport;branch=z9hG4bK-45cb4074-a1f3c8b3-6481fd09 (83) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Supported: replaces (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Contact: (54) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: Proxy-Authorization: Digest username="tulip1",realm="inspiredbroadcast.net",nonce="62f71a8e",uri="sip:403@10.69.255.251:5060;transport=UDP",response="27eb4f4195ee9793c275b70ee07880a2",algorithm=MD5 (197) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 12: Content-Length: 193 (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 13: (0) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: v=0 (3) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: o=rtp 1170948999 1170948999 IN IP4 10.69.255.229 (48) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: s=- (3) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: c=IN IP4 10.69.255.229 (22) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: t=0 0 (5) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: m=audio 5004 RTP/AVP 0 101 (26) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=fmtp:101 0-15 (15) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 Their Tag 100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 Our tag: as3a84f87b [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:14582 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2576 do_setnat: Setting NAT on RTP to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2586 do_setnat: Setting NAT on UDPTL to Off [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:5113 process_sdp: T38 state changed to 0 on channel [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:5193 process_sdp: We're settling with these formats: 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:13370 handle_request_invite: Checking SIP call limits for device tulip1 [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3004 update_call_counter: Updating call counter for incoming call [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3810 sip_new: *** Our native formats are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3811 sip_new: *** Joint capabilities are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3812 sip_new: *** Our capabilities are 0xf8e (gsm|ulaw|alaw|g726|lpc10|g729|speex|ilbc) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3813 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:3836 sip_new: This channel will not be able to handle video. [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:7960 build_route: build_route: Contact hop: [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:13445 handle_request_invite: SIP/tulip1-09f192b0: New call is still down.... Trying... [Feb 8 15:25:27] DEBUG[15284]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip1-09f192b0 [Feb 8 15:25:27] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip1 [Feb 8 15:25:27] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip1 [Feb 8 15:25:27] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip1 - state 1 (Not in use) [Feb 8 15:25:27] DEBUG[15285]: pbx.c:1769 pbx_extension_helper: Launching 'Macro' -- Executing [403@from-sip:1] Macro("SIP/tulip1-09f192b0", "ext|SIP/tulip3") in new stack [Feb 8 15:25:27] DEBUG[15285]: pbx.c:1769 pbx_extension_helper: Launching 'Dial' -- Executing [s@macro-ext:1] Dial("SIP/tulip1-09f192b0", "SIP/tulip3|15") in new stack [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:15253 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4307 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:2622 create_addr_from_peer: Our T38 capability (3840) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:2576 do_setnat: Setting NAT on RTP to Off [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:2586 do_setnat: Setting NAT on UDPTL to Off [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3810 sip_new: *** Our native formats are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3811 sip_new: *** Joint capabilities are 0x0 (nothing) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3812 sip_new: *** Our capabilities are 0xf8e (gsm|ulaw|alaw|g726|lpc10|g729|speex|ilbc) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3813 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3815 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3836 sip_new: This channel will not be able to handle video. [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:16840 sip_set_rtp_peer: Early remote bridge setting SIP '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' - Sending media to 10.69.255.229 [Feb 8 15:25:27] DEBUG[15285]: rtp.c:1579 ast_rtp_make_compatible: Seeded SDP of 'SIP/tulip3-09f2bb78' with that of 'SIP/tulip1-09f192b0' [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable STACK-macro-ext-s-1. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable ARG1. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable STACK-from-sip-403-1. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Feb 8 15:25:27] DEBUG[15285]: channel.c:3294 ast_channel_inherit_variables: Not copying variable SIPURI. [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:2831 sip_call: Outgoing Call for tulip3 [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:3004 update_call_counter: Updating call counter for outgoing call [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:2846 sip_call: Our T38 capability (3840), joint T38 capability (3840) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:6185 add_sdp: ** Our capability: 0xc8e (gsm|ulaw|alaw|g726|lpc10|ilbc) Video flag: False [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:6186 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 10.69.255.251 port 5470 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 non-codec 0x1 (telephone-event) to SDP [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:6316 add_sdp: -- Done with adding codecs to SDP [Feb 8 15:25:27] DEBUG[15285]: channel.c:2374 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=22) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:6361 add_sdp: Done building SDP. Settling with this capability: 0xc8e (gsm|ulaw|alaw|g726|lpc10|ilbc) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 0: INVITE sip:tulip3@10.69.255.230:5060 SIP/2.0 (44) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 1: Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK3bf568fa;rport (64) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 2: From: "Tulip ATA port 1" ;tag=as169a0952 (63) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 3: To: (35) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 4: Contact: (32) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 5: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 (55) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 6: CSeq: 102 INVITE (16) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 9: Date: Thu, 08 Feb 2007 15:25:27 GMT (35) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 11: Supported: replaces (19) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 12: Content-Type: application/sdp (29) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 13: Content-Length: 387 (19) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4570 parse_request: Header 14: (0) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: v=0 (3) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: o=root 15265 15265 IN IP4 10.69.255.229 (39) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: s=session (9) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: c=IN IP4 10.69.255.229 (22) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: t=0 0 (5) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: m=audio 5004 RTP/AVP 0 8 3 111 97 7 101 (39) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:111 G726-32/8000 (25) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=fmtp:97 mode=30 (17) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:7 LPC/8000 (19) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=fmtp:101 0-16 (15) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=silenceSupp:off - - - - (25) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=ptime:20 (10) [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:4602 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.69.255.230:5060: INVITE sip:tulip3@10.69.255.230:5060 SIP/2.0 Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK3bf568fa;rport From: "Tulip ATA port 1" ;tag=as169a0952 To: Contact: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 08 Feb 2007 15:25:27 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 387 v=0 o=root 15265 15265 IN IP4 10.69.255.229 s=session c=IN IP4 10.69.255.229 t=0 0 m=audio 5004 RTP/AVP 0 8 3 111 97 7 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:7 LPC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Feb 8 15:25:27] DEBUG[15285]: chan_sip.c:1976 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #32 -- Called tulip3 <--- SIP read from 10.69.255.230:5060 ---> SIP/2.0 180 Ringing From: "Tulip ATA port 1";tag=as169a0952 To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK3bf568fa Supported: replaces Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL Contact: Content-Length: 0 <-------------> [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "Tulip ATA port 1";tag=as169a0952 (62) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 (89) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 (55) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 102 INVITE (16) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK3bf568fa (69) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Supported: replaces (19) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Contact: (40) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Content-Length: 0 (17) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 Their Tag Our tag: as169a0952 [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2123 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #32 - INVITE (got response) [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:2132 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' Request 102: Found [Feb 8 15:25:27] DEBUG[15284]: chan_sip.c:11617 handle_response_invite: SIP response 180 to standard invite [Feb 8 15:25:27] DEBUG[15284]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip3-09f2bb78 -- SIP/tulip3-09f2bb78 is ringing [Feb 8 15:25:27] DEBUG[15285]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/tulip1-09f192b0' with that of 'SIP/tulip3-09f2bb78' [Feb 8 15:25:27] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip3 [Feb 8 15:25:27] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip3 [Feb 8 15:25:27] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip3 - state 1 (Not in use) <--- SIP read from 10.69.255.230:5060 ---> SIP/2.0 200 OK From: "Tulip ATA port 1";tag=as169a0952 To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK3bf568fa Supported: replaces Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL Contact: Content-Type: application/sdp Content-Length: 196 v=0 o=rtp 1170948457 1170948457 IN IP4 10.69.255.230 s=- c=IN IP4 10.69.255.230 t=0 0 m=audio 5004 RTP/AVP 2 101 a=rtpmap:2 g726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "Tulip ATA port 1";tag=as169a0952 (62) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 (89) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 (55) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 102 INVITE (16) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK3bf568fa (69) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Supported: replaces (19) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Allow: INVITE, ACK, BYE, REFER, NOTIFY, CANCEL (46) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Contact: (40) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Content-Type: application/sdp (29) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: Content-Length: 196 (19) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 11: (0) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: v=0 (3) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: o=rtp 1170948457 1170948457 IN IP4 10.69.255.230 (48) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: s=- (3) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: c=IN IP4 10.69.255.230 (22) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: t=0 0 (5) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: m=audio 5004 RTP/AVP 2 101 (26) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4602 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines) --- [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 Their Tag 100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Our tag: as169a0952 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:2072 __sip_ack: Acked pending invite 102 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:2090 __sip_ack: Stopping retransmission on '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' of Request 102: Match Not Found [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:11617 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 2 Found RTP audio format 101 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4883 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.69.255.230:5004 Found description format g726-32 for ID 2 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:5113 process_sdp: T38 state changed to 0 on channel SIP/tulip3-09f2bb78 Capabilities: us - 0xf8e (gsm|ulaw|alaw|g726|lpc10|g729|speex|ilbc), peer - audio=0x800 (g726)/video=0x0 (nothing), combined - 0x800 (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.230:5004 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:5193 process_sdp: We're settling with these formats: 0x800 (g726) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:5200 process_sdp: We have an owner, now see if we need to change this call [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:5205 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x800 (g726) and not 0x4 (ulaw) [Feb 8 15:25:34] DEBUG[15284]: channel.c:2838 set_format: Set channel SIP/tulip3-09f2bb78 to read format ulaw [Feb 8 15:25:34] DEBUG[15284]: channel.c:2838 set_format: Set channel SIP/tulip3-09f2bb78 to write format ulaw [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:3004 update_call_counter: Updating call counter for outgoing call [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:7960 build_route: build_route: Contact hop: list_route: hop: [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:5630 reqprep: Strict routing enforced for session 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.69.255.230, port 5060 Transmitting (no NAT) to 10.69.255.230:5060: ACK sip:tulip3@10.69.255.230:5060 SIP/2.0 Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK6f22b2ec;rport From: "Tulip ATA port 1" ;tag=as169a0952 To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Contact: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 8 15:25:34] DEBUG[15285]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip3-09f2bb78 -- SIP/tulip3-09f2bb78 answered SIP/tulip1-09f192b0 [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:16840 sip_set_rtp_peer: Early remote bridge setting SIP '100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229' - Sending media to 10.69.255.230 [Feb 8 15:25:34] DEBUG[15285]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/tulip1-09f192b0' with that of 'SIP/tulip3-09f2bb78' [Feb 8 15:25:34] DEBUG[15285]: channel.c:2838 set_format: Set channel SIP/tulip1-09f192b0 to read format slin [Feb 8 15:25:34] DEBUG[15285]: channel.c:2838 set_format: Set channel SIP/tulip3-09f2bb78 to write format slin [Feb 8 15:25:34] DEBUG[15285]: channel.c:2838 set_format: Set channel SIP/tulip3-09f2bb78 to read format slin [Feb 8 15:25:34] DEBUG[15285]: channel.c:2838 set_format: Set channel SIP/tulip1-09f192b0 to write format slin [Feb 8 15:25:34] DEBUG[15285]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip1-09f192b0 [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:3457 sip_answer: SIP answering channel: SIP/tulip1-09f192b0 [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:3467 sip_answer: *** Peer native formats: 0x800 (g726) [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:3470 sip_answer: *** Our native formats: 0x4 (ulaw) [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:6419 transmit_response_with_sdp: Setting framing from config on incoming call [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:6185 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:6186 add_sdp: ** Our prefcodec: 0x0 (nothing) [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:6316 add_sdp: -- Done with adding codecs to SDP [Feb 8 15:25:34] DEBUG[15285]: channel.c:2374 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=18) [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:6361 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Feb 8 15:25:34] DEBUG[15285]: chan_sip.c:1976 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 [Feb 8 15:25:34] DEBUG[15285]: rtp.c:3244 ast_rtp_bridge: Channel codec0 = 4 is not codec1 = 2048, cannot native bridge in RTP. [Feb 8 15:25:34] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip3 [Feb 8 15:25:34] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip3 [Feb 8 15:25:34] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip3 - state 1 (Not in use) [Feb 8 15:25:34] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip1 [Feb 8 15:25:34] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip1 [Feb 8 15:25:34] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip1 - state 1 (Not in use) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: ACK sip:403@10.69.255.251 SIP/2.0 (33) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "tulip1";tag=100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 (94) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: "403";tag=as30791ce3 (52) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 (72) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 2 ACK (11) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.229:5060;rport;branch=z9hG4bK-45cb407b-a1f3e2ed-262de15e (83) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Contact: (54) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Proxy-Authorization: Digest username="tulip1",realm="inspiredbroadcast.net",nonce="62f71a8e",uri="sip:403@10.69.255.251:5060;transport=UDP",response="27eb4f4195ee9793c275b70ee07880a2",algorithm=MD5 (197) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Content-Length: 0 (17) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: (0) [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4358 find_call: = No match Their Call ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 Their Tag 100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Our tag: as169a0952 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 Their Tag 100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 Our tag: as30791ce3 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:14582 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:2080 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #34 [Feb 8 15:25:34] DEBUG[15284]: chan_sip.c:2090 __sip_ack: Stopping retransmission on '100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229' of Response 2: Match Not Found [Feb 8 15:25:45] DEBUG[15284]: chan_sip.c:2011 __sip_autodestruct: Auto destroying SIP dialog '55b95bb674fbc3ce6ec07fe54c9e6dd8@127.0.0.1' [Feb 8 15:25:45] DEBUG[15284]: chan_sip.c:3110 sip_destroy: Destroying SIP dialog 55b95bb674fbc3ce6ec07fe54c9e6dd8@127.0.0.1 Really destroying SIP dialog '55b95bb674fbc3ce6ec07fe54c9e6dd8@127.0.0.1' Method: REGISTER [Feb 8 15:25:45] DEBUG[15284]: chan_sip.c:2011 __sip_autodestruct: Auto destroying SIP dialog '195c159e0e96715a788140bb20522d82@127.0.0.1' [Feb 8 15:25:45] DEBUG[15284]: chan_sip.c:3110 sip_destroy: Destroying SIP dialog 195c159e0e96715a788140bb20522d82@127.0.0.1 Really destroying SIP dialog '195c159e0e96715a788140bb20522d82@127.0.0.1' Method: REGISTER [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: BYE sip:403@10.69.255.251 SIP/2.0 (33) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "tulip1";tag=100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 (94) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: "403";tag=as30791ce3 (52) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 (72) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 3 BYE (11) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.229:5060;rport;branch=z9hG4bK-45cb408a-a1f41ed4-4e9851bf (83) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Supported: replaces (19) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: Proxy-Authorization: Digest username="tulip1",realm="inspiredbroadcast.net",nonce="62f71a8e",uri="sip:403@10.69.255.251",response="f82bd4b244e0bdb9efc4e3edb98efcc1",algorithm=MD5 (178) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 9: Content-Length: 0 (17) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 10: (0) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4358 find_call: = No match Their Call ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 Their Tag 100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Our tag: as169a0952 [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 Their Tag 100c43a0-e5ff450a-13c4-45cb4074-363aa7b3-45cb4074 Our tag: as30791ce3 [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:14582 handle_request: **** Received BYE (8) - Command in SIP BYE [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:1634 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229 [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:14159 handle_request_bye: Received bye, issuing owner hangup [Feb 8 15:25:49] DEBUG[15285]: channel.c:3793 ast_generic_bridge: Didn't get a frame from channel: SIP/tulip1-09f192b0 [Feb 8 15:25:49] DEBUG[15285]: channel.c:4111 ast_channel_bridge: Bridge stops bridging channels SIP/tulip1-09f192b0 and SIP/tulip3-09f2bb78 [Feb 8 15:25:49] DEBUG[15285]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/tulip3-09f2bb78' [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3308 sip_hangup: Hangup call SIP/tulip3-09f2bb78, SIP callid 569fa61538d5e3e1631e85194238d3e2@10.69.255.251) [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3316 sip_hangup: update_call_counter(tulip3) - decrement call limit counter on hangup [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3004 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' in 32000 ms (Method: INVITE) [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:5630 reqprep: Strict routing enforced for session 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.69.255.230, port 5060 Reliably Transmitting (no NAT) to 10.69.255.230:5060: BYE sip:tulip3@10.69.255.230:5060 SIP/2.0 Via: SIP/2.0/UDP 10.69.255.251:5060;branch=z9hG4bK5a2d2f49;rport From: "Tulip ATA port 1" ;tag=as169a0952 To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:1976 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #36 [Feb 8 15:25:49] DEBUG[15285]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip3-09f2bb78 [Feb 8 15:25:49] DEBUG[15285]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Feb 8 15:25:49] DEBUG[15285]: app_dial.c:1650 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Feb 8 15:25:49] DEBUG[15285]: app_macro.c:261 _macro_exec: Spawn extension (macro-ext,s,1) exited non-zero on 'SIP/tulip1-09f192b0' in macro 'ext' [Feb 8 15:25:49] DEBUG[15285]: pbx.c:2367 __ast_pbx_run: Spawn extension (macro-ext,s,1) exited non-zero on 'SIP/tulip1-09f192b0' == Spawn extension (macro-ext, s, 1) exited non-zero on 'SIP/tulip1-09f192b0' [Feb 8 15:25:49] DEBUG[15285]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/tulip1-09f192b0' [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3308 sip_hangup: Hangup call SIP/tulip1-09f192b0, SIP callid 100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229) [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3316 sip_hangup: update_call_counter(tulip1) - decrement call limit counter on hangup [Feb 8 15:25:49] DEBUG[15285]: chan_sip.c:3004 update_call_counter: Updating call counter for incoming call [Feb 8 15:25:49] DEBUG[15285]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/tulip1-09f192b0 [Feb 8 15:25:49] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip3 [Feb 8 15:25:49] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip3 [Feb 8 15:25:49] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip3 - state 1 (Not in use) [Feb 8 15:25:49] DEBUG[15268]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - tulip1 [Feb 8 15:25:49] DEBUG[15268]: chan_sip.c:15187 sip_devicestate: Checking device state for peer tulip1 [Feb 8 15:25:49] DEBUG[15268]: devicestate.c:287 do_state_change: Changing state for SIP/tulip1 - state 1 (Not in use) <--- SIP read from 10.69.255.230:5060 ---> SIP/2.0 200 OK From: "Tulip ATA port 1";tag=as169a0952 To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 CSeq: 103 BYE Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK5a2d2f49 Supported: replaces Content-Length: 0 <-------------> [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 1: From: "Tulip ATA port 1";tag=as169a0952 (62) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 2: To: ;tag=100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 (89) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 3: Call-ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 (55) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 4: CSeq: 103 BYE (13) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 5: Via: SIP/2.0/UDP 10.69.255.251:5060;rport=5060;branch=z9hG4bK5a2d2f49 (69) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 6: Supported: replaces (19) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 7: Content-Length: 0 (17) [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4570 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:4358 find_call: = Found Their Call ID: 569fa61538d5e3e1631e85194238d3e2@10.69.255.251 Their Tag 100c30d8-e6ff450a-13c4-45cb4075-1730a57a-45cb4075 Our tag: as169a0952 [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:2080 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #36 [Feb 8 15:25:49] DEBUG[15284]: chan_sip.c:2090 __sip_ack: Stopping retransmission on '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' of Request 103: Match Not Found Really destroying SIP dialog '569fa61538d5e3e1631e85194238d3e2@10.69.255.251' Method: INVITE Really destroying SIP dialog '100c61a0-e5ff450a-13c4-45cb4074-2366cc02-45cb4074@10.69.255.229' Method: BYE Beginning asterisk shutdown.... Executing last minute cleanups == Destroying musiconhold processes Asterisk cleanly ending (2). [Feb 8 15:26:00] DEBUG[15265]: asterisk.c:1192 quit_handler: Asterisk ending (2). ]0;root@asterisk1:~/src[root@asterisk1 src]# Script done on Thu 08 Feb 2007 15:26:01 GMT