centrala:~/branch_1.4/channels# asterisk centrala:~/branch_1.4/channels# asterisk -r Asterisk SVN-branch-1.4-r47405M, 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 SVN-branch-1.4-r47405M currently running on centrala (pid = 2179) 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> 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> sip debug SIP Debugging enabled [Nov 13 17:58:10] DEBUG[2202]: chan_sip.c:1966 __sip_autodestruct: Auto destroying SIP dialog '1B1B-144B-4310000EDC17C80548B-0@SipHost' [Nov 13 17:58:10] DEBUG[2202]: chan_sip.c:3047 sip_destroy: Destroying SIP dialog 1B1B-144B-4310000EDC17C80548B-0@SipHost Really destroying SIP dialog '1B1B-144B-4310000EDC17C80548B-0@SipHost' Method: REGISTER centrala*CLI> <--- SIP read from 10.10.3.58:5060 ---> INVITE sip:08344@10.10.119.251:5060;user=phone SIP/2.0 Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,REGISTER,INFO,PRACK,REFER,SUBSCRIBE,NOTIFY,PUBLISH,MESSAGE From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 18 INVITE Contact: Content-Type: application/sdp Content-Length: 258 Expires: 40 Max-Forwards: 70 User-Agent: SIP-ITG-1-2-31-692 Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK7aa8efdfd26ee4b9 v=0 o=9972 1793877780 1793877780 IN IP4 10.10.3.58 s=Session SDP c=IN IP4 10.10.3.58 t=0 0 m=audio 9004 RTP/AVP 18 4 2 0 8 a=rtpmap:18 G729/8000/1 a=rtpmap:4 G723/8000/1 a=rtpmap:2 G726-32/8000/1 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 <-------------> [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:08344@10.10.119.251:5060;user=phone SIP/2.0 (61) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,REGISTER,INFO,PRACK,REFER,SUBSCRIBE,NOTIFY,PUBLISH,MESSAGE (95) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 (90) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: (47) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost (50) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: CSeq: 18 INVITE (15) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Contact: (40) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: Content-Type: application/sdp (29) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Content-Length: 258 (19) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Expires: 40 (11) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: Max-Forwards: 70 (16) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 11: User-Agent: SIP-ITG-1-2-31-692 (30) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 12: Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK7aa8efdfd26ee4b9 (63) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 13: (0) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: o=9972 1793877780 1793877780 IN IP4 10.10.3.58 (51) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: s=Session SDP (13) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.3.58 (19) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: m=audio 9004 RTP/AVP 18 4 2 0 8 (31) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729/8000/1 (23) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:4 G723/8000/1 (22) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:2 G726-32/8000/1 (25) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:0 PCMU/8000/1 (22) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000/1 (22) --- (13 headers 11 lines) --- [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2530 do_setnat: Setting NAT on RTP to Off [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2540 do_setnat: Setting NAT on UDPTL to Off [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4217 sip_alloc: Allocating new SIP dialog for 1B1B-144B-101600007BC42B85265B-16@SipHost - INVITE (With RTP) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:14286 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.10.3.58 : 5060 (no NAT) Using INVITE request as basis request - 1B1B-144B-101600007BC42B85265B-16@SipHost [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2530 do_setnat: Setting NAT on RTP to Off [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2540 do_setnat: Setting NAT on UDPTL to Off Found user '9972' Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 2 Found RTP audio format 0 Found RTP audio format 8 Peer audio RTP is at port 10.10.3.58:9004 [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format G729 for ID 18 Found description format G723 for ID 4 Found description format G726-32 for ID 2 Found description format PCMU for ID 0 Found description format PCMA for ID 8 [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x508 (alaw|g729|ilbc), peer - audio=0x90d (g723|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x108 (alaw|g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.3.58:9004 [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x108 (alaw|g729) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:13078 handle_request_invite: Checking SIP call limits for device 9972 [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2946 update_call_counter: Updating call counter for incoming call Looking for 08344 in default (domain 10.10.119.251) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:3724 sip_new: *** Our native formats are 0x100 (g729) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:3725 sip_new: *** Joint capabilities are 0x108 (alaw|g729) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:3726 sip_new: *** Our capabilities are 0x508 (alaw|g729|ilbc) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:3727 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:3750 sip_new: This channel will not be able to handle video. [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:7816 build_route: build_route: Contact hop: list_route: hop: [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:13152 handle_request_invite: SIP/9972-081b1af8: New call is still down.... Trying... <--- Transmitting (no NAT) to 10.10.3.58:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK7aa8efdfd26ee4b9;received=10.10.3.58 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 18 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 13 17:58:25] DEBUG[2202]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9972-081b1af8 [Nov 13 17:58:25] DEBUG[2183]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9972 [Nov 13 17:58:25] DEBUG[2183]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9972 [Nov 13 17:58:25] DEBUG[2183]: devicestate.c:287 do_state_change: Changing state for SIP/9972 - state 1 (Not in use) [Nov 13 17:58:25] DEBUG[2211]: app_queue.c:546 changethread: Device 'SIP/9972' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 13 17:58:25] DEBUG[2212]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' -- Executing [08344@default:1] Dial("SIP/9972-081b1af8", "SIP/10.10.119.225/08344|60|r") in new stack [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:14930 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4217 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3724 sip_new: *** Our native formats are 0x100 (g729) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3725 sip_new: *** Joint capabilities are 0x0 (nothing) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3726 sip_new: *** Our capabilities are 0x508 (alaw|g729|ilbc) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3727 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3729 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:3750 sip_new: This channel will not be able to handle video. [Nov 13 17:58:25] DEBUG[2212]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-default-08344-1. [Nov 13 17:58:25] DEBUG[2212]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Nov 13 17:58:25] DEBUG[2212]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Nov 13 17:58:25] DEBUG[2212]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Nov 13 17:58:25] DEBUG[2212]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:2781 sip_call: Outgoing Call for 08344 [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:2795 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:6053 add_sdp: ** Our capability: 0x100 (g729) Video flag: False [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:6054 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.10.119.251 port 14682 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:6185 add_sdp: -- Done with adding codecs to SDP [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:6230 add_sdp: Done building SDP. Settling with this capability: 0x100 (g729) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:08344@10.10.119.225 SIP/2.0 (45) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport (66) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 3: To: (36) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 4: Contact: (40) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 6: CSeq: 102 INVITE (16) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 8: Max-Forwards: 70 (16) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 9: Date: Mon, 13 Nov 2006 16:58:25 GMT (35) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 11: Supported: replaces (19) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 12: Content-Type: application/sdp (29) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 267 (19) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: o=root 2212 2212 IN IP4 10.10.119.251 (39) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: s=session (9) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.251 (24) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: m=audio 14682 RTP/AVP 18 101 (28) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=fmtp:18 annexb=no (19) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=fmtp:101 0-16 (15) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=silenceSupp:off - - - - (25) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:4499 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:08344@10.10.119.225 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport From: "9972" ;tag=as2a02cc7d To: Contact: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 13 Nov 2006 16:58:25 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 267 v=0 o=root 2212 2212 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 14682 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 --- [Nov 13 17:58:25] DEBUG[2212]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 -- Called 10.10.119.225/08344 centrala*CLI> <--- Transmitting (no NAT) to 10.10.3.58:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK7aa8efdfd26ee4b9;received=10.10.3.58 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: ;tag=as21657797 Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 18 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=z9hG4bK19ae163e;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Date: Mon, 13 Nov 2006 11:02:44 GMT Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 100 Trying (18) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport (66) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=7E361C50-1972 (54) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Date: Mon, 13 Nov 2006 11:02:44 GMT (35) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Allow-Events: telephone-event (29) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2076 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #11 - INVITE (got response) [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5009d258320680ac71df160b6b200c37@10.10.119.251' Request 102: Found [Nov 13 17:58:25] DEBUG[2202]: chan_sip.c:11408 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=z9hG4bK19ae163e;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Date: Mon, 13 Nov 2006 11:02:44 GMT Call-ID: 5009d258320680ac71df160b6b200c37@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: 223 v=0 o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16480 RTP/AVP 18 c=IN IP4 10.10.119.225 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 <-------------> [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport (66) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=7E361C50-1972 (54) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Date: Mon, 13 Nov 2006 11:02:44 GMT (35) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 223 (19) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 (63) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: m=audio 16480 RTP/AVP 18 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=fmtp:18 annexb=no (19) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 10 lines) --- [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5009d258320680ac71df160b6b200c37@10.10.119.251' Request 102: Found [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:11408 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format G729 for ID 18 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4a40 Capabilities: us - 0x508 (alaw|g729|ilbc), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x100 (g729) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081c4a40 is making progress passing it to SIP/9972-081b1af8 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=z9hG4bK19ae163e;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Date: Mon, 13 Nov 2006 11:02:44 GMT Call-ID: 5009d258320680ac71df160b6b200c37@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: 223 v=0 o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16480 RTP/AVP 18 c=IN IP4 10.10.119.225 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 <-------------> [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport (66) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=7E361C50-1972 (54) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Date: Mon, 13 Nov 2006 11:02:44 GMT (35) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 223 (19) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 (63) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: m=audio 16480 RTP/AVP 18 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=fmtp:18 annexb=no (19) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 10 lines) --- [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5009d258320680ac71df160b6b200c37@10.10.119.251' Request 102: Found [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:11408 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format G729 for ID 18 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4a40 Capabilities: us - 0x508 (alaw|g729|ilbc), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x100 (g729) [Nov 13 17:58:26] DEBUG[2202]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081c4a40 is making progress passing it to SIP/9972-081b1af8 [Nov 13 17:58:29] DEBUG[2212]: rtp.c:808 ast_rtcp_read: Got RTCP report of 92 bytes [Nov 13 17:58:33] DEBUG[2212]: rtp.c:808 ast_rtcp_read: Got RTCP report of 92 bytes 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=z9hG4bK19ae163e;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Date: Mon, 13 Nov 2006 11:02:44 GMT Call-ID: 5009d258320680ac71df160b6b200c37@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: 223 v=0 o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16480 RTP/AVP 18 c=IN IP4 10.10.119.225 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 <-------------> [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK19ae163e;rport (66) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=7E361C50-1972 (54) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Date: Mon, 13 Nov 2006 11:02:44 GMT (35) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 223 (19) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 7525 9738 IN IP4 10.10.119.225 (63) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: m=audio 16480 RTP/AVP 18 (24) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=fmtp:18 annexb=no (19) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 10 lines) --- [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:2025 __sip_ack: Acked pending invite 102 [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5009d258320680ac71df160b6b200c37@10.10.119.251' of Request 102: Match Not Found [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:11408 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format G729 for ID 18 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4a40 Capabilities: us - 0x508 (alaw|g729|ilbc), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16480 [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x100 (g729) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:7816 build_route: build_route: Contact hop: list_route: hop: [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5009d258320680ac71df160b6b200c37@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:08344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK7333d70e;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Contact: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 13 17:58:34] DEBUG[2212]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081c4a40 [Nov 13 17:58:34] DEBUG[2183]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 13 17:58:34] DEBUG[2183]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 13 17:58:34] DEBUG[2183]: channel.c:943 channel_find_locked: Avoiding initial deadlock for channel '0x81d6328' -- SIP/10.10.119.225-081c4a40 answered SIP/9972-081b1af8 [Nov 13 17:58:34] DEBUG[2212]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9972-081b1af8 [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:3393 sip_answer: SIP answering channel: SIP/9972-081b1af8 [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:6285 transmit_response_with_sdp: Setting framing from config on incoming call [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:6053 add_sdp: ** Our capability: 0x108 (alaw|g729) Video flag: True [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:6054 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.10.119.251 port 17706 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:6185 add_sdp: -- Done with adding codecs to SDP [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:6230 add_sdp: Done building SDP. Settling with this capability: 0x108 (alaw|g729) centrala*CLI> <--- Reliably Transmitting (no NAT) to 10.10.3.58:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK7aa8efdfd26ee4b9;received=10.10.3.58 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: ;tag=as21657797 Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 18 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 235 v=0 o=root 2212 2212 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 17706 RTP/AVP 18 8 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Nov 13 17:58:34] DEBUG[2212]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14 -- Packet2Packet bridging SIP/9972-081b1af8 and SIP/10.10.119.225-081c4a40 [Nov 13 17:58:34] DEBUG[2183]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 2 (In use) [Nov 13 17:58:34] DEBUG[2183]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9972 [Nov 13 17:58:34] DEBUG[2183]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9972 [Nov 13 17:58:34] DEBUG[2183]: devicestate.c:287 do_state_change: Changing state for SIP/9972 - state 1 (Not in use) [Nov 13 17:58:34] DEBUG[2213]: 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. [Nov 13 17:58:34] DEBUG[2214]: app_queue.c:546 changethread: Device 'SIP/9972' 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.3.58:5060 ---> ACK sip:08344@10.10.119.251 SIP/2.0 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: ;tag=as21657797 Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 18 ACK Content-Length: 0 Max-Forwards: 70 User-Agent: SIP-ITG-1-2-31-692 Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK89cd95b8b0bad863 <-------------> [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: ACK sip:08344@10.10.119.251 SIP/2.0 (42) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 (90) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: To: ;tag=as21657797 (62) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost (50) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: CSeq: 18 ACK (12) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Content-Length: 0 (17) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: User-Agent: SIP-ITG-1-2-31-692 (30) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bK89cd95b8b0bad863 (63) [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:14286 handle_request: **** Received ACK (6) - Command in SIP ACK [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14 [Nov 13 17:58:34] DEBUG[2202]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '1B1B-144B-101600007BC42B85265B-16@SipHost' of Response 18: Match Not Found centrala*CLI> <--- SIP read from 10.10.3.58:5060 ---> BYE sip:08344@10.10.119.251 SIP/2.0 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: ;tag=as21657797 Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 19 BYE Content-Length: 0 Max-Forwards: 70 User-Agent: SIP-ITG-1-2-31-692 Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bKdae06cebd65221e1 <-------------> [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: BYE sip:08344@10.10.119.251 SIP/2.0 (42) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 (90) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: To: ;tag=as21657797 (62) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost (50) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: CSeq: 19 BYE (12) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Content-Length: 0 (17) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: User-Agent: SIP-ITG-1-2-31-692 (30) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bKdae06cebd65221e1 (63) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:14286 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 10.10.3.58 : 5060 (no NAT) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:13859 handle_request_bye: Received bye, issuing owner hangup . <--- Transmitting (no NAT) to 10.10.3.58:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.3.58:5060;branch=z9hG4bKdae06cebd65221e1;received=10.10.3.58 From: "9972" ;tag=SIP-ITG-1-2-31-692-32e0d0cc-10170000 To: ;tag=as21657797 Call-ID: 1B1B-144B-101600007BC42B85265B-16@SipHost CSeq: 19 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 13 17:58:37] DEBUG[2212]: rtp.c:2947 bridge_p2p_loop: Oooh, got a hangup [Nov 13 17:58:37] DEBUG[2212]: channel.c:3918 ast_channel_bridge: Returning from native bridge, channels: SIP/9972-081b1af8, SIP/10.10.119.225-081c4a40 [Nov 13 17:58:37] DEBUG[2212]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/10.10.119.225-081c4a40' [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:3245 sip_hangup: Hangup call SIP/10.10.119.225-081c4a40, SIP callid 5009d258320680ac71df160b6b200c37@10.10.119.251) [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:3253 sip_hangup: update_call_counter(08344) - decrement call limit counter on hangup [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog '5009d258320680ac71df160b6b200c37@10.10.119.251' in 32000 ms (Method: INVITE) [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5009d258320680ac71df160b6b200c37@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:08344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK49ffe102;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #16 [Nov 13 17:58:37] DEBUG[2212]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081c4a40 [Nov 13 17:58:37] DEBUG[2183]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 13 17:58:37] DEBUG[2183]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 13 17:58:37] DEBUG[2183]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 1 (Not in use) [Nov 13 17:58:37] DEBUG[2212]: rtp.c:1418 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Nov 13 17:58:37] DEBUG[2212]: app_dial.c:1639 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Nov 13 17:58:37] DEBUG[2212]: pbx.c:2363 __ast_pbx_run: Spawn extension (default,08344,1) exited non-zero on 'SIP/9972-081b1af8' == Spawn extension (default, 08344, 1) exited non-zero on 'SIP/9972-081b1af8' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"9972" <9972>' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9972' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '08344' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/9972-081b1af8' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225-081c4a40' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225/08344|60|r' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-13 17:58:25' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-13 17:58:34' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-13 17:58:37' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '12' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '3' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163437105.0' [Nov 13 17:58:37] DEBUG[2212]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 13 17:58:37] DEBUG[2212]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/9972-081b1af8' 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=z9hG4bK49ffe102;rport From: "9972" ;tag=as2a02cc7d To: ;tag=7E361C50-1972 Date: Mon, 13 Nov 2006 11:02:56 GMT Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 103 BYE Reason: Q.850;cause=16 Content-Length: 0 <-------------> [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK49ffe102;rport (66) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 2: From: "9972" ;tag=as2a02cc7d (64) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=7E361C50-1972 (54) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 4: Date: Mon, 13 Nov 2006 11:02:56 GMT (35) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5009d258320680ac71df160b6b200c37@10.10.119.251 (57) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 7: CSeq: 103 BYE (13) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 8: Reason: Q.850;cause=16 (22) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #16 [Nov 13 17:58:37] DEBUG[2202]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5009d258320680ac71df160b6b200c37@10.10.119.251' of Request 103: Match Not Found Really destroying SIP dialog '5009d258320680ac71df160b6b200c37@10.10.119.251' Method: INVITE [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:3245 sip_hangup: Hangup call SIP/9972-081b1af8, SIP callid 1B1B-144B-101600007BC42B85265B-16@SipHost) [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:3253 sip_hangup: update_call_counter(9972) - decrement call limit counter on hangup [Nov 13 17:58:37] DEBUG[2212]: chan_sip.c:2946 update_call_counter: Updating call counter for incoming call [Nov 13 17:58:37] DEBUG[2212]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9972-081b1af8 [Nov 13 17:58:37] DEBUG[2183]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9972 [Nov 13 17:58:37] DEBUG[2183]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9972 [Nov 13 17:58:37] DEBUG[2183]: devicestate.c:287 do_state_change: Changing state for SIP/9972 - state 1 (Not in use) [Nov 13 17:58:37] DEBUG[2215]: 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. [Nov 13 17:58:37] DEBUG[2216]: app_queue.c:546 changethread: Device 'SIP/9972' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Really destroying SIP dialog '1B1B-144B-101600007BC42B85265B-16@SipHost' Method: BYE centrala*CLI> sip show pe peers peer centrala*CLI> sip show peer cisco3 centrala*CLI> * Name : cisco3 Secret : MD5Secret : Context : default Subscr.Cont. : Language : AMA flags : Unknown Transfer mode: open CallingPres : Presentation Allowed, Not Screened Callgroup : Pickupgroup : Mailbox : VM Extension : asterisk LastMsgsSent : -1 Call limit : 0 Dynamic : No Callerid : "" <> MaxCallBR : 384 kbps Expire : -1 Insecure : port,invite Nat : RFC3581 ACL : No T38 pt UDPTL : Yes CanReinvite : Yes PromiscRedir : No User=Phone : No Video Support: No Trust RPID : No Send RPID : No Subscriptions: Yes Overlap dial : Yes DTMFmode : rfc2833 LastMsg : 0 ToHost : 10.10.119.225 Addr->IP : 10.10.119.225 Port 5060 Defaddr->IP : 0.0.0.0 Port 0 Def. Username: SIP Options : (none) Codecs : 0x108 (alaw|g729) Codec Order : (g729:20,alaw:20) Status : Unmonitored Useragent : Reg. Contact : centrala*CLI>