centrala:~/asterisk-1.4/asterisk-1.4.0# asterisk -r Asterisk 1.4.0, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'core show license' for details. ========================================================================= Connected to Asterisk 1.4.0 currently running on centrala (pid = 7401) centrala*CLI> set debug 4 Core debug was 0 and is now 4 The 'set debug' command is deprecated and will be removed in a future release. Please use 'core set debug' instead. centrala*CLI> set verbose 4 Verbosity was 0 and is now 4 The 'set verbose' command is deprecated and will be removed in a future release. Please use 'core set verbose' instead. centrala*CLI> sip debug SIP Debugging enabled The 'sip debug' command is deprecated and will be removed in a future release. Please use 'sip set debug' instead. [Feb 6 09:27:44] DEBUG[7427]: chan_sip.c:1992 __sip_autodestruct: Auto destroying SIP dialog '193732388862200782741@10.10.162.2' [Feb 6 09:27:44] DEBUG[7427]: chan_sip.c:3080 sip_destroy: Destroying SIP dialog 193732388862200782741@10.10.162.2 Really destroying SIP dialog '193732388862200782741@10.10.162.2' Method: OPTIONS centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> OPTIONS sip:9974@10.10.162.2 SIP/2.0 Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2087516688 Max-Forwards: 70 From: ;tag=1c2087513466 To: Call-ID: 208751213962200782841@10.10.162.2 CSeq: 1 OPTIONS Contact: Supported: em,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Content-Length: 0 <-------------> [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: OPTIONS sip:9974@10.10.162.2 SIP/2.0 (41) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2087516688 (55) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: Max-Forwards: 70 (16) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=1c2087513466 (50) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: To: (30) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 208751213962200782841@10.10.162.2 (42) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 OPTIONS (15) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Contact: (36) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Supported: em,timer,replaces,path (33) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (61) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Length: 0 (17) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 208751213962200782841@10.10.162.2 - OPTIONS (No RTP) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS Looking for 9974 in default (domain 10.10.162.2) <--- Transmitting (no NAT) to 10.10.162.2:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2087516688;received=10.10.162.2 From: ;tag=1c2087513466 To: ;tag=as6a14a035 Call-ID: 208751213962200782841@10.10.162.2 CSeq: 1 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Accept: application/sdp Content-Length: 0 <------------> Scheduling destruction of SIP dialog '208751213962200782841@10.10.162.2' in 32000 ms (Method: OPTIONS) [Feb 6 09:28:12] DEBUG[7427]: chan_sip.c:14664 sipsock_read: SIP message could not be handled, bad request: 208751213962200782841@10.10.162.2 centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> INVITE sip:8367@10.10.119.251;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2120089328 Max-Forwards: 70 From: ;tag=1c2120086823 To: Call-ID: 212008637362200782854@10.10.162.2 CSeq: 1 INVITE Contact: Supported: em,100rel,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Content-Type: application/sdp Content-Length: 278 v=0 o=AudiocodesGW 2120080789 2120080665 IN IP4 10.10.162.2 s=Phone-Call c=IN IP4 10.10.162.2 t=0 0 m=audio 6000 RTP/AVP 8 18 101 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:8367@10.10.119.251;user=phone SIP/2.0 (56) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2120089328 (55) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: Max-Forwards: 70 (16) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=1c2120086823 (49) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: To: (47) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 212008637362200782854@10.10.162.2 (42) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 INVITE (14) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Contact: (36) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Supported: em,100rel,timer,replaces,path (40) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (61) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Length: 278 (19) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: (0) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=AudiocodesGW 2120080789 2120080665 IN IP4 10.10.162.2 (55) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=Phone-Call (12) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.162.2 (20) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=audio 6000 RTP/AVP 8 18 101 (29) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=fmtp:18 annexb=no (19) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=fmtp:101 0-15 (15) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) --- (13 headers 13 lines) --- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to Off [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 212008637362200782854@10.10.162.2 - INVITE (With RTP) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: em,100rel,timer,replaces,path" [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -em- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1684 parse_sip_options: Found no match for SIP option: em (Please file bug report!) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -100rel- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: 100rel [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -timer- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: timer [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -replaces- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: replaces [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -path- [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: path Sending to 10.10.162.2 : 5060 (no NAT) Using INVITE request as basis request - 212008637362200782854@10.10.162.2 [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On Found user '9973' Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:4838 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.162.2:6000 Found description format PCMA for ID 8 Found description format G729 for ID 18 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x100 (g729), peer - audio=0x108 (alaw|g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.10.162.2:6000 [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x100 (g729) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:13237 handle_request_invite: Checking SIP call limits for device 9973 [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Looking for 8367 in test_1 (domain 10.10.119.251) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x100 (g729) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x100 (g729) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:7891 build_route: build_route: Contact hop: list_route: hop: [Feb 6 09:28:25] DEBUG[7427]: chan_sip.c:13310 handle_request_invite: SIP/9973-081c9630: New call is still down.... Trying... <--- Transmitting (NAT) to 10.10.162.2:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2120089328;received=10.10.162.2 From: ;tag=1c2120086823 To: Call-ID: 212008637362200782854@10.10.162.2 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 6 09:28:25] DEBUG[7427]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9973-081c9630 [Feb 6 09:28:25] DEBUG[7407]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9973 [Feb 6 09:28:25] DEBUG[7407]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 9973 [Feb 6 09:28:25] DEBUG[7407]: devicestate.c:287 do_state_change: Changing state for SIP/9973 - state 1 (Not in use) [Feb 6 09:28:25] DEBUG[7443]: app_queue.c:546 changethread: Device 'SIP/9973' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 6 09:28:25] DEBUG[7444]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' -- Executing [8367@test_1:1] Dial("SIP/9973-081c9630", "SIP/10.10.119.225/8367|300|rtT") in new stack [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:15106 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Feb 6 09:28:25] DEBUG[7444]: frame.c:1252 ast_codec_choose: Could not find preferred codec - Going for the best codec [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3766 sip_new: *** Our native formats are 0x4 (ulaw) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x0 (nothing) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [Feb 6 09:28:25] DEBUG[7444]: frame.c:1252 ast_codec_choose: Could not find preferred codec - Going for the best codec [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3771 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Feb 6 09:28:25] DEBUG[7444]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-test_1-8367-1. [Feb 6 09:28:25] DEBUG[7444]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Feb 6 09:28:25] DEBUG[7444]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Feb 6 09:28:25] DEBUG[7444]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Feb 6 09:28:25] DEBUG[7444]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:2812 sip_call: Outgoing Call for 8367 [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:2826 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:6122 add_sdp: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:6123 add_sdp: ** Our prefcodec: 0x100 (g729) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:6140 add_sdp: This call needs video offers, but there's no video support enabled! Audio is at 10.10.119.251 port 19890 Adding codec 0x2 (gsm) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:6254 add_sdp: -- Done with adding codecs to SDP [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:6299 add_sdp: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:8367@10.10.119.225 SIP/2.0 (45) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport (66) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 3: To: (36) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 4: Contact: (40) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 6: CSeq: 102 INVITE (16) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 9: Date: Tue, 06 Feb 2007 08:28:25 GMT (35) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 11: Supported: replaces (19) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 12: Content-Type: application/sdp (29) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 291 (19) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4527 parse_request: Header 14: (0) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: o=root 7444 7444 IN IP4 10.10.119.251 (39) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: s=session (9) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.251 (24) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: m=audio 19890 RTP/AVP 3 0 8 101 (31) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=fmtp:101 0-16 (15) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=silenceSupp:off - - - - (25) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:4559 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:8367@10.10.119.225 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport From: "9973" ;tag=as3035f116 To: Contact: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 06 Feb 2007 08:28:25 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 291 v=0 o=root 7444 7444 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 19890 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Feb 6 09:28:25] DEBUG[7444]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #13 -- Called 10.10.119.225/8367 <--- Transmitting (NAT) to 10.10.162.2:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2120089328;received=10.10.162.2 From: ;tag=1c2120086823 To: ;tag=as3e892e58 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Date: Tue, 06 Feb 2007 08:28:57 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 100 Trying (18) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport (66) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=33673B34-17B0 (54) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:28:57 GMT (35) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 102 INVITE (16) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Allow-Events: telephone-event (29) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Content-Length: 0 (17) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #13 - INVITE (got response) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0320f129114360872611436b2127a4d6@10.10.119.251' Request 102: Found [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:11531 handle_response_invite: SIP response 100 to standard invite centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Date: Tue, 06 Feb 2007 08:28:57 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 18404 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport (66) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=33673B34-17B0 (54) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:28:57 GMT (35) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 102 INVITE (16) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow-Events: telephone-event (29) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Contact: (46) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 200 (19) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: (0) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 (63) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=audio 18404 RTP/AVP 8 (23) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0320f129114360872611436b2127a4d6@10.10.119.251' Request 102: Found [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:11531 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4838 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:18404 Found description format PCMA for ID 8 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081db2d0 Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:18404 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x8 (alaw) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5152 process_sdp: We have an owner, now see if we need to change this call [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5157 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x8 (alaw) and not 0x4 (ulaw) [Feb 6 09:28:26] DEBUG[7427]: frame.c:1252 ast_codec_choose: Could not find preferred codec - Going for the best codec [Feb 6 09:28:26] DEBUG[7427]: channel.c:2731 set_format: Set channel SIP/10.10.119.225-081db2d0 to read format ulaw [Feb 6 09:28:26] DEBUG[7427]: channel.c:2731 set_format: Set channel SIP/10.10.119.225-081db2d0 to write format ulaw -- SIP/10.10.119.225-081db2d0 is making progress passing it to SIP/9973-081c9630 centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Date: Tue, 06 Feb 2007 08:28:57 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 18404 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport (66) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=33673B34-17B0 (54) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:28:57 GMT (35) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 102 INVITE (16) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow-Events: telephone-event (29) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Contact: (46) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 200 (19) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: (0) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 (63) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=audio 18404 RTP/AVP 8 (23) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0320f129114360872611436b2127a4d6@10.10.119.251' Request 102: Found [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:11531 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:4838 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:18404 Found description format PCMA for ID 8 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081db2d0 Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:18404 [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x8 (alaw) [Feb 6 09:28:26] DEBUG[7427]: chan_sip.c:5152 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081db2d0 is making progress passing it to SIP/9973-081c9630 centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Date: Tue, 06 Feb 2007 08:28:57 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 18404 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56d11913;rport (66) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=33673B34-17B0 (54) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:28:57 GMT (35) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 102 INVITE (16) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow-Events: telephone-event (29) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Contact: (46) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Type: application/sdp (29) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 200 (19) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: (0) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7452 IN IP4 10.10.119.225 (63) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=audio 18404 RTP/AVP 8 (23) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0320f129114360872611436b2127a4d6@10.10.119.251' of Request 102: Match Not Found [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:11531 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4838 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:18404 Found description format PCMA for ID 8 [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:5068 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081db2d0 Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:18404 [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:5145 process_sdp: We're settling with these formats: 0x8 (alaw) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:5152 process_sdp: We have an owner, now see if we need to change this call [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:7891 build_route: build_route: Contact hop: list_route: hop: [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:5576 reqprep: Strict routing enforced for session 0320f129114360872611436b2127a4d6@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 Transmitting (no NAT) to 10.10.119.225:5060: ACK sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK61a0299d;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Contact: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 6 09:28:28] DEBUG[7444]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081db2d0 [Feb 6 09:28:28] DEBUG[7407]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Feb 6 09:28:28] DEBUG[7407]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 10.10.119.225 [Feb 6 09:28:28] DEBUG[7407]: channel.c:943 channel_find_locked: Avoiding initial deadlock for channel '0x81ecc40' -- SIP/10.10.119.225-081db2d0 answered SIP/9973-081c9630 [Feb 6 09:28:28] DEBUG[7444]: channel.c:2731 set_format: Set channel SIP/9973-081c9630 to read format slin [Feb 6 09:28:28] DEBUG[7444]: channel.c:2731 set_format: Set channel SIP/10.10.119.225-081db2d0 to write format slin [Feb 6 09:28:28] DEBUG[7444]: channel.c:2731 set_format: Set channel SIP/10.10.119.225-081db2d0 to read format slin [Feb 6 09:28:28] DEBUG[7444]: channel.c:2731 set_format: Set channel SIP/9973-081c9630 to write format slin [Feb 6 09:28:28] DEBUG[7444]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9973-081c9630 [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:3428 sip_answer: SIP answering channel: SIP/9973-081c9630 [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:6354 transmit_response_with_sdp: Setting framing from config on incoming call [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:6122 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:6123 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.10.119.251 port 14790 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:6254 add_sdp: -- Done with adding codecs to SDP [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:6299 add_sdp: Done building SDP. Settling with this capability: 0x100 (g729) <--- Reliably Transmitting (NAT) to 10.10.162.2:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2120089328;received=10.10.162.2 From: ;tag=1c2120086823 To: ;tag=as3e892e58 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 7444 7444 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 14790 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Feb 6 09:28:28] DEBUG[7444]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #16 [Feb 6 09:28:28] DEBUG[7407]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 2 (In use) [Feb 6 09:28:28] DEBUG[7446]: app_queue.c:546 changethread: Device 'SIP/10.10.119.225' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 6 09:28:28] DEBUG[7444]: rtp.c:2647 ast_rtp_write: Ooh, format changed from unknown to g729 [Feb 6 09:28:28] DEBUG[7444]: rtp.c:2664 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Feb 6 09:28:28] DEBUG[7407]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9973 [Feb 6 09:28:28] DEBUG[7407]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 9973 [Feb 6 09:28:28] DEBUG[7407]: devicestate.c:287 do_state_change: Changing state for SIP/9973 - state 1 (Not in use) [Feb 6 09:28:28] DEBUG[7447]: app_queue.c:546 changethread: Device 'SIP/9973' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> ACK sip:8367@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2125914583 Max-Forwards: 70 From: ;tag=1c2120086823 To: ;tag=as3e892e58 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 1 ACK Contact: Supported: em,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Content-Length: 0 <-------------> [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: ACK sip:8367@10.10.119.251 SIP/2.0 (42) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac2125914583 (55) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: Max-Forwards: 70 (16) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=1c2120086823 (49) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: To: ;tag=as3e892e58 (62) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 212008637362200782854@10.10.162.2 (42) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 ACK (11) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Contact: (36) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Supported: em,timer,replaces,path (33) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (61) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Length: 0 (17) [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #16 [Feb 6 09:28:28] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '212008637362200782854@10.10.162.2' of Response 1: Match Not Found [Feb 6 09:28:28] DEBUG[7444]: rtp.c:2647 ast_rtp_write: Ooh, format changed from unknown to alaw [Feb 6 09:28:28] DEBUG[7444]: rtp.c:2664 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Feb 6 09:28:28] DEBUG[7444]: rtp.c:862 ast_rtcp_read: Got RTCP report of 68 bytes [Feb 6 09:28:28] DEBUG[7444]: rtp.c:862 ast_rtcp_read: Got RTCP report of 136 bytes [Feb 6 09:28:30] DEBUG[7444]: rtp.c:862 ast_rtcp_read: Got RTCP report of 136 bytes centrala*CLI> <--- SIP read from 10.10.119.225:53942 ---> INVITE sip:9973@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Date: Tue, 06 Feb 2007 08:29:05 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1170750545 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 405 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7453 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=image 18404 udptl t38 c=IN IP4 10.10.119.225 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:9973@10.10.119.251:5060 SIP/2.0 (49) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 (60) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=33673B34-17B0 (56) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: "9973" ;tag=as3035f116 (62) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:05 GMT (35) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Supported: 100rel,timer,resource-priority,replaces (50) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Min-SE: 1800 (13) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 (55) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: CSeq: 101 INVITE (16) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Max-Forwards: 70 (16) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Timestamp: 1170750545 (21) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: Contact: (46) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 15: Expires: 180 (12) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 16: Allow-Events: telephone-event (29) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 17: Content-Type: application/sdp (29) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 18: Content-Length: 405 (19) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 19: (0) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7453 IN IP4 10.10.119.225 (63) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=image 18404 udptl t38 (23) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxVersion:0 (17) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38MaxBitRate:14400 (21) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (19 headers 16 lines) --- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,resource-priority,replaces" [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -100rel- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: 100rel [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -timer- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: timer [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -resource-priority- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: resource-priority [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1670 parse_sip_options: Found SIP option: -replaces- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1676 parse_sip_options: Matched SIP option: replaces Sending to 10.10.119.225 : 5060 (no NAT) Got T.38 offer in SDP in dialog 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4784 process_sdp: T38 state changed to 4 on channel SIP/10.10.119.225-081db2d0 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4834 process_sdp: Peer T.38 UDPTL is at port 10.10.119.225:18404 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5000 process_sdp: FaxVersion: 0 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4976 process_sdp: T38MaxBitRate: 14400 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5014 process_sdp: FillBitRemoval: 0 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5020 process_sdp: Transcoding MMR: 0 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5027 process_sdp: Transcoding JBIG: 0 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5033 process_sdp: RateMangement: transferredTCF [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4972 process_sdp: MaxBufferSize:200 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5008 process_sdp: FaxMaxDatagram: 72 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5041 process_sdp: UDP EC: t38UDPRedundancy [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5061 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5103 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:13288 handle_request_invite: Got a SIP re-invite for call 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:13383 handle_request_invite: SIP/10.10.119.225-081db2d0: This call is UP.... [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:16560 sip_handle_t38_reinvite: Sending reinvite on SIP '212008637362200782854@10.10.162.2' - It's UDPTL soon redirected to us (IP 10.10.119.251) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5576 reqprep: Strict routing enforced for session 212008637362200782854@10.10.162.2 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.162.2, port 5060 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5975 add_t38_sdp: T.38 UDPTL is at 10.10.119.251 port 4648 [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5981 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:5908 t38_get_rate: T38MaxFaxRate 9600 found [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1603 initialize_initreq: Initializing already initialized SIP dialog 212008637362200782854@10.10.162.2 (presumably reinvite) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:9973@10.10.162.2 SIP/2.0 (40) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK699989ae;rport (66) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=as3e892e58 (64) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=1c2120086823 (47) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Contact: (41) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 212008637362200782854@10.10.162.2 (42) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 102 INVITE (16) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Supported: replaces (19) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Type: application/sdp (29) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Content-Length: 261 (19) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: (0) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=root 7444 7445 IN IP4 10.10.119.251 (39) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=session (9) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.251 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=image 4648 udptl t38 (22) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxVersion:0 (17) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38MaxBitRate:9600 (20) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) Reliably Transmitting (NAT) to 10.10.162.2:5060: INVITE sip:9973@10.10.162.2 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK699989ae;rport From: ;tag=as3e892e58 To: ;tag=1c2120086823 Contact: Call-ID: 212008637362200782854@10.10.162.2 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-info: SIP re-invite (T38 switchover) Content-Type: application/sdp Content-Length: 261 v=0 o=root 7444 7445 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=image 4648 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:72 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy --- [Feb 6 09:28:33] DEBUG[7427]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> SIP/2.0 415 Unsupported Media Type Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK699989ae;rport From: ;tag=as3e892e58 To: ;tag=1c2120086823 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 102 INVITE Contact: Supported: em,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Content-Length: 0 <-------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 415 Unsupported Media Type (34) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK699989ae;rport (66) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=as3e892e58 (64) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=1c2120086823 (47) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Call-ID: 212008637362200782854@10.10.162.2 (42) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Contact: (36) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Supported: em,timer,replaces,path (33) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Server: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (57) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Content-Length: 0 (17) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18 [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '212008637362200782854@10.10.162.2' of Request 102: Match Not Found -- Got SIP response 415 "Unsupported Media Type" back from 10.10.162.2 [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:5576 reqprep: Strict routing enforced for session 212008637362200782854@10.10.162.2 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.162.2, port 5060 Transmitting (NAT) to 10.10.162.2:5060: ACK sip:9973@10.10.162.2 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK699989ae;rport From: ;tag=as3e892e58 To: ;tag=1c2120086823 Contact: Call-ID: 212008637362200782854@10.10.162.2 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:1615 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 212008637362200782854@10.10.162.2 [Feb 6 09:28:34] DEBUG[7444]: channel.c:3682 ast_generic_bridge: Didn't get a frame from channel: SIP/9973-081c9630 [Feb 6 09:28:34] DEBUG[7444]: channel.c:3990 ast_channel_bridge: Bridge stops bridging channels SIP/9973-081c9630 and SIP/10.10.119.225-081db2d0 [Feb 6 09:28:34] DEBUG[7444]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/10.10.119.225-081db2d0' [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:3278 sip_hangup: Hangup call SIP/10.10.119.225-081db2d0, SIP callid 0320f129114360872611436b2127a4d6@10.10.119.251) [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:3286 sip_hangup: update_call_counter(8367) - decrement call limit counter on hangup [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Scheduling destruction of SIP dialog '0320f129114360872611436b2127a4d6@10.10.119.251' in 32000 ms (Method: INVITE) [Feb 6 09:28:34] DEBUG[7444]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081db2d0 [Feb 6 09:28:34] DEBUG[7407]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Feb 6 09:28:34] DEBUG[7407]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 10.10.119.225 [Feb 6 09:28:34] DEBUG[7407]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 1 (Not in use) [Feb 6 09:28:34] DEBUG[7448]: app_queue.c:546 changethread: Device 'SIP/10.10.119.225' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 6 09:28:34] DEBUG[7444]: rtp.c:1465 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Feb 6 09:28:34] DEBUG[7444]: app_dial.c:1643 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Feb 6 09:28:34] DEBUG[7444]: pbx.c:2363 __ast_pbx_run: Spawn extension (test_1,8367,1) exited non-zero on 'SIP/9973-081c9630' == Spawn extension (test_1, 8367, 1) exited non-zero on 'SIP/9973-081c9630' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9973' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9973' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '8367' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'test_1' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/9973-081c9630' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225-081db2d0' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225/8367|300|rtT' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2007-02-06 09:28:25' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2007-02-06 09:28:28' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2007-02-06 09:28:34' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '6' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1170750505.0' [Feb 6 09:28:34] DEBUG[7444]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Feb 6 09:28:34] DEBUG[7444]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/9973-081c9630' [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:3278 sip_hangup: Hangup call SIP/9973-081c9630, SIP callid 212008637362200782854@10.10.162.2) [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:3286 sip_hangup: update_call_counter(9973) - decrement call limit counter on hangup [Feb 6 09:28:34] DEBUG[7444]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Feb 6 09:28:34] DEBUG[7444]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9973-081c9630 [Feb 6 09:28:34] DEBUG[7407]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9973 [Feb 6 09:28:34] DEBUG[7407]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 9973 [Feb 6 09:28:34] DEBUG[7407]: devicestate.c:287 do_state_change: Changing state for SIP/9973 - state 1 (Not in use) [Feb 6 09:28:34] DEBUG[7449]: app_queue.c:546 changethread: Device 'SIP/9973' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. centrala*CLI> <--- SIP read from 10.10.119.225:53942 ---> INVITE sip:9973@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Date: Tue, 06 Feb 2007 08:29:05 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1170750545 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 405 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7453 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=image 18404 udptl t38 c=IN IP4 10.10.119.225 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:9973@10.10.119.251:5060 SIP/2.0 (49) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 (60) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=33673B34-17B0 (56) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: "9973" ;tag=as3035f116 (62) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:05 GMT (35) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Supported: 100rel,timer,resource-priority,replaces (50) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Min-SE: 1800 (13) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 (55) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: CSeq: 101 INVITE (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Max-Forwards: 70 (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Timestamp: 1170750545 (21) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: Contact: (46) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 15: Expires: 180 (12) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 16: Allow-Events: telephone-event (29) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 17: Content-Type: application/sdp (29) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 18: Content-Length: 405 (19) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 19: (0) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7453 IN IP4 10.10.119.225 (63) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=image 18404 udptl t38 (23) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxVersion:0 (17) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38MaxBitRate:14400 (21) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (19 headers 16 lines) --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:14472 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:13290 handle_request_invite: Got a SIP re-transmit of INVITE for call 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:34] NOTICE[7427]: chan_sip.c:13479 handle_request_invite: Unable to create/find SIP channel for this INVITE <--- Transmitting (no NAT) to 10.10.119.225:5060 ---> SIP/2.0 503 Unavailable Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2;received=10.10.119.225 From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> Scheduling destruction of SIP dialog '0320f129114360872611436b2127a4d6@10.10.119.251' in 32000 ms (Method: INVITE) Really destroying SIP dialog '212008637362200782854@10.10.162.2' Method: ACK centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> ACK sip:9973@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Date: Tue, 06 Feb 2007 08:29:05 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Max-Forwards: 70 CSeq: 101 ACK Content-Length: 0 <-------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: ACK sip:9973@10.10.119.251:5060 SIP/2.0 (46) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C7DF2 (60) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=33673B34-17B0 (56) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: "9973" ;tag=as3035f116 (62) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:05 GMT (35) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 101 ACK (13) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Content-Length: 0 (17) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0320f129114360872611436b2127a4d6@10.10.119.251' of Response 101: Match Found [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:5576 reqprep: Strict routing enforced for session 0320f129114360872611436b2127a4d6@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 Reliably Transmitting (no NAT) to 10.10.119.225:5060: BYE sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK1e70e742;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21 Scheduling destruction of SIP dialog '0320f129114360872611436b2127a4d6@10.10.119.251' in 32000 ms (Method: ACK) <--- SIP read from 10.10.119.225:53942 ---> INVITE sip:9973@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C85EA From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Date: Tue, 06 Feb 2007 08:29:05 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 102 INVITE Max-Forwards: 70 Timestamp: 1170750545 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 189 v=0 o=CiscoSystemsSIP-GW-UserAgent 2601 7454 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 18404 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - <-------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: INVITE sip:9973@10.10.119.251:5060 SIP/2.0 (49) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C85EA (60) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=33673B34-17B0 (56) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: "9973" ;tag=as3035f116 (62) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:05 GMT (35) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Supported: 100rel,timer,resource-priority,replaces (50) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Min-SE: 1800 (13) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Cisco-Guid: 3961082906-3035763163-2822022566-4050708206 (55) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: CSeq: 102 INVITE (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Max-Forwards: 70 (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: Timestamp: 1170750545 (21) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 14: Contact: (46) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 15: Expires: 180 (12) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 16: Allow-Events: telephone-event (29) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 17: Content-Type: application/sdp (29) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 18: Content-Length: 189 (19) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 19: (0) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: v=0 (3) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 2601 7454 IN IP4 10.10.119.225 (63) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: s=SIP Call (10) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: t=0 0 (5) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: m=audio 18404 RTP/AVP 8 (23) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4559 parse_request: Line: a=silenceSupp:off - - - - (25) --- (19 headers 8 lines) --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.10.119.225 : 5060 (no NAT) Using INVITE request as basis request - 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:13288 handle_request_invite: Got a SIP re-invite for call 0320f129114360872611436b2127a4d6@10.10.119.251 [Feb 6 09:28:34] NOTICE[7427]: chan_sip.c:13479 handle_request_invite: Unable to create/find SIP channel for this INVITE <--- Reliably Transmitting (no NAT) to 10.10.119.225:5060 ---> SIP/2.0 503 Unavailable Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C85EA;received=10.10.119.225 From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #23 Scheduling destruction of SIP dialog '0320f129114360872611436b2127a4d6@10.10.119.251' in 32000 ms (Method: INVITE) centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> ACK sip:9973@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C85EA From: ;tag=33673B34-17B0 To: "9973" ;tag=as3035f116 Date: Tue, 06 Feb 2007 08:29:05 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Max-Forwards: 70 CSeq: 102 ACK Content-Length: 0 <-------------> [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: ACK sip:9973@10.10.119.251:5060 SIP/2.0 (46) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK134C85EA (60) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: ;tag=33673B34-17B0 (56) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: "9973" ;tag=as3035f116 (62) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:05 GMT (35) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Max-Forwards: 70 (16) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 102 ACK (13) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Content-Length: 0 (17) [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #23 [Feb 6 09:28:34] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0320f129114360872611436b2127a4d6@10.10.119.251' of Response 102: Match Not Found [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:1848 retrans_pkt: SIP TIMER: Rescheduling retransmission #21 (1) BYE - 8 [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:1862 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #21)) Retransmitting #1 (no NAT) to 10.10.119.225:5060: BYE sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK1e70e742;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK1e70e742;rport From: "9973" ;tag=as3035f116 To: ;tag=33673B34-17B0 Date: Tue, 06 Feb 2007 08:29:06 GMT Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 103 BYE Content-Length: 0 <-------------> [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK1e70e742;rport (66) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: From: "9973" ;tag=as3035f116 (64) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: To: ;tag=33673B34-17B0 (54) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: Date: Tue, 06 Feb 2007 08:29:06 GMT (35) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 0320f129114360872611436b2127a4d6@10.10.119.251 (57) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: CSeq: 103 BYE (13) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Content-Length: 0 (17) [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21 [Feb 6 09:28:35] DEBUG[7427]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0320f129114360872611436b2127a4d6@10.10.119.251' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '0320f129114360872611436b2127a4d6@10.10.119.251' Method: ACK [Feb 6 09:28:44] DEBUG[7427]: chan_sip.c:1992 __sip_autodestruct: Auto destroying SIP dialog '208751213962200782841@10.10.162.2' [Feb 6 09:28:44] DEBUG[7427]: chan_sip.c:3080 sip_destroy: Destroying SIP dialog 208751213962200782841@10.10.162.2 Really destroying SIP dialog '208751213962200782841@10.10.162.2' Method: OPTIONS centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> OPTIONS sip:9974@10.10.162.2 SIP/2.0 Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac90222663 Max-Forwards: 70 From: ;tag=1c90218524 To: Call-ID: 9021809262200782941@10.10.162.2 CSeq: 1 OPTIONS Contact: Supported: em,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Content-Length: 0 <-------------> [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: OPTIONS sip:9974@10.10.162.2 SIP/2.0 (41) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac90222663 (53) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: Max-Forwards: 70 (16) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=1c90218524 (48) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: To: (30) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 9021809262200782941@10.10.162.2 (40) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 OPTIONS (15) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Contact: (36) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Supported: em,timer,replaces,path (33) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (61) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Content-Length: 0 (17) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 9021809262200782941@10.10.162.2 - OPTIONS (No RTP) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:14453 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS Looking for 9974 in default (domain 10.10.162.2) <--- Transmitting (no NAT) to 10.10.162.2:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac90222663;received=10.10.162.2 From: ;tag=1c90218524 To: ;tag=as380edbca Call-ID: 9021809262200782941@10.10.162.2 CSeq: 1 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Accept: application/sdp Content-Length: 0 <------------> Scheduling destruction of SIP dialog '9021809262200782941@10.10.162.2' in 32000 ms (Method: OPTIONS) [Feb 6 09:29:12] DEBUG[7427]: chan_sip.c:14664 sipsock_read: SIP message could not be handled, bad request: 9021809262200782941@10.10.162.2 centrala*CLI> <--- SIP read from 10.10.162.2:5060 ---> BYE sip:8367@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac116223700 Max-Forwards: 70 From: ;tag=1c2120086823 To: ;tag=as3e892e58 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 2 BYE Contact: Supported: em,timer,replaces,path Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 Reason: Q.850 ;cause=16 Content-Length: 0 <-------------> [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 0: BYE sip:8367@10.10.119.251 SIP/2.0 (42) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac116223700 (54) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 2: Max-Forwards: 70 (16) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=1c2120086823 (49) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 4: To: ;tag=as3e892e58 (62) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 212008637362200782854@10.10.162.2 (42) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 6: CSeq: 2 BYE (11) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 7: Contact: (36) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 8: Supported: em,timer,replaces,path (33) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 10: User-Agent: Audiocodes-Sip-Gateway-MP-112 FXS/v.4.80A.038.004 (61) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 11: Reason: Q.850 ;cause=16 (23) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 12: Content-Length: 0 (17) [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:4527 parse_request: Header 13: (0) --- (13 headers 0 lines) --- <--- Transmitting (no NAT) to 10.10.162.2:5060 ---> SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 10.10.162.2;branch=z9hG4bKac116223700;received=10.10.162.2 From: ;tag=1c2120086823 To: ;tag=as3e892e58 Call-ID: 212008637362200782854@10.10.162.2 CSeq: 2 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Feb 6 09:29:23] DEBUG[7427]: chan_sip.c:14631 sipsock_read: Invalid SIP message - rejected , no callid, len 560 centrala*CLI> exit centrala:~/asterisk-1.4/asterisk-1.4.0#