Asterisk SVN-branch-1.4-r48326, 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-r48326 currently running on a-node2 (pid = 9775) n-node2*CLI> Verbosity is at least 3 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=z9hG4bK34ef.a594f283.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-a6153a90;rport=5242 From: ivoc ;tag=ba4bb301a5152650o0 To: Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 102 INVITE Max-Forwards: 69 Contact: ivoc Expires: 240 User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 262 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp X-Custom-Duration: 7200000 v=0 o=- 7631582 7631582 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=audio 16474 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 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@mydomain.tld SIP/2.0 (43) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Record-Route: (64) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK34ef.a594f283.0 (61) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-a6153a90;rport=5242 (71) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: From: ivoc ;tag=ba4bb301a5152650o0 (69) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: To: (34) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Max-Forwards: 69 (16) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Contact: ivoc (49) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: Expires: 240 (12) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: Content-Length: 262 (19) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: Supported: x-sipura (19) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 16: X-Custom-Duration: 7200000 (32) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 17: (0) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=- 7631582 7631582 IN IP4 10.2.0.1 (41) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=- (3) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=audio 16474 RTP/AVP 18 100 101 (32) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:100 192-193 (18) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=ptime:30 (10) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) --- (17 headers 13 lines) --- [Dec 7 10:15:15] WARNING[9795]: rtp.c:1889 ast_rtp_settos: Unable to set TOS to 184 [Dec 7 10:15:15] WARNING[9795]: udptl.c:846 ast_udptl_settos: UDPTL unable to set TOS to 184 [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to Off [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to Off [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for f89b6195-238d28cc@10.2.0.1 - INVITE (With RTP) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:14449 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:1670 parse_sip_options: Found SIP option: -x-sipura- [Dec 7 10:15:15] DEBUG[9795]: 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 - f89b6195-238d28cc@10.2.0.1 Found peer 'ser' [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to On [Dec 7 10:15:15] DEBUG[9795]: 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 7 10:15:15] DEBUG[9795]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.2.0.1:16474 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 7 10:15:15] DEBUG[9795]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x180108 (alaw|g729|h263|h263p), 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:16474 Peer video RTP is at port 10.2.0.1:48128 [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x100 (g729) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:13233 handle_request_invite: Checking SIP call limits for device [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Looking for 1234 in pre-process (domain mydomain.tld) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x180108 (alaw|g729|h263|h263p) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:7860 build_route: build_route: Record-Route hop: list_route: hop: [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:13306 handle_request_invite: SIP/mydomain.tld-093ba1c8: 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=z9hG4bK34ef.a594f283.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-a6153a90;rport=5242 From: ivoc ;tag=ba4bb301a5152650o0 To: Call-ID: f89b6195-238d28cc@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 7 10:15:15] DEBUG[9795]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:15] DEBUG[9778]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 7 10:15:15] DEBUG[9778]: chan_sip.c:15044 sip_devicestate: Checking device state for peer mydomain.tld [Dec 7 10:15:15] DEBUG[9907]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' [Dec 7 10:15:15] DEBUG[9778]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-093ba1c8", "X-Custom-Test3: ") in new stack [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:16809 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Dec 7 10:15:15] DEBUG[9907]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-093ba1c8", "X-Custom-Network: class4") in new stack [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:16809 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Dec 7 10:15:15] DEBUG[9907]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-093ba1c8", "SIP/1234@ser") in new stack [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:15102 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Dec 7 10:15:15] WARNING[9907]: rtp.c:1889 ast_rtp_settos: Unable to set TOS to 184 [Dec 7 10:15:15] DEBUG[9908]: 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. [Dec 7 10:15:15] WARNING[9907]: udptl.c:846 ast_udptl_settos: UDPTL unable to set TOS to 184 [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2605 create_addr_from_peer: Our T38 capability (3856) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to On [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x180108 (alaw|g729|h263|h263p) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3771 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 7 10:15:15] DEBUG[9907]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2812 sip_call: Outgoing Call for 1234 [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:2826 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6757 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6757 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6120 add_sdp: ** Our capability: 0x180108 (alaw|g729|h263|h263p) Video flag: False [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6121 add_sdp: ** Our prefcodec: 0x100 (g729) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6136 add_sdp: This call needs video offers! Video is at 10.0.0.2 port 16540 Audio is at 10.0.0.2 port 17960 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x80000 (h263) to SDP Adding codec 0x100000 (h263p) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6252 add_sdp: -- Done with adding codecs to SDP [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:6297 add_sdp: Done building SDP. Settling with this capability: 0x180108 (alaw|g729|h263|h263p) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (45) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK50ab84b6;rport (65) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as69f19785 (63) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 3: To: (36) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 4: Contact: (39) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 7: User-Agent: Asterisk (27) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 9: Remote-Party-ID: "ivoc" ;privacy=off;screen=no (81) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 10: Date: Thu, 07 Dec 2006 08:15:15 GMT (35) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 12: Supported: replaces (19) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 13: X-Custom-Network: class4 (26) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 14: X-Custom-Test3: (24) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 16: Content-Length: 395 (19) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4525 parse_request: Header 17: (0) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: o=root 9775 9775 IN IP4 10.0.0.2 (38) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: s=session (9) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: b=CT:384 (8) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: m=audio 17960 RTP/AVP 18 8 101 (30) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: m=video 16540 RTP/AVP 34 103 (28) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:4557 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Dec 7 10:15:15] DEBUG[9907]: 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=z9hG4bK50ab84b6;rport From: "ivoc" ;tag=as69f19785 To: Contact: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Date: Thu, 07 Dec 2006 08:15:15 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: 395 v=0 o=root 9775 9775 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 b=CT:384 t=0 0 m=audio 17960 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 m=video 16540 RTP/AVP 34 103 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=sendrecv --- [Dec 7 10:15:15] DEBUG[9907]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #4 -- Called 1234@ser a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK50ab84b6;rport=5060 From: "ivoc" ;tag=as69f19785 To: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld CSeq: 102 INVITE Server: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK50ab84b6;rport=5060 (70) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as69f19785 (63) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: To: (36) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: OpenSER (1.1.0-notls (i386/linux)) (50) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #4 - INVITE (got response) [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' Request 102: Found [Dec 7 10:15:15] DEBUG[9795]: chan_sip.c:11529 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=z9hG4bK50ab84b6;rport=5060 From: "ivoc" ;tag=as69f19785 To: ;tag=252B6800-16EA Date: Thu, 07 Dec 2006 08:15:15 GMT Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@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: 345 v=0 o=CiscoSystemsSIP-GW-UserAgent 525 9109 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 16656 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 - - - - m=video 0 RTP/AVP 34 c=IN IP4 10.3.0.1 <-------------> [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK50ab84b6;rport=5060 (70) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as69f19785 (63) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=252B6800-16EA (54) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: Date: Thu, 07 Dec 2006 08:15:15 GMT (35) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Allow-Events: telephone-event (29) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: Contact: (45) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Record-Route: (56) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: Content-Length: 345 (19) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 525 9109 IN IP4 10.3.0.1 (60) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=audio 16656 RTP/AVP 18 101 (28) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (15 headers 15 lines) --- [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' Request 102: Found [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:11529 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:16656 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 7 10:15:16] DEBUG[9795]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel SIP/ser-093cfc38 Capabilities: us - 0x180108 (alaw|g729|h263|h263p), peer - audio=0x80100 (g729|h263)/video=0x80000 (h263), combined - 0x80100 (g729|h263) 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:16656 [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Dec 7 10:15:16] DEBUG[9795]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call -- SIP/ser-093cfc38 is making progress passing it to SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:16] DEBUG[9907]: chan_sip.c:6352 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 7 10:15:16] DEBUG[9907]: chan_sip.c:6120 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Dec 7 10:15:16] DEBUG[9907]: chan_sip.c:6121 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 18568 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 7 10:15:16] DEBUG[9907]: chan_sip.c:6252 add_sdp: -- Done with adding codecs to SDP [Dec 7 10:15:16] DEBUG[9907]: chan_sip.c:6297 add_sdp: Done building SDP. Settling with this capability: 0x100 (g729) <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK34ef.a594f283.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-a6153a90;rport=5242 From: ivoc ;tag=ba4bb301a5152650o0 To: ;tag=as28273689 Call-ID: f89b6195-238d28cc@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: 265 v=0 o=root 9775 9775 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 18568 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 7 10:15:16] DEBUG[9907]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to g729 [Dec 7 10:15:16] DEBUG[9907]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Dec 7 10:15:16] DEBUG[9907]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to g729 [Dec 7 10:15:16] DEBUG[9907]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Dec 7 10:15:17] DEBUG[9907]: rtp.c:866 ast_rtcp_read: Got RTCP report of 88 bytes 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=z9hG4bK50ab84b6;rport=5060 From: "ivoc" ;tag=as69f19785 To: ;tag=252B6800-16EA Date: Thu, 07 Dec 2006 08:15:15 GMT Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@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: 345 v=0 o=CiscoSystemsSIP-GW-UserAgent 525 9109 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 16656 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 - - - - m=video 0 RTP/AVP 34 c=IN IP4 10.3.0.1 <-------------> [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK50ab84b6;rport=5060 (70) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as69f19785 (63) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=252B6800-16EA (54) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: Date: Thu, 07 Dec 2006 08:15:15 GMT (35) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Allow-Events: telephone-event (29) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: Contact: (45) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Record-Route: (56) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Content-Length: 345 (19) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: (0) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 525 9109 IN IP4 10.3.0.1 (60) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=audio 16656 RTP/AVP 18 101 (28) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (14 headers 15 lines) --- [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' of Request 102: Match Not Found [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:11529 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:16656 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 7 10:15:19] DEBUG[9795]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel SIP/ser-093cfc38 Capabilities: us - 0x180108 (alaw|g729|h263|h263p), peer - audio=0x80100 (g729|h263)/video=0x80000 (h263), combined - 0x80100 (g729|h263) 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:16656 [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:7860 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=z9hG4bK6095d7b3;rport Route: From: "ivoc" ;tag=as69f19785 To: ;tag=252B6800-16EA Contact: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Dec 7 10:15:19] DEBUG[9907]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-093cfc38 -- SIP/ser-093cfc38 answered SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:19] DEBUG[9907]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:3428 sip_answer: SIP answering channel: SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:6352 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:6120 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:6121 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 18568 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:6252 add_sdp: -- Done with adding codecs to SDP [Dec 7 10:15:19] DEBUG[9907]: chan_sip.c:6297 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=z9hG4bK34ef.a594f283.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-a6153a90;rport=5242 Record-Route: From: ivoc ;tag=ba4bb301a5152650o0 To: ;tag=as28273689 Call-ID: f89b6195-238d28cc@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: 265 v=0 o=root 9775 9776 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 18568 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 7 10:15:19] DEBUG[9907]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #8 [Dec 7 10:15:19] DEBUG[9907]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Dec 7 10:15:19] DEBUG[9778]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Dec 7 10:15:19] DEBUG[9778]: chan_sip.c:15044 sip_devicestate: Checking device state for peer ser [Dec 7 10:15:19] DEBUG[9778]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Dec 7 10:15:19] DEBUG[9778]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 7 10:15:19] DEBUG[9778]: chan_sip.c:15044 sip_devicestate: Checking device state for peer mydomain.tld [Dec 7 10:15:19] DEBUG[9909]: 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 7 10:15:19] DEBUG[9778]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 7 10:15:19] DEBUG[9910]: 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 ---> ACK sip:1234@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK34ef.a594f283.2 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-ddb2ddf;rport=5242 From: ivoc ;tag=ba4bb301a5152650o0 To: ;tag=as28273689 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 102 ACK Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="4577cebf3752088f2f9d92ae2058e91db9772e5d",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="9981af037bcde3026e99c77d11acfe53" Contact: ivoc User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: ACK sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK34ef.a594f283.2 (61) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-ddb2ddf;rport=5242 (70) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: From: ivoc ;tag=ba4bb301a5152650o0 (69) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: To: ;tag=as28273689 (49) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: CSeq: 102 ACK (13) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Max-Forwards: 69 (16) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="4577cebf3752088f2f9d92ae2058e91db9772e5d",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="9981af037bcde3026e99c77d11acfe53" (218) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Contact: ivoc (49) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Content-Length: 0 (17) [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:14449 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #8 [Dec 7 10:15:19] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on 'f89b6195-238d28cc@10.2.0.1' of Response 102: Match Not Found [Dec 7 10:15:19] NOTICE[9907]: rtp.c:772 process_rfc3389: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client IP: 10.3.0.1 [Dec 7 10:15:20] DEBUG[9907]: rtp.c:866 ast_rtcp_read: Got RTCP report of 132 bytes [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:22] DEBUG[9907]: chan_sip.c:4044 sip_rtp_read: Oooh, format changed to 8 [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/ser-093cfc38 to read format g729 [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/ser-093cfc38 to write format g729 [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/mydomain.tld-093ba1c8 to read format slin [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/ser-093cfc38 to write format slin [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/ser-093cfc38 to read format slin [Dec 7 10:15:22] DEBUG[9907]: channel.c:2731 set_format: Set channel SIP/mydomain.tld-093ba1c8 to write format slin [Dec 7 10:15:22] DEBUG[9907]: rtp.c:2621 ast_rtp_write: Ooh, format changed from g729 to alaw [Dec 7 10:15:22] DEBUG[9907]: rtp.c:2638 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:22] NOTICE[9907]: rtp.c:1272 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Dec 7 10:15:25] DEBUG[9907]: rtp.c:866 ast_rtcp_read: Got RTCP report of 72 bytes a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:2222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bKA7E1130A From: ;tag=252B6800-16EA To: "ivoc" ;tag=as69f19785 Date: Thu, 07 Dec 2006 08:15:25 GMT Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 3873290008-2231439835-2690963382-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: 1165479325 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 768 v=0 o=CiscoSystemsSIP-GW-UserAgent 525 9110 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 16656 udptl 101 t38 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=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 m=video 0 RTP/AVP 34 c=IN IP4 10.3.0.1 <-------------> [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 (61) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bKA7E1130A (59) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=252B6800-16EA (56) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as69f19785 (61) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Date: Thu, 07 Dec 2006 08:15:25 GMT (35) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Min-SE: 1800 (13) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Cisco-Guid: 3873290008-2231439835-2690963382-1321745574 (55) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: CSeq: 101 INVITE (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Max-Forwards: 69 (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: Timestamp: 1165479325 (21) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 15: Contact: (45) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 16: Expires: 180 (12) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 17: Allow-Events: telephone-event (29) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 18: Content-Type: application/sdp (29) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 19: Content-Length: 768 (19) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 20: (0) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 525 9110 IN IP4 10.3.0.1 (60) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=image 16656 udptl 101 t38 t38 (31) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (20 headers 30 lines) --- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14449 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1662 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,replaces" [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1670 parse_sip_options: Found SIP option: -100rel- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1676 parse_sip_options: Matched SIP option: 100rel [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1670 parse_sip_options: Found SIP option: -timer- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1676 parse_sip_options: Matched SIP option: timer [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1670 parse_sip_options: Found SIP option: -replaces- [Dec 7 10:15:25] DEBUG[9795]: 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 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4782 process_sdp: T38 state changed to 4 on channel SIP/ser-093cfc38 Found RTP video format 34 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4832 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:16656 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 7200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5012 process_sdp: FillBitRemoval: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5018 process_sdp: Transcoding MMR: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5025 process_sdp: Transcoding JBIG: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 72 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 7200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5012 process_sdp: FillBitRemoval: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5018 process_sdp: Transcoding MMR: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5025 process_sdp: Transcoding JBIG: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 72 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5059 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x180108 (alaw|g729|h263|h263p), peer - audio=0x80000 (h263)/video=0x80000 (h263), combined - 0x80000 (h263) 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:16656 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x80000 (h263) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5155 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x80000 (h263) and not 0x8 (alaw) [Dec 7 10:15:25] DEBUG[9795]: frame.c:1252 ast_codec_choose: Could not find preferred codec - Going for the best codec [Dec 7 10:15:25] WARNING[9795]: channel.c:627 ast_best_codec: Don't know any of 0x0 formats [Dec 7 10:15:25] WARNING[9795]: channel.c:2702 set_format: Unable to find a codec translation path from h263 to slin [Dec 7 10:15:25] WARNING[9795]: channel.c:2702 set_format: Unable to find a codec translation path from h263 to slin [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:13284 handle_request_invite: Got a SIP re-invite for call 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:13379 handle_request_invite: SIP/ser-093cfc38: This call is UP.... [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:16556 sip_handle_t38_reinvite: Sending reinvite on SIP 'f89b6195-238d28cc@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 7 10:15:25] DEBUG[9795]: chan_sip.c:5973 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4877 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5979 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5910 t38_get_rate: T38MaxFaxRate 7200 found [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1603 initialize_initreq: Initializing already initialized SIP dialog f89b6195-238d28cc@10.2.0.1 (presumably reinvite) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:2222@10.2.0.1:5242 SIP/2.0 (48) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport (65) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: Route: (57) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=as28273689 (51) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: To: ivoc ;tag=ba4bb301a5152650o0 (67) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Contact: (34) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: User-Agent: Asterisk (27) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Max-Forwards: 70 (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Supported: replaces (19) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: Content-Length: 261 (19) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=root 9775 9777 IN IP4 10.0.0.2 (38) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=session (9) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=image 4877 udptl t38 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) Reliably Transmitting (NAT) to 10.0.0.1:5060: INVITE sip:2222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport Route: From: ;tag=as28273689 To: ivoc ;tag=ba4bb301a5152650o0 Contact: Call-ID: f89b6195-238d28cc@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 9775 9777 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4877 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 7 10:15:25] DEBUG[9795]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [Dec 7 10:15:25] WARNING[9907]: channel.c:3033 ast_channel_make_compatible: No path to translate from SIP/mydomain.tld-093ba1c8(256) to SIP/ser-093cfc38(524288) [Dec 7 10:15:25] WARNING[9907]: channel.c:3958 ast_channel_bridge: Can't make SIP/mydomain.tld-093ba1c8 and SIP/ser-093cfc38 compatible [Dec 7 10:15:25] WARNING[9907]: res_features.c:1415 ast_bridge_call: Bridge failed on channels SIP/mydomain.tld-093ba1c8 and SIP/ser-093cfc38 [Dec 7 10:15:25] DEBUG[9907]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/ser-093cfc38' [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:3278 sip_hangup: Hangup call SIP/ser-093cfc38, SIP callid 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld) [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:3286 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call Scheduling destruction of SIP dialog '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' in 32000 ms (Method: INVITE) [Dec 7 10:15:25] DEBUG[9907]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-093cfc38 [Dec 7 10:15:25] DEBUG[9907]: rtp.c:1477 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 7 10:15:25] DEBUG[9907]: app_dial.c:1640 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 7 10:15:25] DEBUG[9907]: pbx.c:2363 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-093ba1c8' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-093ba1c8' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"ivoc" <2222>' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2222' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-093ba1c8' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-093cfc38' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-07 10:15:15' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-07 10:15:19' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-07 10:15:25' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '10' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '6' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1165479315.0' [Dec 7 10:15:25] DEBUG[9907]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport=5060 From: ;tag=as28273689 To: ivoc ;tag=ba4bb301a5152650o0 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 102 INVITE Server: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport=5060 (70) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=as28273689 (51) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: To: ivoc ;tag=ba4bb301a5152650o0 (67) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: OpenSER (1.1.0-notls (i386/linux)) (50) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9778]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Dec 7 10:15:25] DEBUG[9778]: chan_sip.c:15044 sip_devicestate: Checking device state for peer ser [Dec 7 10:15:25] DEBUG[9778]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9911]: 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 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:14636 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9907]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/mydomain.tld-093ba1c8' [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:3278 sip_hangup: Hangup call SIP/mydomain.tld-093ba1c8, SIP callid f89b6195-238d28cc@10.2.0.1) [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:3286 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Dec 7 10:15:25] DEBUG[9907]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog 'f89b6195-238d28cc@10.2.0.1' in 32000 ms (Method: ACK) [Dec 7 10:15:25] DEBUG[9907]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-093ba1c8 [Dec 7 10:15:25] DEBUG[9778]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 7 10:15:25] DEBUG[9778]: chan_sip.c:15044 sip_devicestate: Checking device state for peer mydomain.tld [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #9 - INVITE (got response) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on 'f89b6195-238d28cc@10.2.0.1' Request 102: Found [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:11529 handle_response_invite: SIP response 100 to standard invite 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:2222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK745881fa;rport Route: From: ;tag=as28273689 To: ivoc ;tag=ba4bb301a5152650o0 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12 Scheduling destruction of SIP dialog 'f89b6195-238d28cc@10.2.0.1' in 32000 ms (Method: ACK) <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ivoc ;tag=ba4bb301a5152650o0 From: ;tag=as28273689 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport=5060 Contact: ivoc Server: Linksys/SPA2102-3.3.6 Content-Length: 271 Content-Type: application/sdp v=0 o=- 7632583 7632583 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=image 16474 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: To: ivoc ;tag=ba4bb301a5152650o0 (67) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=as28273689 (51) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: CSeq: 102 INVITE (16) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK2b9be2c8;rport=5060 (70) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Contact: ivoc (49) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Content-Length: 271 (19) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Content-Type: application/sdp (29) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=- 7632583 7632583 IN IP4 10.2.0.1 (41) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=- (3) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=image 16474 udptl t38 (23) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:14400 (21) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on 'f89b6195-238d28cc@10.2.0.1' of Request 102: Match Not Found [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:11529 handle_response_invite: SIP response 200 to standard invite Got T.38 offer in SDP in dialog f89b6195-238d28cc@10.2.0.1 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4786 process_sdp: T38 state changed to 3 on channel [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4832 process_sdp: Peer T.38 UDPTL is at port 10.2.0.1:16474 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid f89b6195-238d28cc@10.2.0.1 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4998 process_sdp: FaxVersion: 0 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4974 process_sdp: T38MaxBitRate: 14400 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5031 process_sdp: RateMangement: transferredTCF [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:4970 process_sdp: MaxBufferSize:200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5006 process_sdp: FaxMaxDatagram: 200 [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5039 process_sdp: UDP EC: t38UDPRedundancy [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5059 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x180108 (alaw|g729|h263|h263p), 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 7 10:15:25] DEBUG[9795]: chan_sip.c:5101 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:7889 build_route: build_route: Contact hop: ivoc list_route: hop: [Dec 7 10:15:25] DEBUG[9795]: chan_sip.c:5574 reqprep: Strict routing enforced for session f89b6195-238d28cc@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:2222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1fc3e4ce;rport From: ;tag=as28273689 To: ivoc ;tag=ba4bb301a5152650o0 Contact: Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- [Dec 7 10:15:25] DEBUG[9778]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 7 10:15:25] DEBUG[9912]: 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. [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:1848 retrans_pkt: SIP TIMER: Rescheduling retransmission #12 (1) BYE - 8 [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:1862 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #12)) Retransmitting #1 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5242 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK745881fa;rport Route: From: ;tag=as28273689 To: ivoc ;tag=ba4bb301a5152650o0 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:2222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bKA7E1130A From: ;tag=252B6800-16EA To: "ivoc" ;tag=as69f19785 Date: Thu, 07 Dec 2006 08:15:25 GMT Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 3873290008-2231439835-2690963382-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: 1165479325 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 768 v=0 o=CiscoSystemsSIP-GW-UserAgent 525 9110 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 16656 udptl 101 t38 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=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 m=video 0 RTP/AVP 34 c=IN IP4 10.3.0.1 <-------------> [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 (61) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bKA7E1130A (59) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: From: ;tag=252B6800-16EA (56) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as69f19785 (61) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Date: Thu, 07 Dec 2006 08:15:25 GMT (35) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Min-SE: 1800 (13) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: Cisco-Guid: 3873290008-2231439835-2690963382-1321745574 (55) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 12: CSeq: 101 INVITE (16) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 13: Max-Forwards: 69 (16) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 14: Timestamp: 1165479325 (21) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 15: Contact: (45) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 16: Expires: 180 (12) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 17: Allow-Events: telephone-event (29) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 18: Content-Type: application/sdp (29) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 19: Content-Length: 768 (19) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 20: (0) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 525 9110 IN IP4 10.3.0.1 (60) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=image 16656 udptl 101 t38 t38 (31) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxVersion:0 (17) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38MaxBitRate:7200 (20) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (20 headers 30 lines) --- [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:14449 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:14468 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:13286 handle_request_invite: Got a SIP re-transmit of INVITE for call 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld [Dec 7 10:15:26] NOTICE[9795]: chan_sip.c:13475 handle_request_invite: Unable to create/find SIP channel for this INVITE <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 503 Unavailable Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bKA7E1130A From: ;tag=252B6800-16EA To: "ivoc" ;tag=as69f19785 Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld CSeq: 101 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> Scheduling destruction of SIP dialog '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' in 32000 ms (Method: INVITE) <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ivoc ;tag=ba4bb301a5152650o0 From: ;tag=as28273689 Call-ID: f89b6195-238d28cc@10.2.0.1 CSeq: 103 BYE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK745881fa;rport=5060 Server: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: To: ivoc ;tag=ba4bb301a5152650o0 (67) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=as28273689 (51) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: Call-ID: f89b6195-238d28cc@10.2.0.1 (41) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: CSeq: 103 BYE (13) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK745881fa;rport=5060 (70) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: Linksys/SPA2102-3.3.6 (29) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Dec 7 10:15:26] DEBUG[9795]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on 'f89b6195-238d28cc@10.2.0.1' of Request 103: Match Not Found Really destroying SIP dialog 'f89b6195-238d28cc@10.2.0.1' Method: ACK <--- SIP read from 10.0.0.1:5060 ---> ACK sip:2222@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 From: ;tag=252B6800-16EA Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld To: "ivoc" ;tag=as69f19785 CSeq: 101 ACK Route: User-Agent: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: ACK sip:2222@10.0.0.2:5060 SIP/2.0 (45) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK8351.24be79e3.0 (61) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=252B6800-16EA (56) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: To: "ivoc" ;tag=as69f19785 (61) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: CSeq: 101 ACK (13) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Route: (49) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: User-Agent: OpenSER (1.1.0-notls (i386/linux)) (54) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: Content-Length: 0 (17) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:14449 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' of Response 101: Match Found 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=z9hG4bK5fab4e10;rport Route: From: "ivoc" ;tag=as69f19785 To: ;tag=252B6800-16EA Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15 Scheduling destruction of SIP dialog '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' in 32000 ms (Method: ACK) 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=z9hG4bK5fab4e10;rport=5060 From: "ivoc" ;tag=as69f19785 To: ;tag=252B6800-16EA Date: Thu, 07 Dec 2006 08:15:27 GMT Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE <-------------> [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5fab4e10;rport=5060 (70) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 2: From: "ivoc" ;tag=as69f19785 (63) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=252B6800-16EA (54) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 4: Date: Thu, 07 Dec 2006 08:15:27 GMT (35) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld (61) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 8: CSeq: 103 BYE (13) [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:4525 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #15 [Dec 7 10:15:27] DEBUG[9795]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '2430da6e286195ab6327ebcb6ef37b9c@mydomain.tld' Method: ACK