Asterisk SVN-branch-1.4-r48281, 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-r48281 currently running on a-node2 (pid = 24217) onnode2*CLI> Verbosity is at least 3 a-node2*CLI> set de No such command 'set de' (type 'help' for help) a-node2*CLI> a-node2*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. a-node2*CLI> set verbose 4 Verbosity was 3 and is now 4 The 'set verbose' command is deprecated and will be removed in a future release. Please use 'core set verbose' instead. a-node2*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. a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:1234@mydomain.tld SIP/2.0 Record-Route: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-7e02744b;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE Max-Forwards: 69 Contact: ivoc Expires: 240 User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 260 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp X-Custom-Duration: 7200000 v=0 o=- 781009 781009 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=audio 16464 RTP/AVP 18 100 101 a=rtpmap:18 G729a/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@mydomain.tld SIP/2.0 (43) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Record-Route: (64) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.0 (61) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-7e02744b;rport=5242 (71) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: From: ivoc ;tag=48e06077edefdf45o0 (69) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: To: (34) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Max-Forwards: 69 (16) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Contact: ivoc (49) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: Expires: 240 (12) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: Content-Length: 260 (19) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: Supported: x-sipura (19) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 16: X-Custom-Duration: 7200000 (32) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 17: (0) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=- 781009 781009 IN IP4 10.2.0.1 (39) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=- (3) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=audio 16464 RTP/AVP 18 100 101 (32) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:100 192-193 (18) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=ptime:30 (10) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) --- (17 headers 13 lines) --- [Dec 6 15:13:31] WARNING[24250]: rtp.c:1889 ast_rtp_settos: Unable to set TOS to 184 [Dec 6 15:13:31] WARNING[24250]: udptl.c:846 ast_udptl_settos: UDPTL unable to set TOS to 184 [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to Off [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to Off [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for 610575df-3d3b88fd@10.2.0.1 - INVITE (With RTP) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:1670 parse_sip_options: Found SIP option: -x-sipura- [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:1682 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 10.0.0.1 : 5060 (no NAT) Using INVITE request as basis request - 610575df-3d3b88fd@10.2.0.1 Found peer 'ser' [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to On [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On Found RTP audio format 18 Found RTP audio format 100 Found RTP audio format 101 [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.2.0.1:16464 Found description format G729a for ID 18 Found description format NSE for ID 100 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x108 (alaw|g729), peer - audio=0x100 (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.2.0.1:16464 [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x100 (g729) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:13224 handle_request_invite: Checking SIP call limits for device [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Looking for 1234 in pre-process (domain mydomain.tld) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x108 (alaw|g729) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:7859 build_route: build_route: Record-Route hop: list_route: hop: [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:13297 handle_request_invite: SIP/mydomain.tld-09032050: New call is still down.... Trying... <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-7e02744b;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 6 15:13:31] DEBUG[24250]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-09032050 [Dec 6 15:13:31] DEBUG[24233]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 6 15:13:31] DEBUG[24233]: chan_sip.c:15035 sip_devicestate: Checking device state for peer mydomain.tld [Dec 6 15:13:31] DEBUG[24233]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 6 15:13:31] DEBUG[24497]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-09032050", "X-Custom-Test3: ") in new stack [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:16800 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Dec 6 15:13:31] DEBUG[24497]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-09032050", "X-Custom-Network: class4") in new stack [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:16800 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Dec 6 15:13:31] DEBUG[24497]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-09032050", "SIP/1234@ser") in new stack [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:15093 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Dec 6 15:13:31] WARNING[24497]: rtp.c:1889 ast_rtp_settos: Unable to set TOS to 184 [Dec 6 15:13:31] WARNING[24497]: udptl.c:846 ast_udptl_settos: UDPTL unable to set TOS to 184 [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2605 create_addr_from_peer: Our T38 capability (3856) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x108 (alaw|g729) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3771 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 6 15:13:31] DEBUG[24497]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2812 sip_call: Outgoing Call for 1234 [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:2826 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6756 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6756 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6119 add_sdp: ** Our capability: 0x108 (alaw|g729) Video flag: False [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6120 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.0.0.2 port 12230 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6251 add_sdp: -- Done with adding codecs to SDP [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:6296 add_sdp: Done building SDP. Settling with this capability: 0x108 (alaw|g729) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (45) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport (65) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as7ed14cae (63) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 3: To: (36) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 4: Contact: (39) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 7: User-Agent: Asterisk (27) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 9: Remote-Party-ID: "ivoc" ;privacy=off;screen=no (81) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 10: Date: Wed, 06 Dec 2006 13:13:31 GMT (35) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 12: Supported: replaces (19) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 13: X-Custom-Network: class4 (26) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 14: X-Custom-Test3: (24) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 16: Content-Length: 291 (19) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4525 parse_request: Header 17: (0) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: o=root 24217 24217 IN IP4 10.0.0.2 (40) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: s=session (9) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: m=audio 12230 RTP/AVP 18 8 101 (30) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) Reliably Transmitting (NAT) to 10.0.0.1:5060: INVITE sip:1234@10.0.0.1 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport From: "ivoc" ;tag=as7ed14cae To: Contact: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Date: Wed, 06 Dec 2006 13:13:31 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-Custom-Network: class4 X-Custom-Test3: Content-Type: application/sdp Content-Length: 291 v=0 o=root 24217 24217 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 12230 RTP/AVP 18 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Dec 6 15:13:31] DEBUG[24497]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #4 -- Called 1234@ser [Dec 6 15:13:31] DEBUG[24498]: app_queue.c:546 changethread: Device 'SIP/mydomain.tld' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 From: "ivoc" ;tag=as7ed14cae To: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 102 INVITE Server: openSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 (70) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as7ed14cae (63) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: To: (36) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Server: openSER (1.1.0-notls (i386/linux)) (50) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #4 - INVITE (got response) [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' Request 102: Found [Dec 6 15:13:31] DEBUG[24250]: chan_sip.c:11528 handle_response_invite: SIP response 100 to standard invite a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 From: "ivoc" ;tag=as7ed14cae To: ;tag=21162030-D6E Date: Wed, 06 Dec 2006 13:13:31 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER Allow-Events: telephone-event Contact: Record-Route: Content-Disposition: session;handling=required Content-Type: application/sdp Content-Length: 300 v=0 o=CiscoSystemsSIP-GW-UserAgent 1421 5642 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 16936 RTP/AVP 18 101 c=IN IP4 10.3.0.1 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=silenceSupp:off - - - - <-------------> [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 (70) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as7ed14cae (63) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=21162030-D6E (53) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: Date: Wed, 06 Dec 2006 13:13:31 GMT (35) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Allow-Events: telephone-event (29) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: Contact: (45) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Record-Route: (56) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: Content-Length: 300 (19) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 1421 5642 IN IP4 10.3.0.1 (61) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=audio 16936 RTP/AVP 18 101 (28) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) --- (15 headers 13 lines) --- [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' Request 102: Found [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:11528 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Found RTP audio format 101 [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:16936 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 [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel SIP/ser-090374c8 Capabilities: us - 0x108 (alaw|g729), peer - audio=0x100 (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.3.0.1:16936 [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x100 (g729) [Dec 6 15:13:32] DEBUG[24250]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call -- SIP/ser-090374c8 is making progress passing it to SIP/mydomain.tld-09032050 [Dec 6 15:13:32] DEBUG[24497]: chan_sip.c:6351 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 6 15:13:32] DEBUG[24497]: chan_sip.c:6119 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Dec 6 15:13:32] DEBUG[24497]: chan_sip.c:6120 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 16120 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 6 15:13:32] DEBUG[24497]: chan_sip.c:6251 add_sdp: -- Done with adding codecs to SDP [Dec 6 15:13:32] DEBUG[24497]: chan_sip.c:6296 add_sdp: Done building SDP. Settling with this capability: 0x100 (g729) a-node2*CLI> <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-7e02744b;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 24217 24217 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 16120 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 <------------> [Dec 6 15:13:32] DEBUG[24497]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to g729 [Dec 6 15:13:32] DEBUG[24497]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Dec 6 15:13:32] DEBUG[24497]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to g729 [Dec 6 15:13:32] DEBUG[24497]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 From: "ivoc" ;tag=as7ed14cae To: ;tag=21162030-D6E Date: Wed, 06 Dec 2006 13:13:31 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER Allow-Events: telephone-event Contact: Record-Route: Content-Type: application/sdp Content-Length: 300 v=0 o=CiscoSystemsSIP-GW-UserAgent 1421 5642 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 16936 RTP/AVP 18 101 c=IN IP4 10.3.0.1 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=silenceSupp:off - - - - <-------------> [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7ecdf50c;rport=5060 (70) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as7ed14cae (63) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=21162030-D6E (53) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: Date: Wed, 06 Dec 2006 13:13:31 GMT (35) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Allow-Events: telephone-event (29) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: Contact: (45) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Record-Route: (56) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Content-Length: 300 (19) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: (0) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 1421 5642 IN IP4 10.3.0.1 (61) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=audio 16936 RTP/AVP 18 101 (28) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) --- (14 headers 13 lines) --- [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' of Request 102: Match Not Found [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:11528 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Found RTP audio format 101 [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:16936 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 [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel SIP/ser-090374c8 Capabilities: us - 0x108 (alaw|g729), peer - audio=0x100 (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.3.0.1:16936 [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x100 (g729) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:7859 build_route: build_route: Record-Route hop: list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.1, port 5060 Transmitting (NAT) to 10.0.0.1:5060: ACK sip:1234@10.3.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK6aae8683;rport Route: From: "ivoc" ;tag=as7ed14cae To: ;tag=21162030-D6E Contact: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Dec 6 15:13:33] DEBUG[24497]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-090374c8 -- SIP/ser-090374c8 answered SIP/mydomain.tld-09032050 [Dec 6 15:13:33] DEBUG[24497]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-09032050 [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:3428 sip_answer: SIP answering channel: SIP/mydomain.tld-09032050 [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:6351 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:6119 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:6120 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 16120 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:6251 add_sdp: -- Done with adding codecs to SDP [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:6296 add_sdp: Done building SDP. Settling with this capability: 0x100 (g729) <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-7e02744b;rport=5242 Record-Route: From: ivoc ;tag=48e06077edefdf45o0 To: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 267 v=0 o=root 24217 24218 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 16120 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 <------------> [Dec 6 15:13:33] DEBUG[24497]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #8 -- Packet2Packet bridging SIP/mydomain.tld-09032050 and SIP/ser-090374c8 [Dec 6 15:13:33] DEBUG[24233]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Dec 6 15:13:33] DEBUG[24233]: chan_sip.c:15035 sip_devicestate: Checking device state for peer ser [Dec 6 15:13:33] DEBUG[24233]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Dec 6 15:13:33] DEBUG[24233]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 6 15:13:33] DEBUG[24233]: chan_sip.c:15035 sip_devicestate: Checking device state for peer mydomain.tld [Dec 6 15:13:33] DEBUG[24233]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> ACK sip:1234@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.2 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-3196be5d;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 ACK Max-Forwards: 69 Proxy-Authorization: Digest username="02222",realm="mydomain.tld",nonce="4576c3278abdb39aed588428dcf86e7d96762162",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="f218a5a09ff200d02cb013fc0668084c" Contact: ivoc User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: ACK sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK6dfc.6850df27.2 (61) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-3196be5d;rport=5242 (71) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ivoc ;tag=48e06077edefdf45o0 (69) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: ;tag=as33e37ae6 (49) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: CSeq: 102 ACK (13) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Max-Forwards: 69 (16) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Proxy-Authorization: Digest username="02222",realm="mydomain.tld",nonce="4576c3278abdb39aed588428dcf86e7d96762162",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="f218a5a09ff200d02cb013fc0668084c" (218) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Contact: ivoc (49) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Content-Length: 0 (17) [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #8 [Dec 6 15:13:33] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '610575df-3d3b88fd@10.2.0.1' of Response 102: Match Not Found [Dec 6 15:13:33] DEBUG[24500]: app_queue.c:546 changethread: Device 'SIP/ser' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 6 15:13:33] DEBUG[24501]: app_queue.c:546 changethread: Device 'SIP/mydomain.tld' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:02222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK094c.53b84f1.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97B91880 From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Date: Wed, 06 Dec 2006 13:13:38 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 1732032235-2221019611-3212892086-1321745574 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER CSeq: 101 INVITE Max-Forwards: 69 Timestamp: 1165410818 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 481 v=0 o=CiscoSystemsSIP-GW-UserAgent 1421 5643 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 16936 udptl 101 t38 c=IN IP4 10.3.0.1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:02222@10.0.0.2:5060 SIP/2.0 (48) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK094c.53b84f1.0 (60) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97B91880 (59) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=21162030-D6E (55) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as7ed14cae (61) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Date: Wed, 06 Dec 2006 13:13:38 GMT (35) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Min-SE: 1800 (13) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Cisco-Guid: 1732032235-2221019611-3212892086-1321745574 (55) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: CSeq: 101 INVITE (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Max-Forwards: 69 (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: Timestamp: 1165410818 (21) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 15: Contact: (45) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 16: Expires: 180 (12) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 17: Allow-Events: telephone-event (29) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 18: Content-Type: application/sdp (29) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 19: Content-Length: 481 (19) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 20: (0) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 1421 5643 IN IP4 10.3.0.1 (61) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=image 16936 udptl 101 t38 (27) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (20 headers 19 lines) --- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,replaces" [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1670 parse_sip_options: Found SIP option: -100rel- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1676 parse_sip_options: Matched SIP option: 100rel [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1670 parse_sip_options: Found SIP option: -timer- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1676 parse_sip_options: Matched SIP option: timer [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1670 parse_sip_options: Found SIP option: -replaces- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1676 parse_sip_options: Matched SIP option: replaces Sending to 10.0.0.1 : 5060 (NAT) Got T.38 offer in SDP in dialog 36b0916b030254d57f1a5d32467d7561@mydomain.tld [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4782 process_sdp: T38 state changed to 4 on channel SIP/ser-090374c8 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4832 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:16936 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 36b0916b030254d57f1a5d32467d7561@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 7200 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5012 process_sdp: FillBitRemoval: 0 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5018 process_sdp: Transcoding MMR: 0 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5025 process_sdp: Transcoding JBIG: 0 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 72 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5059 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x108 (alaw|g729), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5101 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:13275 handle_request_invite: Got a SIP re-invite for call 36b0916b030254d57f1a5d32467d7561@mydomain.tld [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:13370 handle_request_invite: SIP/ser-090374c8: This call is UP.... [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:16547 sip_handle_t38_reinvite: Sending reinvite on SIP '610575df-3d3b88fd@10.2.0.1' - It's UDPTL soon redirected to us (IP 10.0.0.2) set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.1, port 5060 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5972 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4028 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5978 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5909 t38_get_rate: T38MaxFaxRate 7200 found [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1603 initialize_initreq: Initializing already initialized SIP dialog 610575df-3d3b88fd@10.2.0.1 (presumably reinvite) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:02222@10.2.0.1:5242 SIP/2.0 (48) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport (65) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Route: (57) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=as33e37ae6 (51) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: ivoc ;tag=48e06077edefdf45o0 (67) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Contact: (34) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: User-Agent: Asterisk (27) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Max-Forwards: 70 (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Supported: replaces (19) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: Content-Length: 261 (19) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=root 24217 24219 IN IP4 10.0.0.2 (40) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=session (9) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=image 4028 udptl t38 (22) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) Reliably Transmitting (NAT) to 10.0.0.1:5060: INVITE sip:02222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport Route: From: ;tag=as33e37ae6 To: ivoc ;tag=48e06077edefdf45o0 Contact: Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE User-Agent: Asterisk 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 24217 24219 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4028 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:72 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy --- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport=5060 From: ;tag=as33e37ae6 To: ivoc ;tag=48e06077edefdf45o0 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE Server: openSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport=5060 (70) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=as33e37ae6 (51) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: To: ivoc ;tag=48e06077edefdf45o0 (67) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Server: openSER (1.1.0-notls (i386/linux)) (50) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #9 - INVITE (got response) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '610575df-3d3b88fd@10.2.0.1' Request 102: Found [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:11526 handle_response_invite: SIP response 100 to RE-invite on outgoing call 610575df-3d3b88fd@10.2.0.1 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ivoc ;tag=48e06077edefdf45o0 From: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport=5060 Contact: ivoc Server: Linksys/SPA2102-3.3.6 Content-Length: 269 Content-Type: application/sdp v=0 o=- 781757 781757 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=image 16464 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: To: ivoc ;tag=48e06077edefdf45o0 (67) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=as33e37ae6 (51) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: CSeq: 102 INVITE (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK363b6b65;rport=5060 (70) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Contact: ivoc (49) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Content-Length: 269 (19) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Content-Type: application/sdp (29) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=- 781757 781757 IN IP4 10.2.0.1 (39) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=- (3) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=image 16464 udptl t38 (23) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:14400 (21) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '610575df-3d3b88fd@10.2.0.1' of Request 102: Match Not Found [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:11526 handle_response_invite: SIP response 200 to RE-invite on outgoing call 610575df-3d3b88fd@10.2.0.1 Got T.38 offer in SDP in dialog 610575df-3d3b88fd@10.2.0.1 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4782 process_sdp: T38 state changed to 4 on channel SIP/mydomain.tld-09032050 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4832 process_sdp: Peer T.38 UDPTL is at port 10.2.0.1:16464 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 610575df-3d3b88fd@10.2.0.1 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 14400 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 200 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5059 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x108 (alaw|g729), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5101 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:7888 build_route: build_route: Contact hop: ivoc list_route: hop: [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:16575 sip_handle_t38_reinvite: Responding 200 OK on SIP '36b0916b030254d57f1a5d32467d7561@mydomain.tld' - It's UDPTL soon redirected to us (IP 10.0.0.2) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:16580 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/mydomain.tld-09032050 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:16581 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/ser-090374c8 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5972 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4352 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5978 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5905 t38_get_rate: T38MaxFaxRate 9600 found <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK094c.53b84f1.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97B91880 From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 101 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 263 v=0 o=root 24217 24218 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4352 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <------------> [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #10 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:5574 reqprep: Strict routing enforced for session 610575df-3d3b88fd@10.2.0.1 set_destination: Parsing for address/port to send to set_destination: set destination to 10.2.0.1, port 5242 Transmitting (NAT) to 10.0.0.1:5060: ACK sip:02222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK62fed94a;rport From: ;tag=as33e37ae6 To: ivoc ;tag=48e06077edefdf45o0 Contact: Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> ACK sip:02222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK094c.53b84f1.2 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97BA183 From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Date: Wed, 06 Dec 2006 13:13:38 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Max-Forwards: 69 CSeq: 101 ACK Content-Length: 0 <-------------> [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: ACK sip:02222@10.0.0.2:5060 SIP/2.0 (45) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK094c.53b84f1.2 (60) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97BA183 (58) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=21162030-D6E (55) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as7ed14cae (61) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Date: Wed, 06 Dec 2006 13:13:38 GMT (35) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Max-Forwards: 69 (16) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: CSeq: 101 ACK (13) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #10 [Dec 6 15:13:38] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' of Response 101: Match Not Found a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:02222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKd84c.7bf71c25.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97C31BFD From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Date: Wed, 06 Dec 2006 13:14:12 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 1732032235-2221019611-3212892086-1321745574 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER CSeq: 102 INVITE Max-Forwards: 69 Timestamp: 1165410852 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 493 v=0 o=CiscoSystemsSIP-GW-UserAgent 1421 5645 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 16936 udptl 101 t38 c=IN IP4 10.3.0.1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy a=sendonly <-------------> [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:02222@10.0.0.2:5060 SIP/2.0 (48) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKd84c.7bf71c25.0 (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97C31BFD (59) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=21162030-D6E (55) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as7ed14cae (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Date: Wed, 06 Dec 2006 13:14:12 GMT (35) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Min-SE: 1800 (13) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Cisco-Guid: 1732032235-2221019611-3212892086-1321745574 (55) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 12: CSeq: 102 INVITE (16) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 13: Max-Forwards: 69 (16) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 14: Timestamp: 1165410852 (21) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 15: Contact: (45) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 16: Expires: 180 (12) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 17: Allow-Events: telephone-event (29) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 18: Content-Type: application/sdp (29) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 19: Content-Length: 493 (19) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 20: (0) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 1421 5645 IN IP4 10.3.0.1 (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: m=image 16936 udptl 101 t38 (27) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4557 parse_request: Line: a=sendonly (10) --- (20 headers 20 lines) --- [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.0.0.1 : 5060 (NAT) Got T.38 offer in SDP in dialog 36b0916b030254d57f1a5d32467d7561@mydomain.tld [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4782 process_sdp: T38 state changed to 4 on channel SIP/ser-090374c8 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4832 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:16936 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 36b0916b030254d57f1a5d32467d7561@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 7200 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5012 process_sdp: FillBitRemoval: 0 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5018 process_sdp: Transcoding MMR: 0 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5025 process_sdp: Transcoding JBIG: 0 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 72 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5059 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x108 (alaw|g729), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5101 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:13275 handle_request_invite: Got a SIP re-invite for call 36b0916b030254d57f1a5d32467d7561@mydomain.tld [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:13370 handle_request_invite: SIP/ser-090374c8: This call is UP.... [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5972 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4352 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5978 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:5909 t38_get_rate: T38MaxFaxRate 7200 found <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKd84c.7bf71c25.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97C31BFD From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 261 v=0 o=root 24217 24219 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4352 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:72 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <------------> [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:13403 handle_request_invite: T38 state changed to 5 on channel SIP/ser-090374c8 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> ACK sip:02222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKd84c.7bf71c25.2 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97C41251 From: ;tag=21162030-D6E To: "ivoc" ;tag=as7ed14cae Date: Wed, 06 Dec 2006 13:14:12 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Max-Forwards: 69 CSeq: 102 ACK Content-Length: 0 <-------------> [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: ACK sip:02222@10.0.0.2:5060 SIP/2.0 (45) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKd84c.7bf71c25.2 (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK97C41251 (59) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=21162030-D6E (55) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as7ed14cae (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Date: Wed, 06 Dec 2006 13:14:12 GMT (35) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Max-Forwards: 69 (16) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: CSeq: 102 ACK (13) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11 [Dec 6 15:14:12] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' of Response 102: Match Not Found a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> BYE sip:1234@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK7dfc.88e129b7.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-cf0fc026;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 103 BYE Max-Forwards: 69 Proxy-Authorization: Digest username="02222",realm="mydomain.tld",nonce="4576c3278abdb39aed588428dcf86e7d96762162",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="94e1214dd26d74d6c6488c9eefed7dc7" User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: BYE sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK7dfc.88e129b7.0 (61) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-cf0fc026;rport=5242 (71) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: From: ivoc ;tag=48e06077edefdf45o0 (69) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: To: ;tag=as33e37ae6 (49) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 610575df-3d3b88fd@10.2.0.1 (41) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: CSeq: 103 BYE (13) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Max-Forwards: 69 (16) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: Proxy-Authorization: Digest username="02222",realm="mydomain.tld",nonce="4576c3278abdb39aed588428dcf86e7d96762162",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="94e1214dd26d74d6c6488c9eefed7dc7" (218) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: User-Agent: Linksys/SPA2102-3.3.6 (33) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 10: Content-Length: 0 (17) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:14440 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 10.0.0.1 : 5060 (NAT) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:1615 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 610575df-3d3b88fd@10.2.0.1 [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:14017 handle_request_bye: Received bye, issuing owner hangup . <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK7dfc.88e129b7.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-cf0fc026;rport=5242 From: ivoc ;tag=48e06077edefdf45o0 To: ;tag=as33e37ae6 Call-ID: 610575df-3d3b88fd@10.2.0.1 CSeq: 103 BYE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 6 15:14:26] DEBUG[24497]: rtp.c:3006 bridge_p2p_loop: Oooh, got a hangup [Dec 6 15:14:26] DEBUG[24497]: channel.c:3924 ast_channel_bridge: Returning from native bridge, channels: SIP/mydomain.tld-09032050, SIP/ser-090374c8 [Dec 6 15:14:26] DEBUG[24497]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/ser-090374c8' [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:3278 sip_hangup: Hangup call SIP/ser-090374c8, SIP callid 36b0916b030254d57f1a5d32467d7561@mydomain.tld) [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:3286 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Scheduling destruction of SIP dialog '36b0916b030254d57f1a5d32467d7561@mydomain.tld' in 32000 ms (Method: ACK) set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.1, port 5060 Reliably Transmitting (NAT) to 10.0.0.1:5060: BYE sip:1234@10.3.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2c51e459;rport Route: From: "ivoc" ;tag=as7ed14cae To: ;tag=21162030-D6E Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #13 [Dec 6 15:14:26] DEBUG[24497]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-090374c8 [Dec 6 15:14:26] DEBUG[24497]: rtp.c:1477 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 6 15:14:26] DEBUG[24497]: app_dial.c:1640 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 6 15:14:26] DEBUG[24497]: pbx.c:2363 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-09032050' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-09032050' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"ivoc" <02222>' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '02222' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-09032050' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-090374c8' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-06 15:13:31' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-06 15:13:33' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-06 15:14:26' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '55' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '53' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1165410811.0' [Dec 6 15:14:26] DEBUG[24497]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 6 15:14:26] DEBUG[24233]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Dec 6 15:14:26] DEBUG[24233]: chan_sip.c:15035 sip_devicestate: Checking device state for peer ser [Dec 6 15:14:26] DEBUG[24233]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Dec 6 15:14:26] DEBUG[24559]: app_queue.c:546 changethread: Device 'SIP/ser' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2c51e459;rport=5060 From: "ivoc" ;tag=as7ed14cae To: ;tag=21162030-D6E Date: Wed, 06 Dec 2006 13:14:26 GMT Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE <-------------> [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2c51e459;rport=5060 (70) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as7ed14cae (63) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=21162030-D6E (53) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 4: Date: Wed, 06 Dec 2006 13:14:26 GMT (35) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 36b0916b030254d57f1a5d32467d7561@mydomain.tld (61) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 8: CSeq: 103 BYE (13) [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:4525 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #13 [Dec 6 15:14:26] DEBUG[24250]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '36b0916b030254d57f1a5d32467d7561@mydomain.tld' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '36b0916b030254d57f1a5d32467d7561@mydomain.tld' Method: ACK [Dec 6 15:14:26] DEBUG[24497]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/mydomain.tld-09032050' [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:3278 sip_hangup: Hangup call SIP/mydomain.tld-09032050, SIP callid 610575df-3d3b88fd@10.2.0.1) [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:3286 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Dec 6 15:14:26] DEBUG[24497]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 6 15:14:26] DEBUG[24497]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-09032050 [Dec 6 15:14:26] DEBUG[24233]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 6 15:14:26] DEBUG[24233]: chan_sip.c:15035 sip_devicestate: Checking device state for peer mydomain.tld [Dec 6 15:14:26] DEBUG[24233]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 6 15:14:26] DEBUG[24560]: app_queue.c:546 changethread: Device 'SIP/mydomain.tld' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. Really destroying SIP dialog '610575df-3d3b88fd@10.2.0.1' Method: BYE