Asterisk SVN-branch-1.4-r51360, 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-r51360 currently running on a-node2 (pid = 11344) Verbosity is at least 4 -- Remote UNIX connection <--- 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=z9hG4bK0c63.86762dd5.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-61f9053d;rport=5242 From: ivoc ;tag=e9b7a6b94932b565o0 To: Call-ID: b308f049-26ef7915@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=- 7348811 7348811 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=audio 16386 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 <-------------> [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:1234@mydomain.tld SIP/2.0 (43) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Record-Route: (64) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0c63.86762dd5.0 (61) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-61f9053d;rport=5242 (71) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: From: ivoc ;tag=e9b7a6b94932b565o0 (69) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: To: (34) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Max-Forwards: 69 (16) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Contact: ivoc (49) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Expires: 240 (12) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Length: 262 (19) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Supported: x-sipura (19) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Content-Type: application/sdp (29) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: X-Custom-Duration: 7200000 (32) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: (0) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=- 7348811 7348811 IN IP4 10.2.0.1 (41) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=- (3) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 16386 RTP/AVP 18 100 101 (32) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:100 192-193 (18) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-15 (15) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:30 (10) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=sendrecv (10) --- (17 headers 13 lines) --- [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to Off [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to Off [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to Off [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4286 sip_alloc: Allocating new SIP dialog for b308f049-26ef7915@10.2.0.1 - INVITE (With RTP) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -x-sipura- [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:1700 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 - b308f049-26ef7915@10.2.0.1 Found peer 'ser' [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On Found RTP audio format 18 Found RTP audio format 100 Found RTP audio format 101 [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4862 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.2.0.1:16386 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 [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x18050a (gsm|alaw|g729|ilbc|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:16386 Peer video RTP is at port 10.2.0.1:25015 [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x100 (g729) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:13327 handle_request_invite: Checking SIP call limits for device [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2996 update_call_counter: Updating call counter for incoming call Looking for 1234 in pre-process (domain mydomain.tld) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:3788 sip_new: *** Our native formats are 0x100 (g729) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:3789 sip_new: *** Joint capabilities are 0x100 (g729) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:3790 sip_new: *** Our capabilities are 0x18050a (gsm|alaw|g729|ilbc|h263|h263p) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:3791 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:3814 sip_new: This channel will not be able to handle video. [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:7895 build_route: build_route: Record-Route hop: list_route: hop: [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:13402 handle_request_invite: SIP/mydomain.tld-082384c8: 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=z9hG4bK0c63.86762dd5.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-61f9053d;rport=5242 From: ivoc ;tag=e9b7a6b94932b565o0 To: Call-ID: b308f049-26ef7915@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 <------------> [Jan 24 11:16:22] DEBUG[11352]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-082384c8 [Jan 24 11:16:22] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 11:16:22] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld [Jan 24 11:16:22] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Jan 24 11:16:22] DEBUG[14147]: pbx.c:1770 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-082384c8", "X-Custom-Test3: ") in new stack [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:16883 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Jan 24 11:16:22] DEBUG[14147]: pbx.c:1770 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-082384c8", "X-Custom-Network: class4") in new stack [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:16883 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Jan 24 11:16:22] DEBUG[14147]: pbx.c:1770 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-082384c8", "SIP/1234@ser") in new stack [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:15192 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4286 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2621 create_addr_from_peer: Our T38 capability (3856) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3788 sip_new: *** Our native formats are 0x100 (g729) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3789 sip_new: *** Joint capabilities are 0x0 (nothing) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3790 sip_new: *** Our capabilities are 0x18050a (gsm|alaw|g729|ilbc|h263|h263p) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3791 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3793 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:3814 sip_new: This channel will not be able to handle video. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable NODE_IP. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_DB. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable EMER_NUMS. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Jan 24 11:16:22] DEBUG[14147]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPURI. [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2830 sip_call: Outgoing Call for 1234 [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:2844 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6788 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6788 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6151 add_sdp: ** Our capability: 0x18050a (gsm|alaw|g729|ilbc|h263|h263p) Video flag: False [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x100 (g729) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6167 add_sdp: This call needs video offers! Video is at 10.0.0.2 port 17708 Audio is at 10.0.0.2 port 16020 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x400 (ilbc) to SDP Adding codec 0x80000 (h263) to SDP Adding codec 0x100000 (h263p) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:6328 add_sdp: Done building SDP. Settling with this capability: 0x18050a (gsm|alaw|g729|ilbc|h263|h263p) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (45) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5e82b6d9;rport (65) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as31b873fa (63) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 3: To: (36) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 4: Contact: (39) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 6: CSeq: 102 INVITE (16) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 7: User-Agent: Asterisk(27) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 9: Remote-Party-ID: "ivoc" ;privacy=off;screen=no (81) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 10: Date: Wed, 24 Jan 2007 09:16:22 GMT (35) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 12: Supported: replaces (19) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 13: X-Custom-Network: class4 (26) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 14: X-Custom-Test3: (24) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 15: Content-Type: application/sdp (29) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 16: Content-Length: 465 (19) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4549 parse_request: Header 17: (0) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: o=root 11344 11344 IN IP4 10.0.0.2 (40) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: s=session (9) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: b=CT:384 (8) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: m=audio 16020 RTP/AVP 18 8 3 97 101 (35) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=fmtp:97 mode=30 (17) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=sendrecv (10) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: m=video 17708 RTP/AVP 34 103 (28) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:4581 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=z9hG4bK5e82b6d9;rport From: "ivoc" ;tag=as31b873fa To: Contact: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Date: Wed, 24 Jan 2007 09:16:22 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: 465 v=0 o=root 11344 11344 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 b=CT:384 t=0 0 m=audio 16020 RTP/AVP 18 8 3 97 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 =rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 17708 RTP/AVP 34 103 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=sendrecv --- [Jan 24 11:16:22] DEBUG[14147]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #48 -- Called 1234@ser a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5e82b6d9;rport=5060 From: "ivoc" ;tag=as31b873fa To: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld CSeq: 102 INVITE Server: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5e82b6d9;rport=5060 (70) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as31b873fa (63) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: (36) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: OpenSer (1.1.0-notls (i386/linux)) (42) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #48 - INVITE (got response) [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4b445dc2709de7436136115a4b88bea0@mydomain.tld' Request 102: Found [Jan 24 11:16:22] DEBUG[11352]: chan_sip.c:11576 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=z9hG4bK5e82b6d9;rport=5060 From: "ivoc" ;tag=as31b873fa To: ;tag=1C941C78-BA3 Date: Wed, 24 Jan 2007 09:16:22 GMT Call-ID: 4b445dc2709de7436136115a4b88bea0@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: 346 v=0 o=CiscoSystemsSIP-GW-UserAgent 8636 9791 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 18320 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 <-------------> [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5e82b6d9;rport=5060 (70) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as31b873fa (63) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C941C78-BA3 (53) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 09:16:22 GMT (35) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Allow-Events: telephone-event (29) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Contact: (45) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Record-Route: (56) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Type: application/sdp (29) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Content-Length: 346 (19) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: (0) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8636 9791 IN IP4 10.3.0.1 (61) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 18320 RTP/AVP 18 101 (28) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (15 headers 15 lines) --- [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4b445dc2709de7436136115a4b88bea0@mydomain.tld' Request 102: Found [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:11576 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:4862 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:18320 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 [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel SIP/ser-08228cf8 Capabilities: us - 0x18050a (gsm|alaw|g729|ilbc|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:18320 [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Jan 24 11:16:23] DEBUG[11352]: chan_sip.c:5176 process_sdp: We have an owner, now see if we need to change this call -- SIP/ser-08228cf8 is making progress passing it to SIP/mydomain.tld-082384c8 [Jan 24 11:16:23] DEBUG[14147]: chan_sip.c:6383 transmit_response_with_sdp: Setting framing from config on incoming call [Jan 24 11:16:23] DEBUG[14147]: chan_sip.c:6151 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Jan 24 11:16:23] DEBUG[14147]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 19290 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 11:16:23] DEBUG[14147]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 11:16:23] DEBUG[14147]: chan_sip.c:6328 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=z9hG4bK0c63.86762dd5.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-61f9053d;rport=5242 From: ivoc ;tag=e9b7a6b94932b565o0 To: ;tag=as3709cca5 Call-ID: b308f049-26ef7915@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 11344 11344 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 19290 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 <------------> [Jan 24 11:16:23] DEBUG[14147]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Jan 24 11:16:23] DEBUG[14147]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Jan 24 11:16:23] DEBUG[14147]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Jan 24 11:16:23] DEBUG[14147]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Jan 24 11:16:24] DEBUG[14147]: rtp.c:871 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=z9hG4bK5e82b6d9;rport=5060 From: "ivoc" ;tag=as31b873fa To: ;tag=1C941C78-BA3 Date: Wed, 24 Jan 2007 09:16:22 GMT Call-ID: 4b445dc2709de7436136115a4b88bea0@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: 346 v=0 o=CiscoSystemsSIP-GW-UserAgent 8636 9791 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 18320 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 <-------------> [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK5e82b6d9;rport=5060 (70) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as31b873fa (63) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C941C78-BA3 (53) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 09:16:22 GMT (35) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Allow-Events: telephone-event (29) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Contact: (45) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Record-Route: (56) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Length: 346 (19) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: (0) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8636 9791 IN IP4 10.3.0.1 (61) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 18320 RTP/AVP 18 101 (28) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (14 headers 15 lines) --- [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '4b445dc2709de7436136115a4b88bea0@mydomain.tld' of Request 102: Match Not Found [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:11576 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4862 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:18320 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 [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel SIP/ser-08228cf8 Capabilities: us - 0x18050a (gsm|alaw|g729|ilbc|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:18320 [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:5176 process_sdp: We have an owner, now see if we need to change this call [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:7895 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=z9hG4bK003ba27b;rport Route: From: "ivoc" ;tag=as31b873fa To: ;tag=1C941C78-BA3 Contact: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Jan 24 11:16:26] DEBUG[14147]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08228cf8 -- SIP/ser-08228cf8 answered SIP/mydomain.tld-082384c8 [Jan 24 11:16:26] DEBUG[14147]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-082384c8 [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:3446 sip_answer: SIP answering channel: SIP/mydomain.tld-082384c8 [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:6383 transmit_response_with_sdp: Setting framing from config on incoming call [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:6151 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 19290 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:6328 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=z9hG4bK0c63.86762dd5.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-61f9053d;rport=5242 Record-Route: From: ivoc ;tag=e9b7a6b94932b565o0 To: ;tag=as3709cca5 Call-ID: b308f049-26ef7915@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 11344 11345 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 19290 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 <------------> [Jan 24 11:16:26] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Jan 24 11:16:26] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer ser [Jan 24 11:16:26] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Jan 24 11:16:26] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 11:16:26] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld [Jan 24 11:16:26] DEBUG[14147]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #52 [Jan 24 11:16:26] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Jan 24 11:16:26] DEBUG[14147]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Jan 24 11:16:26] NOTICE[14147]: rtp.c:781 process_rfc3389: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client IP: 10.3.0.1 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=z9hG4bK0c63.86762dd5.2 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-ac2b4a81;rport=5242 From: ivoc ;tag=e9b7a6b94932b565o0 To: ;tag=as3709cca5 Call-ID: b308f049-26ef7915@10.2.0.1 CSeq: 102 ACK Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b72512b19b1b903576215758650b79b66dbebc",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="b041cd5a43b30cc80dda9667831e00ec" Contact: ivoc User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: ACK sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0c63.86762dd5.2 (61) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-ac2b4a81;rport=5242 (71) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ivoc ;tag=e9b7a6b94932b565o0 (69) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: ;tag=as3709cca5 (49) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: CSeq: 102 ACK (13) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Max-Forwards: 69 (16) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b72512b19b1b903576215758650b79b66dbebc",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="b041cd5a43b30cc80dda9667831e00ec" (218) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Contact: ivoc (49) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Content-Length: 0 (17) [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #52 [Jan 24 11:16:26] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'b308f049-26ef7915@10.2.0.1' of Response 102: Match Not Found [Jan 24 11:16:27] DEBUG[14147]: rtp.c:871 ast_rtcp_read: Got RTCP report of 132 bytes [Jan 24 11:16:28] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:28] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:29] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:29] DEBUG[14147]: chan_sip.c:4068 sip_rtp_read: Oooh, format changed to 8 [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/ser-08228cf8 to read format g729 [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/ser-08228cf8 to write format g729 [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/mydomain.tld-082384c8 to read format slin [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/ser-08228cf8 to write format slin [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/ser-08228cf8 to read format slin [Jan 24 11:16:29] DEBUG[14147]: channel.c:2836 set_format: Set channel SIP/mydomain.tld-082384c8 to write format slin [Jan 24 11:16:29] DEBUG[14147]: rtp.c:2670 ast_rtp_write: Ooh, format changed from g729 to alaw [Jan 24 11:16:29] DEBUG[14147]: rtp.c:2687 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Jan 24 11:16:29] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:29] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:29] NOTICE[14147]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Jan 24 11:16:32] DEBUG[14147]: rtp.c:871 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=z9hG4bK84a2.6fb114e6.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D82D1CE9 From: ;tag=1C941C78-BA3 To: "ivoc" ;tag=as31b873fa Date: Wed, 24 Jan 2007 09:16:32 GMT Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 1683887896-2864845275-2961037238-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: 1169630192 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 769 v=0 o=CiscoSystemsSIP-GW-UserAgent 8636 9792 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 18320 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 <-------------> [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK84a2.6fb114e6.0 (61) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D82D1CE9 (60) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C941C78-BA3 (55) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as31b873fa (61) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 09:16:32 GMT (35) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Min-SE: 1800 (13) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Cisco-Guid: 1683887896-2864845275-2961037238-1321745574 (55) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: CSeq: 101 INVITE (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Max-Forwards: 69 (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Timestamp: 1169630192 (21) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Contact: (45) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: Expires: 180 (12) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: Allow-Events: telephone-event (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 18: Content-Type: application/sdp (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 19: Content-Length: 769 (19) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 20: (0) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8636 9792 IN IP4 10.3.0.1 (61) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 18320 udptl 101 t38 t38 (31) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (20 headers 30 lines) --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,replaces" [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -100rel- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1694 parse_sip_options: Matched SIP option: 100rel [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -timer- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1694 parse_sip_options: Matched SIP option: timer [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -replaces- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1694 parse_sip_options: Matched SIP option: replaces Sending to 10.0.0.1 : 5060 (NAT) Got T.38 offer in SDP in dialog 4b445dc2709de7436136115a4b88bea0@mydomain.tld [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4808 process_sdp: T38 state changed to 4 on channel SIP/ser-08228cf8 Found RTP video format 34 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4858 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:18320 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 4b445dc2709de7436136115a4b88bea0@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 7200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5038 process_sdp: FillBitRemoval: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5044 process_sdp: Transcoding MMR: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5051 process_sdp: Transcoding JBIG: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 72 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 7200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5038 process_sdp: FillBitRemoval: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5044 process_sdp: Transcoding MMR: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5051 process_sdp: Transcoding JBIG: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 72 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5085 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x18050a (gsm|alaw|g729|ilbc|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:18320 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x80000 (h263) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5176 process_sdp: We have an owner, now see if we need to change this call [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5181 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x80000 (h263) and not 0x8 (alaw) [Jan 24 11:16:32] DEBUG[11352]: frame.c:1267 ast_codec_choose: Could not find preferred codec - Going for the best codec [Jan 24 11:16:32] WARNING[11352]: channel.c:702 ast_best_codec: Don't know any of 0x0 formats [Jan 24 11:16:32] WARNING[11352]: channel.c:2807 set_format: Unable to find a codec translation path from h263 to slin [Jan 24 11:16:32] WARNING[11352]: channel.c:2807 set_format: Unable to find a codec translation path from h263 to slin [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:13380 handle_request_invite: Got a SIP re-invite for call 4b445dc2709de7436136115a4b88bea0@mydomain.tld [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:13475 handle_request_invite: SIP/ser-08228cf8: This call is UP.... [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:16628 sip_handle_t38_reinvite: Sending reinvite on SIP 'b308f049-26ef7915@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 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:6005 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4425 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:6011 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5942 t38_get_rate: T38MaxFaxRate 7200 found [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog b308f049-26ef7915@10.2.0.1 (presumably reinvite) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.2.0.1:5242 SIP/2.0 (48) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1bd5ad2a;rport (65) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Route: (57) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=as3709cca5 (51) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: ivoc ;tag=e9b7a6b94932b565o0 (67) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Contact: (34) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: User-Agent: Asterisk(27) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Max-Forwards: 70 (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Supported: replaces (19) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Type: application/sdp (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Content-Length: 351 (19) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: (0) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=root 11344 11346 IN IP4 10.0.0.2 (40) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=session (9) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 4425 udptl t38 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 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=z9hG4bK1bd5ad2a;rport Route: From: ;tag=as3709cca5 To: ivoc ;tag=e9b7a6b94932b565o0 Contact: Call-ID: b308f049-26ef7915@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: 351 v=0 o=root 11344 11346 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4425 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 --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 [Jan 24 11:16:32] WARNING[14147]: chan_sip.c:3469 sip_write: Asked to transmit frame type 8, while native formats is 0x0 (nothing)(0) read/write = 0x40 (slin)(64)/0x40 (slin)(64) [Jan 24 11:16:32] WARNING[14147]: channel.c:3138 ast_channel_make_compatible: No path to translate from SIP/mydomain.tld-082384c8(256) to SIP/ser-08228cf8(524288) [Jan 24 11:16:32] WARNING[14147]: channel.c:4073 ast_channel_bridge: Can't make SIP/mydomain.tld-082384c8 and SIP/ser-08228cf8 compatible [Jan 24 11:16:32] WARNING[14147]: res_features.c:1415 ast_bridge_call: Bridge failed on channels SIP/mydomain.tld-082384c8 and SIP/ser-08228cf8 [Jan 24 11:16:32] DEBUG[14147]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/ser-08228cf8' [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:3296 sip_hangup: Hangup call SIP/ser-08228cf8, SIP callid 4b445dc2709de7436136115a4b88bea0@mydomain.tld) [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:3304 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:2996 update_call_counter: Updating call counter for incoming call Scheduling destruction of SIP dialog '4b445dc2709de7436136115a4b88bea0@mydomain.tld' in 32000 ms (Method: INVITE) [Jan 24 11:16:32] DEBUG[14147]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08228cf8 [Jan 24 11:16:32] DEBUG[14147]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Jan 24 11:16:32] DEBUG[14147]: app_dial.c:1643 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Jan 24 11:16:32] DEBUG[14147]: pbx.c:2368 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-082384c8' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-082384c8' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '"ivoc" <2222>' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2222' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '1234' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-082384c8' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-08228cf8' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'Dial' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 11:16:22' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 11:16:26' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 11:16:32' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '10' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '6' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '1169630182.6' [Jan 24 11:16:32] DEBUG[14147]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '' [Jan 24 11:16:32] DEBUG[14147]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/mydomain.tld-082384c8' [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:3296 sip_hangup: Hangup call SIP/mydomain.tld-082384c8, SIP callid b308f049-26ef7915@10.2.0.1) [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:3304 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Jan 24 11:16:32] DEBUG[14147]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog 'b308f049-26ef7915@10.2.0.1' in 32000 ms (Method: ACK) [Jan 24 11:16:32] DEBUG[14147]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-082384c8 [Jan 24 11:16:32] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Jan 24 11:16:32] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer ser [Jan 24 11:16:32] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Jan 24 11:16:32] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 11:16:32] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1bd5ad2a;rport=5060 From: ;tag=as3709cca5 To: ivoc ;tag=e9b7a6b94932b565o0 Call-ID: b308f049-26ef7915@10.2.0.1 CSeq: 102 INVITE Server: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1bd5ad2a;rport=5060 (70) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=as3709cca5 (51) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ivoc ;tag=e9b7a6b94932b565o0 (67) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: OpenSer (1.1.0-notls (i386/linux)) (42) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #53 - INVITE (got response) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on 'b308f049-26ef7915@10.2.0.1' Request 102: Found [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:11576 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=z9hG4bK37a4a7a8;rport Route: From: ;tag=as3709cca5 To: ivoc ;tag=e9b7a6b94932b565o0 Call-ID: b308f049-26ef7915@10.2.0.1 CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #56 Scheduling destruction of SIP dialog 'b308f049-26ef7915@10.2.0.1' in 32000 ms (Method: ACK) [Jan 24 11:16:32] DEBUG[11347]: 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 ---> SIP/2.0 200 OK To: ivoc ;tag=e9b7a6b94932b565o0 From: ;tag=as3709cca5 Call-ID: b308f049-26ef7915@10.2.0.1 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1bd5ad2a;rport=5060 Contact: ivoc Server: Linksys/SPA2102-3.3.6 Content-Length: 271 Content-Type: application/sdp v=0 o=- 7349814 7349814 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=image 16386 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: To: ivoc ;tag=e9b7a6b94932b565o0 (67) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=as3709cca5 (51) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: CSeq: 102 INVITE (16) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1bd5ad2a;rport=5060 (70) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Contact: ivoc (49) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Content-Length: 271 (19) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Content-Type: application/sdp (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: (0) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=- 7349814 7349814 IN IP4 10.2.0.1 (41) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=- (3) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 16386 udptl t38 (23) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:14400 (21) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'b308f049-26ef7915@10.2.0.1' of Request 102: Match Not Found [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:11576 handle_response_invite: SIP response 200 to standard invite Got T.38 offer in SDP in dialog b308f049-26ef7915@10.2.0.1 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4812 process_sdp: T38 state changed to 3 on channel [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4858 process_sdp: Peer T.38 UDPTL is at port 10.2.0.1:16386 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid b308f049-26ef7915@10.2.0.1 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 14400 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 200 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5085 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x18050a (gsm|alaw|g729|ilbc|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) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5127 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:7924 build_route: build_route: Contact hop: ivoc list_route: hop: [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:5606 reqprep: Strict routing enforced for session b308f049-26ef7915@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=z9hG4bK04f9f678;rport From: ;tag=as3709cca5 To: ivoc ;tag=e9b7a6b94932b565o0 Contact: Call-ID: b308f049-26ef7915@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 ---> SIP/2.0 200 OK To: ivoc ;tag=e9b7a6b94932b565o0 From: ;tag=as3709cca5 Call-ID: b308f049-26ef7915@10.2.0.1 CSeq: 103 BYE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK37a4a7a8;rport=5060 Server: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: To: ivoc ;tag=e9b7a6b94932b565o0 (67) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=as3709cca5 (51) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Call-ID: b308f049-26ef7915@10.2.0.1 (41) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: CSeq: 103 BYE (13) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK37a4a7a8;rport=5060 (70) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Linksys/SPA2102-3.3.6 (29) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #56 [Jan 24 11:16:32] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on 'b308f049-26ef7915@10.2.0.1' of Request 103: Match Not Found Really destroying SIP dialog 'b308f049-26ef7915@10.2.0.1' Method: ACK 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=z9hG4bK84a2.6fb114e6.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D82D1CE9 From: ;tag=1C941C78-BA3 To: "ivoc" ;tag=as31b873fa Date: Wed, 24 Jan 2007 09:16:32 GMT Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 1683887896-2864845275-2961037238-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: 1169630192 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 769 v=0 o=CiscoSystemsSIP-GW-UserAgent 8636 9792 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 18320 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 <-------------> [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK84a2.6fb114e6.0 (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D82D1CE9 (60) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C941C78-BA3 (55) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as31b873fa (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 09:16:32 GMT (35) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Min-SE: 1800 (13) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Cisco-Guid: 1683887896-2864845275-2961037238-1321745574 (55) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: CSeq: 101 INVITE (16) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Max-Forwards: 69 (16) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Timestamp: 1169630192 (21) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Contact: (45) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: Expires: 180 (12) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: Allow-Events: telephone-event (29) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 18: Content-Type: application/sdp (29) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 19: Content-Length: 769 (19) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 20: (0) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8636 9792 IN IP4 10.3.0.1 (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 18320 udptl 101 t38 t38 (31) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (20 headers 30 lines) --- [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:14558 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:13382 handle_request_invite: Got a SIP re-transmit of INVITE for call 4b445dc2709de7436136115a4b88bea0@mydomain.tld [Jan 24 11:16:33] NOTICE[11352]: chan_sip.c:13572 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=z9hG4bK84a2.6fb114e6.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D82D1CE9 From: ;tag=1C941C78-BA3 To: "ivoc" ;tag=as31b873fa Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld CSeq: 101 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY upported: replaces Contact: Content-Length: 0 <------------> Scheduling destruction of SIP dialog '4b445dc2709de7436136115a4b88bea0@mydomain.tld' in 32000 ms (Method: INVITE) a-node2*CLI> <--- 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=z9hG4bK84a2.6fb114e6.0 From: ;tag=1C941C78-BA3 Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld To: "ivoc" ;tag=as31b873fa CSeq: 101 ACK Route: User-Agent: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: ACK sip:2222@10.0.0.2:5060 SIP/2.0 (45) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK84a2.6fb114e6.0 (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=1C941C78-BA3 (55) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as31b873fa (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: CSeq: 101 ACK (13) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Route: (49) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: User-Agent: OpenSer (1.1.0-notls (i386/linux)) (46) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Content-Length: 0 (17) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '4b445dc2709de7436136115a4b88bea0@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=z9hG4bK51ea1e37;rport Route: From: "ivoc" ;tag=as31b873fa To: ;tag=1C941C78-BA3 Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #59 Scheduling destruction of SIP dialog '4b445dc2709de7436136115a4b88bea0@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=z9hG4bK51ea1e37;rport=5060 From: "ivoc" ;tag=as31b873fa To: ;tag=1C941C78-BA3 Date: Wed, 24 Jan 2007 09:16:33 GMT Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE <-------------> [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK51ea1e37;rport=5060 (70) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as31b873fa (63) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C941C78-BA3 (53) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 09:16:33 GMT (35) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 4b445dc2709de7436136115a4b88bea0@mydomain.tld (61) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: CSeq: 103 BYE (13) [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #59 [Jan 24 11:16:33] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '4b445dc2709de7436136115a4b88bea0@mydomain.tld' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '4b445dc2709de7436136115a4b88bea0@mydomain.tld' Method: ACK