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. ========================================================================= <--- 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=z9hG4bK1965.fea1e3d4.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-b01de9f9;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: Call-ID: 49963ffa-374ad541@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=- 7107188 7107188 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=audio 16482 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 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:1234@mydomain.tld SIP/2.0 (43) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Record-Route: (64) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK1965.fea1e3d4.0 (61) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-b01de9f9;rport=5242 (71) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: From: ivoc ;tag=692e68a6239ae485o0 (69) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: To: (34) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Max-Forwards: 69 (16) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Contact: ivoc (49) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Expires: 240 (12) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Length: 262 (19) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Supported: x-sipura (19) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Content-Type: application/sdp (29) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: X-Custom-Duration: 7200000 (32) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: (0) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=- 7107188 7107188 IN IP4 10.2.0.1 (41) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=- (3) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 16482 RTP/AVP 18 100 101 (32) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:100 192-193 (18) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-15 (15) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:30 (10) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=sendrecv (10) --- (17 headers 13 lines) --- [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to Off [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to Off [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to Off [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4286 sip_alloc: Allocating new SIP dialog for 49963ffa-374ad541@10.2.0.1 - INVITE (With RTP) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -x-sipura- [Jan 24 10:36:05] 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 - 49963ffa-374ad541@10.2.0.1 Found peer 'ser' [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2580 do_setnat: Setting NAT on VRTP to On [Jan 24 10:36:05] 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 10:36:05] 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:16482 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 10:36:05] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), 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:16482 [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x100 (g729) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:13327 handle_request_invite: Checking SIP call limits for device [Jan 24 10:36:05] 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 10:36:05] DEBUG[11352]: chan_sip.c:3788 sip_new: *** Our native formats are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:3789 sip_new: *** Joint capabilities are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:3790 sip_new: *** Our capabilities are 0x50a (gsm|alaw|g729|ilbc) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:3791 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:3814 sip_new: This channel will not be able to handle video. [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:7895 build_route: build_route: Record-Route hop: list_route: hop: [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:13402 handle_request_invite: SIP/mydomain.tld-08227778: 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=z9hG4bK1965.fea1e3d4.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-b01de9f9;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: Call-ID: 49963ffa-374ad541@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 10:36:05] DEBUG[11352]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-08227778 [Jan 24 10:36:05] DEBUG[11455]: pbx.c:1770 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-08227778", "X-Custom-Test3: ") in new stack [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:16883 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Jan 24 10:36:05] DEBUG[11455]: pbx.c:1770 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-08227778", "X-Custom-Network: class4") in new stack [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:16883 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Jan 24 10:36:05] DEBUG[11455]: pbx.c:1770 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-08227778", "SIP/1234@ser") in new stack [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:15192 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4286 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2621 create_addr_from_peer: Our T38 capability (3856) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2575 do_setnat: Setting NAT on RTP to On [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2585 do_setnat: Setting NAT on UDPTL to On [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3788 sip_new: *** Our native formats are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3789 sip_new: *** Joint capabilities are 0x0 (nothing) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3790 sip_new: *** Our capabilities are 0x50a (gsm|alaw|g729|ilbc) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3791 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3793 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:3814 sip_new: This channel will not be able to handle video. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable NODE_IP. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_DB. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable EMER_NUMS. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3279 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Jan 24 10:36:05] DEBUG[11455]: channel.c:3292 ast_channel_inherit_variables: Not copying variable SIPURI. [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2830 sip_call: Outgoing Call for 1234 [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:2844 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6788 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6788 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6151 add_sdp: ** Our capability: 0x50a (gsm|alaw|g729|ilbc) Video flag: False [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.0.0.2 port 12282 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 non-codec 0x1 (telephone-event) to SDP [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:6328 add_sdp: Done building SDP. Settling with this capability: 0x50a (gsm|alaw|g729|ilbc) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (45) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1aa1358a;rport (65) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as550371df (63) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 3: To: (36) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 4: Contact: (39) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 6: CSeq: 102 INVITE (16) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 7: User-Agent: Asterisk (27) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 8: Max-Forwards: 70 (16) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 9: Remote-Party-ID: "ivoc" ;privacy=off;screen=no (81) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 10: Date: Wed, 24 Jan 2007 08:36:05 GMT (35) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 12: Supported: replaces (19) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 13: X-Custom-Network: class4 (26) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 14: X-Custom-Test3: (24) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 15: Content-Type: application/sdp (29) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 16: Content-Length: 359 (19) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4549 parse_request: Header 17: (0) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: o=root 11344 11344 IN IP4 10.0.0.2 (40) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: s=session (9) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: m=audio 12282 RTP/AVP 18 8 3 97 101 (35) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=fmtp:97 mode=30 (17) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 10:36:05] DEBUG[11455]: 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=z9hG4bK1aa1358a;rport From: "ivoc" ;tag=as550371df To: Contact: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Date: Wed, 24 Jan 2007 08:36:05 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: 359 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 12282 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 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jan 24 10:36:05] DEBUG[11455]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #29 -- Called 1234@ser [Jan 24 10:36:05] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 10:36:05] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld [Jan 24 10:36:05] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) <--- 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=z9hG4bK1aa1358a;rport=5060 From: "ivoc" ;tag=as550371df To: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 102 INVITE Server: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1aa1358a;rport=5060 (70) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as550371df (63) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: (36) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: OpenSer (1.1.0-notls (i386/linux)) (42) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #29 - INVITE (got response) [Jan 24 10:36:05] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' Request 102: Found [Jan 24 10:36:05] 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=z9hG4bK1aa1358a;rport=5060 From: "ivoc" ;tag=as550371df To: ;tag=1C6F3E2C-2432 Date: Wed, 24 Jan 2007 08:36:05 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER Allow-Events: telephone-event Contact: Record-Route: Content-Disposition: session;handling=required Content-Type: application/sdp Content-Length: 300 v=0 o=CiscoSystemsSIP-GW-UserAgent 8649 8386 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 17992 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 - - - - <-------------> [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1aa1358a;rport=5060 (70) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as550371df (63) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C6F3E2C-2432 (54) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 08:36:05 GMT (35) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 10:36:06] 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 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Allow-Events: telephone-event (29) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Contact: (45) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Record-Route: (56) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Type: application/sdp (29) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Content-Length: 300 (19) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: (0) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8649 8386 IN IP4 10.3.0.1 (61) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 17992 RTP/AVP 18 101 (28) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) --- (15 headers 13 lines) --- [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' Request 102: Found [Jan 24 10:36:06] 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 [Jan 24 10:36:06] 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:17992 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 10:36:06] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel SIP/ser-08220f20 Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.3.0.1:17992 [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x100 (g729) [Jan 24 10:36:06] DEBUG[11352]: chan_sip.c:5176 process_sdp: We have an owner, now see if we need to change this call -- SIP/ser-08220f20 is making progress passing it to SIP/mydomain.tld-08227778 [Jan 24 10:36:06] DEBUG[11455]: chan_sip.c:6383 transmit_response_with_sdp: Setting framing from config on incoming call [Jan 24 10:36:06] DEBUG[11455]: chan_sip.c:6151 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Jan 24 10:36:06] DEBUG[11455]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 13956 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 10:36:06] DEBUG[11455]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 10:36:06] DEBUG[11455]: 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=z9hG4bK1965.fea1e3d4.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-b01de9f9;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@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 13956 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 10:36:06] DEBUG[11455]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Jan 24 10:36:06] DEBUG[11455]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Jan 24 10:36:06] DEBUG[11455]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Jan 24 10:36:06] DEBUG[11455]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1aa1358a;rport=5060 From: "ivoc" ;tag=as550371df To: ;tag=1C6F3E2C-2432 Date: Wed, 24 Jan 2007 08:36:05 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER Allow-Events: telephone-event Contact: Record-Route: Content-Type: application/sdp Content-Length: 300 v=0 o=CiscoSystemsSIP-GW-UserAgent 8649 8386 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 17992 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 - - - - <-------------> [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK1aa1358a;rport=5060 (70) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as550371df (63) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C6F3E2C-2432 (54) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 08:36:05 GMT (35) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 10:36:07] 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 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Allow-Events: telephone-event (29) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Contact: (45) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Record-Route: (56) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: Content-Type: application/sdp (29) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Length: 300 (19) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: (0) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8649 8386 IN IP4 10.3.0.1 (61) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=audio 17992 RTP/AVP 18 101 (28) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:18 annexb=no (19) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=ptime:20 (10) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) --- (14 headers 13 lines) --- [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' of Request 102: Match Not Found [Jan 24 10:36:07] 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 [Jan 24 10:36:07] 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:17992 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 10:36:07] DEBUG[11352]: chan_sip.c:5092 process_sdp: T38 state changed to 0 on channel SIP/ser-08220f20 Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.3.0.1:17992 [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:5169 process_sdp: We're settling with these formats: 0x100 (g729) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:5176 process_sdp: We have an owner, now see if we need to change this call [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 10:36:07] 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=z9hG4bK3e3764c2;rport Route: From: "ivoc" ;tag=as550371df To: ;tag=1C6F3E2C-2432 Contact: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Jan 24 10:36:07] DEBUG[11455]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08220f20 -- SIP/ser-08220f20 answered SIP/mydomain.tld-08227778 [Jan 24 10:36:07] DEBUG[11455]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-08227778 [Jan 24 10:36:07] DEBUG[11455]: chan_sip.c:3446 sip_answer: SIP answering channel: SIP/mydomain.tld-08227778 [Jan 24 10:36:07] DEBUG[11455]: chan_sip.c:6383 transmit_response_with_sdp: Setting framing from config on incoming call [Jan 24 10:36:07] DEBUG[11455]: chan_sip.c:6151 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Jan 24 10:36:07] DEBUG[11455]: chan_sip.c:6152 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 13956 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Jan 24 10:36:07] DEBUG[11455]: chan_sip.c:6283 add_sdp: -- Done with adding codecs to SDP [Jan 24 10:36:07] DEBUG[11455]: 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=z9hG4bK1965.fea1e3d4.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-b01de9f9;rport=5242 Record-Route: From: ivoc ;tag=692e68a6239ae485o0 To: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@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 13956 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 10:36:07] DEBUG[11455]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 -- Packet2Packet bridging SIP/mydomain.tld-08227778 and SIP/ser-08220f20 [Jan 24 10:36:07] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Jan 24 10:36:07] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer ser [Jan 24 10:36:07] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Jan 24 10:36:07] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 10:36:07] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld [Jan 24 10:36:07] 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 ---> ACK sip:1234@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK1965.fea1e3d4.2 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-99ab9c1c;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 102 ACK Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b71ba19103b695bd915c20e381f54540ef8311",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="821d8d5b55485b7a6796840b8abebc92" Contact: ivoc User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: ACK sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK1965.fea1e3d4.2 (61) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-99ab9c1c;rport=5242 (71) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ivoc ;tag=692e68a6239ae485o0 (69) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: ;tag=as59ba45a2 (49) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: CSeq: 102 ACK (13) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Max-Forwards: 69 (16) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b71ba19103b695bd915c20e381f54540ef8311",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="821d8d5b55485b7a6796840b8abebc92" (218) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Contact: ivoc (49) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Content-Length: 0 (17) [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33 [Jan 24 10:36:07] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '49963ffa-374ad541@10.2.0.1' of Response 102: Match Not Found [Jan 24 10:36:09] DEBUG[11455]: rtp.c:871 ast_rtcp_read: Got RTCP report of 132 bytes [Jan 24 10:36:12] DEBUG[11455]: rtp.c:871 ast_rtcp_read: Got RTCP report of 132 bytes [Jan 24 10:36:13] DEBUG[11455]: 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=z9hG4bKc3f4.27d7bf.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D509127A From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Date: Wed, 24 Jan 2007 08:36:13 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 3291474930-2864452059-2859325366-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: 1169627773 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 481 v=0 o=CiscoSystemsSIP-GW-UserAgent 8649 8387 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 17992 udptl 101 t38 c=IN IP4 10.3.0.1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKc3f4.27d7bf.0 (59) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D509127A (60) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C6F3E2C-2432 (56) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as550371df (61) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 08:36:13 GMT (35) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Min-SE: 1800 (13) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Cisco-Guid: 3291474930-2864452059-2859325366-1321745574 (55) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Jan 24 10:36:13] 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 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: CSeq: 101 INVITE (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Max-Forwards: 69 (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Timestamp: 1169627773 (21) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Contact: (45) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: Expires: 180 (12) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: Allow-Events: telephone-event (29) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 18: Content-Type: application/sdp (29) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 19: Content-Length: 481 (19) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 20: (0) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8649 8387 IN IP4 10.3.0.1 (61) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 17992 udptl 101 t38 (27) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (20 headers 19 lines) --- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1680 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,replaces" [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -100rel- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1694 parse_sip_options: Matched SIP option: 100rel [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -timer- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1694 parse_sip_options: Matched SIP option: timer [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1688 parse_sip_options: Found SIP option: -replaces- [Jan 24 10:36:13] 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 2aeff79f2927bffb76321288507c86d2@mydomain.tld [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4808 process_sdp: T38 state changed to 4 on channel SIP/ser-08220f20 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4858 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:17992 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 2aeff79f2927bffb76321288507c86d2@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 7200 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5038 process_sdp: FillBitRemoval: 0 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5044 process_sdp: Transcoding MMR: 0 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5051 process_sdp: Transcoding JBIG: 0 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 72 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5085 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5127 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:13380 handle_request_invite: Got a SIP re-invite for call 2aeff79f2927bffb76321288507c86d2@mydomain.tld [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:13475 handle_request_invite: SIP/ser-08220f20: This call is UP.... [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:16628 sip_handle_t38_reinvite: Sending reinvite on SIP '49963ffa-374ad541@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 10:36:13] DEBUG[11352]: chan_sip.c:6005 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4974 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:6011 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5942 t38_get_rate: T38MaxFaxRate 7200 found [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1621 initialize_initreq: Initializing already initialized SIP dialog 49963ffa-374ad541@10.2.0.1 (presumably reinvite) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.2.0.1:5242 SIP/2.0 (48) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK6f87efdb;rport (65) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Route: (57) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=as59ba45a2 (51) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: ivoc ;tag=692e68a6239ae485o0 (67) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Contact: (34) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: CSeq: 102 INVITE (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: User-Agent: Asterisk (27) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Max-Forwards: 70 (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: Supported: replaces (19) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Content-Type: application/sdp (29) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Content-Length: 351 (19) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: (0) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=root 11344 11346 IN IP4 10.0.0.2 (40) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=session (9) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 4974 udptl t38 (22) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 10:36:13] 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=z9hG4bK6f87efdb;rport Route: From: ;tag=as59ba45a2 To: ivoc ;tag=692e68a6239ae485o0 Contact: Call-ID: 49963ffa-374ad541@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 4974 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 10:36:13] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 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=z9hG4bK6f87efdb;rport=5060 From: ;tag=as59ba45a2 To: ivoc ;tag=692e68a6239ae485o0 Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 102 INVITE Server: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK6f87efdb;rport=5060 (70) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=as59ba45a2 (51) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ivoc ;tag=692e68a6239ae485o0 (67) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: CSeq: 102 INVITE (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: OpenSer (1.1.0-notls (i386/linux)) (42) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2122 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #34 - INVITE (got response) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '49963ffa-374ad541@10.2.0.1' Request 102: Found [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:11574 handle_response_invite: SIP response 100 to RE-invite on outgoing call 49963ffa-374ad541@10.2.0.1 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ivoc ;tag=692e68a6239ae485o0 From: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK6f87efdb;rport=5060 Contact: ivoc Server: Linksys/SPA2102-3.3.6 Content-Length: 271 Content-Type: application/sdp v=0 o=- 7107918 7107918 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=image 16482 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: To: ivoc ;tag=692e68a6239ae485o0 (67) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: ;tag=as59ba45a2 (51) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: CSeq: 102 INVITE (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK6f87efdb;rport=5060 (70) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Contact: ivoc (49) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Content-Length: 271 (19) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Content-Type: application/sdp (29) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: (0) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=- 7107918 7107918 IN IP4 10.2.0.1 (41) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=- (3) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 16482 udptl t38 (23) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:14400 (21) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2071 __sip_ack: Acked pending invite 102 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '49963ffa-374ad541@10.2.0.1' of Request 102: Match Not Found [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:11574 handle_response_invite: SIP response 200 to RE-invite on outgoing call 49963ffa-374ad541@10.2.0.1 Got T.38 offer in SDP in dialog 49963ffa-374ad541@10.2.0.1 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4808 process_sdp: T38 state changed to 4 on channel SIP/mydomain.tld-08227778 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4858 process_sdp: Peer T.38 UDPTL is at port 10.2.0.1:16482 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 49963ffa-374ad541@10.2.0.1 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 14400 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 200 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5085 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), 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 10:36:13] DEBUG[11352]: chan_sip.c:5127 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:7924 build_route: build_route: Contact hop: ivoc list_route: hop: [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:16656 sip_handle_t38_reinvite: Responding 200 OK on SIP '2aeff79f2927bffb76321288507c86d2@mydomain.tld' - It's UDPTL soon redirected to us (IP 10.0.0.2) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:16661 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/mydomain.tld-08227778 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:16662 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/ser-08220f20 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:6005 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4030 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:6011 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5938 t38_get_rate: T38MaxFaxRate 9600 found <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKc3f4.27d7bf.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D509127A From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 101 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 353 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=image 4030 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <------------> [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:5606 reqprep: Strict routing enforced for session 49963ffa-374ad541@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=z9hG4bK051af6ab;rport From: ;tag=as59ba45a2 To: ivoc ;tag=692e68a6239ae485o0 Contact: Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- [Jan 24 10:36:13] DEBUG[11455]: rtp.c:871 ast_rtcp_read: Got RTCP report of 48 bytes 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=z9hG4bKc3f4.27d7bf.2 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50A1817 From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Date: Wed, 24 Jan 2007 08:36:13 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Max-Forwards: 69 CSeq: 101 ACK Content-Length: 0 <-------------> [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: ACK sip:2222@10.0.0.2:5060 SIP/2.0 (45) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKc3f4.27d7bf.2 (59) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50A1817 (60) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C6F3E2C-2432 (56) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as550371df (61) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 08:36:13 GMT (35) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Max-Forwards: 69 (16) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: CSeq: 101 ACK (13) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Content-Length: 0 (17) [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 [Jan 24 10:36:13] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' of Response 101: Match Not Found 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=z9hG4bK93f4.4adf28a1.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50E1FBB From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Date: Wed, 24 Jan 2007 08:36:47 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 3291474930-2864452059-2859325366-1321745574 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER CSeq: 102 INVITE Max-Forwards: 69 Timestamp: 1169627807 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 493 v=0 o=CiscoSystemsSIP-GW-UserAgent 8649 8389 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 17992 udptl 101 t38 c=IN IP4 10.3.0.1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=T38FaxVersion:0 a=T38MaxBitRate:7200 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy a=sendonly <-------------> [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK93f4.4adf28a1.0 (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50E1FBB (60) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C6F3E2C-2432 (56) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as550371df (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 08:36:47 GMT (35) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Min-SE: 1800 (13) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Cisco-Guid: 3291474930-2864452059-2859325366-1321745574 (55) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Jan 24 10:36:47] 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 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 12: CSeq: 102 INVITE (16) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 13: Max-Forwards: 69 (16) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 14: Timestamp: 1169627807 (21) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 15: Contact: (45) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 16: Expires: 180 (12) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 17: Allow-Events: telephone-event (29) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 18: Content-Type: application/sdp (29) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 19: Content-Length: 493 (19) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 20: (0) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: v=0 (3) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8649 8389 IN IP4 10.3.0.1 (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: s=SIP Call (10) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: t=0 0 (5) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: m=image 17992 udptl 101 t38 (27) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=fmtp:101 0-16 (15) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=silenceSupp:off - - - - (25) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxVersion:0 (17) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38MaxBitRate:7200 (20) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4581 parse_request: Line: a=sendonly (10) --- (20 headers 20 lines) --- [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.0.0.1 : 5060 (NAT) Got T.38 offer in SDP in dialog 2aeff79f2927bffb76321288507c86d2@mydomain.tld [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4808 process_sdp: T38 state changed to 4 on channel SIP/ser-08220f20 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4858 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:17992 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 2aeff79f2927bffb76321288507c86d2@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5024 process_sdp: FaxVersion: 0 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5000 process_sdp: T38MaxBitRate: 7200 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5038 process_sdp: FillBitRemoval: 0 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5044 process_sdp: Transcoding MMR: 0 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5051 process_sdp: Transcoding JBIG: 0 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5057 process_sdp: RateMangement: transferredTCF [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4996 process_sdp: MaxBufferSize:200 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5032 process_sdp: FaxMaxDatagram: 72 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5065 process_sdp: UDP EC: t38UDPRedundancy [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5085 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x50a (gsm|alaw|g729|ilbc), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5127 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:13380 handle_request_invite: Got a SIP re-invite for call 2aeff79f2927bffb76321288507c86d2@mydomain.tld [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:13475 handle_request_invite: SIP/ser-08220f20: This call is UP.... [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:6005 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4030 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:6011 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:5942 t38_get_rate: T38MaxFaxRate 7200 found <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK93f4.4adf28a1.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50E1FBB From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 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 4030 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 10:36:47] DEBUG[11352]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #36 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:13508 handle_request_invite: T38 state changed to 5 on channel SIP/ser-08220f20 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=z9hG4bK93f4.4adf28a1.2 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50F12E8 From: ;tag=1C6F3E2C-2432 To: "ivoc" ;tag=as550371df Date: Wed, 24 Jan 2007 08:36:47 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Max-Forwards: 69 CSeq: 102 ACK Content-Length: 0 <-------------> [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: ACK sip:2222@10.0.0.2:5060 SIP/2.0 (45) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK93f4.4adf28a1.2 (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK5D50F12E8 (60) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ;tag=1C6F3E2C-2432 (56) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: "ivoc" ;tag=as550371df (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Date: Wed, 24 Jan 2007 08:36:47 GMT (35) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Max-Forwards: 69 (16) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: CSeq: 102 ACK (13) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: Content-Length: 0 (17) [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received ACK (6) - Command in SIP ACK [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #36 [Jan 24 10:36:47] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' of Response 102: Match Not Found [Jan 24 10:36:47] DEBUG[11455]: rtp.c:871 ast_rtcp_read: Got RTCP report of 92 bytes [Jan 24 10:36:59] DEBUG[11455]: rtp.c:871 ast_rtcp_read: Got RTCP report of 100 bytes a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> BYE sip:1234@10.0.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK2965.f5632564.0 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-c59f6c6b;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 103 BYE Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b71ba19103b695bd915c20e381f54540ef8311",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="396ae9f6d8672ac3ee2798dba829bc40" User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: BYE sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK2965.f5632564.0 (61) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-c59f6c6b;rport=5242 (71) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: From: ivoc ;tag=692e68a6239ae485o0 (69) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: To: ;tag=as59ba45a2 (49) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 49963ffa-374ad541@10.2.0.1 (41) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: CSeq: 103 BYE (13) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Max-Forwards: 69 (16) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45b71ba19103b695bd915c20e381f54540ef8311",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="396ae9f6d8672ac3ee2798dba829bc40" (218) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: User-Agent: Linksys/SPA2102-3.3.6 (33) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 10: Content-Length: 0 (17) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:14539 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 10.0.0.1 : 5060 (NAT) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:1633 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 49963ffa-374ad541@10.2.0.1 [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:14116 handle_request_bye: Received bye, issuing owner hangup <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK2965.f5632564.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5242;branch=z9hG4bK-c59f6c6b;rport=5242 From: ivoc ;tag=692e68a6239ae485o0 To: ;tag=as59ba45a2 Call-ID: 49963ffa-374ad541@10.2.0.1 CSeq: 103 BYE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jan 24 10:36:59] DEBUG[11455]: rtp.c:3051 bridge_p2p_loop: Oooh, got a hangup [Jan 24 10:36:59] DEBUG[11455]: channel.c:4039 ast_channel_bridge: Returning from native bridge, channels: SIP/mydomain.tld-08227778, SIP/ser-08220f20 [Jan 24 10:36:59] DEBUG[11455]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/ser-08220f20' [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:3296 sip_hangup: Hangup call SIP/ser-08220f20, SIP callid 2aeff79f2927bffb76321288507c86d2@mydomain.tld) [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:3304 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:2996 update_call_counter: Updating call counter for incoming call Scheduling destruction of SIP dialog '2aeff79f2927bffb76321288507c86d2@mydomain.tld' in 32000 ms (Method: ACK) set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.1, port 5060 Reliably Transmitting (NAT) to 10.0.0.1:5060: BYE sip:1234@10.3.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK336349b1;rport Route: From: "ivoc" ;tag=as550371df To: ;tag=1C6F3E2C-2432 Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "ivoc" ;privacy=off;screen=no Content-Length: 0 --- [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:1975 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 [Jan 24 10:36:59] DEBUG[11455]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08220f20 [Jan 24 10:36:59] DEBUG[11455]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Jan 24 10:36:59] DEBUG[11455]: app_dial.c:1643 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Jan 24 10:36:59] DEBUG[11455]: pbx.c:2368 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-08227778' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-08227778' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '"ivoc" <2222>' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2222' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '1234' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-08227778' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-08220f20' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'Dial' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 10:36:05' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 10:36:07' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '2007-01-24 10:36:59' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '54' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '52' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '1169627765.2' [Jan 24 10:36:59] DEBUG[11455]: pbx.c:1623 pbx_substitute_variables_helper_full: Function result is '' [Jan 24 10:36:59] DEBUG[11455]: channel.c:1687 ast_hangup: Hanging up channel 'SIP/mydomain.tld-08227778' [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:3296 sip_hangup: Hangup call SIP/mydomain.tld-08227778, SIP callid 49963ffa-374ad541@10.2.0.1) [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:3304 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Jan 24 10:36:59] DEBUG[11455]: chan_sip.c:2996 update_call_counter: Updating call counter for outgoing call [Jan 24 10:36:59] DEBUG[11455]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-08227778 [Jan 24 10:36:59] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Jan 24 10:36:59] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer ser [Jan 24 10:36:59] DEBUG[11347]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Jan 24 10:36:59] DEBUG[11347]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Jan 24 10:36:59] DEBUG[11347]: chan_sip.c:15134 sip_devicestate: Checking device state for peer mydomain.tld [Jan 24 10:36:59] 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 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK336349b1;rport=5060 From: "ivoc" ;tag=as550371df To: ;tag=1C6F3E2C-2432 Date: Wed, 24 Jan 2007 08:36:59 GMT Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE <-------------> [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 0: SIP/2.0 200 OK (14) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK336349b1;rport=5060 (70) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 2: From: "ivoc" ;tag=as550371df (63) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 3: To: ;tag=1C6F3E2C-2432 (54) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 4: Date: Wed, 24 Jan 2007 08:36:59 GMT (35) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 5: Call-ID: 2aeff79f2927bffb76321288507c86d2@mydomain.tld (61) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 7: Content-Length: 0 (17) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 8: CSeq: 103 BYE (13) [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:4549 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:2079 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #38 [Jan 24 10:36:59] DEBUG[11352]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '2aeff79f2927bffb76321288507c86d2@mydomain.tld' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '2aeff79f2927bffb76321288507c86d2@mydomain.tld' Method: ACK Really destroying SIP dialog '49963ffa-374ad541@10.2.0.1' Method: BYE