<--- 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=z9hG4bKb219.963c27d.0 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-45e6be2c;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 102 INVITE Max-Forwards: 69 Contact: ivo test Expires: 240 User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 256 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp X-Custom-Duration: 7200000 v=0 o=- 7840 7840 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=audio 16468 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 <-------------> [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:1234@mydomain.tld SIP/2.0 (43) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Record-Route: (64) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKb219.963c27d.0 (60) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-45e6be2c;rport=5387 (71) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: From: ivo test ;tag=6ecb56db440cf000o0 (73) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: To: (34) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 69 (16) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Contact: ivo test (53) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: Expires: 240 (12) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: Content-Length: 256 (19) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 14: Supported: x-sipura (19) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 15: Content-Type: application/sdp (29) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 16: X-Custom-Duration: 7200000 (32) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 17: (0) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=- 7840 7840 IN IP4 10.2.0.1 (35) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=- (3) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=audio 16468 RTP/AVP 18 100 101 (32) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:100 192-193 (18) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=ptime:30 (10) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) --- (17 headers 13 lines) --- [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2583 do_setnat: Setting NAT on UDPTL to Off [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for d1a6837-d8cbae54@10.2.0.1 - INVITE (With RTP) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:1686 parse_sip_options: Found SIP option: -x-sipura- [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:1698 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 - d1a6837-d8cbae54@10.2.0.1 Found peer 'ser' [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to On [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to On [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2583 do_setnat: Setting NAT on UDPTL to On Found RTP audio format 18 Found RTP audio format 100 Found RTP audio format 101 [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4893 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.2.0.1:16468 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 [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x18050b (g723|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:16468 [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x100 (g729) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:13378 handle_request_invite: Checking SIP call limits for device [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call Looking for 1234 in pre-process (domain mydomain.tld) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3803 sip_new: *** Our native formats are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x18050b (g723|gsm|alaw|g729|ilbc|h263|h263p) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:7935 build_route: build_route: Record-Route hop: list_route: hop: [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:13453 handle_request_invite: SIP/mydomain.tld-081d7b50: 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=z9hG4bKb219.963c27d.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-45e6be2c;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: Call-ID: d1a6837-d8cbae54@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 <------------> [Mar 7 11:45:44] DEBUG[32128]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-081d7b50 [Mar 7 11:45:44] DEBUG[32310]: pbx.c:1791 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-081d7b50", "X-Custom-Test3: ") in new stack [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:16974 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Mar 7 11:45:44] DEBUG[32310]: pbx.c:1791 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-081d7b50", "X-Custom-Network: class4") in new stack [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:16974 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Mar 7 11:45:44] DEBUG[32310]: pbx.c:1791 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-081d7b50", "SIP/1234@ser") in new stack [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:15267 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2619 create_addr_from_peer: Our T38 capability (3856) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to On [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to On [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2583 do_setnat: Setting NAT on UDPTL to On [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3803 sip_new: *** Our native formats are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x0 (nothing) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x18050b (g723|gsm|alaw|g729|ilbc|h263|h263p) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3808 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable NODE_IP. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_DB. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable EMER_NUMS. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3288 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Mar 7 11:45:44] DEBUG[32310]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPURI. [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2828 sip_call: Outgoing Call for 1234 [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:2843 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6819 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6819 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6182 add_sdp: ** Our capability: 0x180100 (g729|h263|h263p) Video flag: False [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x100 (g729) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6198 add_sdp: This call needs video offers! Video is at 10.0.0.2 port 10566 Audio is at 10.0.0.2 port 17004 Adding codec 0x100 (g729) to SDP Adding codec 0x80000 (h263) to SDP Adding codec 0x100000 (h263p) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x180100 (g729|h263|h263p) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (45) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK3494043d;rport (65) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 2: From: "ivo test" ;tag=as5876cc43 (67) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 3: To: (36) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 4: Contact: (39) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 7: User-Agent: asterisk(27) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 9: Remote-Party-ID: "ivo test" ;privacy=off;screen=no (85) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 10: Date: Wed, 07 Mar 2007 09:45:44 GMT (35) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 12: Supported: replaces (19) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 13: X-Custom-Network: class4 (26) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 14: X-Custom-Test3: (24) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 15: Content-Type: application/sdp (29) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 16: Content-Length: 373 (19) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4571 parse_request: Header 17: (0) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: o=root 32120 32120 IN IP4 10.0.0.2 (40) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: b=CT:384 (8) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: m=audio 17004 RTP/AVP 18 101 (28) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=fmtp:18 annexb=no (19) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: m=video 10566 RTP/AVP 34 103 (28) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:4603 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=z9hG4bK3494043d;rport From: "ivo test" ;tag=as5876cc43 To: Contact: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld CSeq: 102 INVITE User-Agent: asterisk Max-Forwards: 70 Remote-Party-ID: "ivo test" ;privacy=off;screen=no Date: Wed, 07 Mar 2007 09:45:44 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: 373 v=0 o=root 32120 32120 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 b=CT:384 t=0 0 m=audio 17004 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 m=video 10566 RTP/AVP 34 103 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=sendrecv --- [Mar 7 11:45:44] DEBUG[32310]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #31 -- Called 1234@ser [Mar 7 11:45:44] DEBUG[32123]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Mar 7 11:45:44] DEBUG[32123]: chan_sip.c:15201 sip_devicestate: Checking device state for peer mydomain.tld [Mar 7 11:45:44] DEBUG[32123]: 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 100 trying -- your call is important to us Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK3494043d;rport=5060 From: "ivo test" ;tag=as5876cc43 To: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld CSeq: 102 INVITE Content-Length: 0 <-------------> [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK3494043d;rport=5060 (70) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: "ivo test" ;tag=as5876cc43 (67) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: To: (36) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: (0) --- (7 headers 0 lines) --- [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #31 - INVITE (got response) [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' Request 102: Found [Mar 7 11:45:44] DEBUG[32128]: chan_sip.c:11621 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=z9hG4bK3494043d;rport=5060 From: "ivo test" ;tag=as5876cc43 To: ;tag=6839F264-10C5 Date: Wed, 07 Mar 2007 09:45:44 GMT Call-ID: 4ccf86cf7c203b5634f874282352f8e3@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 8912 8951 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 17366 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 <-------------> [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK3494043d;rport=5060 (70) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: "ivo test" ;tag=as5876cc43 (67) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=6839F264-10C5 (54) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: Date: Wed, 07 Mar 2007 09:45:44 GMT (35) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Allow-Events: telephone-event (29) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: Contact: (45) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: Record-Route: (56) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 14: Content-Length: 346 (19) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8912 8951 IN IP4 10.3.0.1 (61) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=SIP Call (10) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=audio 17366 RTP/AVP 18 101 (28) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:18 annexb=no (19) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (15 headers 15 lines) --- [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' Request 102: Found [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:11621 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:4893 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:17366 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 [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/ser-08220f78 Capabilities: us - 0x18050b (g723|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:17366 [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Mar 7 11:45:45] DEBUG[32128]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call -- Call on SIP/ser-08220f78 left from hold -- SIP/ser-08220f78 is making progress passing it to SIP/mydomain.tld-081d7b50 [Mar 7 11:45:45] DEBUG[32310]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 7 11:45:45] DEBUG[32310]: chan_sip.c:6182 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Mar 7 11:45:45] DEBUG[32310]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 12082 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 7 11:45:45] DEBUG[32310]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 7 11:45:45] DEBUG[32310]: chan_sip.c:6359 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=z9hG4bKb219.963c27d.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-45e6be2c;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@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 32120 32120 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 12082 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 <------------> [Mar 7 11:45:45] DEBUG[32310]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Mar 7 11:45:45] DEBUG[32310]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Mar 7 11:45:45] DEBUG[32310]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Mar 7 11:45:45] DEBUG[32310]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Mar 7 11:45:46] DEBUG[32310]: rtp.c:871 ast_rtcp_read: Got RTCP report of 88 bytes [Mar 7 11:45:48] DEBUG[32310]: 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=z9hG4bK3494043d;rport=5060 From: "ivo test" ;tag=as5876cc43 To: ;tag=6839F264-10C5 Date: Wed, 07 Mar 2007 09:45:44 GMT Call-ID: 4ccf86cf7c203b5634f874282352f8e3@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 8912 8951 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 17366 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 <-------------> [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK3494043d;rport=5060 (70) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: "ivo test" ;tag=as5876cc43 (67) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=6839F264-10C5 (54) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: Date: Wed, 07 Mar 2007 09:45:44 GMT (35) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Allow-Events: telephone-event (29) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: Contact: (45) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: Record-Route: (56) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 13: Content-Length: 346 (19) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 14: (0) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8912 8951 IN IP4 10.3.0.1 (61) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=SIP Call (10) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=audio 17366 RTP/AVP 18 101 (28) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:18 annexb=no (19) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (14 headers 15 lines) --- [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:2069 __sip_ack: Acked pending invite 102 [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' of Request 102: Match Not Found [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:11621 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Found RTP audio format 101 Found RTP video format 34 [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4893 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.3.0.1:17366 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 [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/ser-08220f78 Capabilities: us - 0x18050b (g723|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:17366 [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:7935 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=z9hG4bK1446f6bd;rport Route: From: "ivo test" ;tag=as5876cc43 To: ;tag=6839F264-10C5 Contact: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld CSeq: 102 ACK User-Agent: asterisk Max-Forwards: 70 Remote-Party-ID: "ivo test" ;privacy=off;screen=no Content-Length: 0 --- -- Call on SIP/ser-08220f78 left from hold [Mar 7 11:45:49] DEBUG[32310]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08220f78 -- SIP/ser-08220f78 answered SIP/mydomain.tld-081d7b50 [Mar 7 11:45:49] DEBUG[32310]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-081d7b50 [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:3461 sip_answer: SIP answering channel: SIP/mydomain.tld-081d7b50 [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:6182 add_sdp: ** Our capability: 0x100 (g729) Video flag: True [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.0.0.2 port 12082 Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:6359 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=z9hG4bKb219.963c27d.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-45e6be2c;rport=5387 Record-Route: From: ivo test ;tag=6ecb56db440cf000o0 To: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@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 32120 32121 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 12082 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 <------------> [Mar 7 11:45:49] DEBUG[32310]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 [Mar 7 11:45:49] DEBUG[32310]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Mar 7 11:45:49] DEBUG[32123]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Mar 7 11:45:49] DEBUG[32123]: chan_sip.c:15201 sip_devicestate: Checking device state for peer ser [Mar 7 11:45:49] DEBUG[32123]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Mar 7 11:45:49] DEBUG[32123]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Mar 7 11:45:49] DEBUG[32123]: chan_sip.c:15201 sip_devicestate: Checking device state for peer mydomain.tld [Mar 7 11:45:49] DEBUG[32123]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Mar 7 11:45:49] NOTICE[32310]: 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=z9hG4bKb219.963c27d.2 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-131bcab7;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 102 ACK Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45ee8af4c1c00fb16beea77b659dcbd1deb45bcd",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="b828b1b50e600d96d3b0529559e86d5e" Contact: ivo test User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: ACK sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKb219.963c27d.2 (60) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-131bcab7;rport=5387 (71) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: From: ivo test ;tag=6ecb56db440cf000o0 (73) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: To: ;tag=as1ce304e5 (49) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 ACK (13) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Max-Forwards: 69 (16) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45ee8af4c1c00fb16beea77b659dcbd1deb45bcd",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="b828b1b50e600d96d3b0529559e86d5e" (218) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Contact: ivo test (53) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: Content-Length: 0 (17) [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 [Mar 7 11:45:49] DEBUG[32128]: chan_sip.c:2087 __sip_ack: Stopping retransmission on 'd1a6837-d8cbae54@10.2.0.1' of Response 102: Match Not Found [Mar 7 11:45:51] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:51] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:51] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:51] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] NOTICE[32310]: rtp.c:1254 ast_rtp_read: Unknown RTP codec 100 received from '10.3.0.1' [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:52] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:53] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: chan_sip.c:4084 sip_rtp_read: Bogus frame of format 'alaw' received from 'SIP/ser-08220f78'! [Mar 7 11:45:54] DEBUG[32310]: 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=z9hG4bKa074.5e8539f1.0 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK2173D16BC From: ;tag=6839F264-10C5 To: "ivo test" ;tag=as5876cc43 Date: Wed, 07 Mar 2007 09:45:54 GMT Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld Supported: 100rel,timer,replaces Min-SE: 1800 Cisco-Guid: 1950127346-3418821083-3210644656-3299621967 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: 1173260754 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 769 v=0 o=CiscoSystemsSIP-GW-UserAgent 8912 8952 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=image 17366 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 <-------------> [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:2222@10.0.0.2:5060 SIP/2.0 (48) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKa074.5e8539f1.0 (61) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK2173D16BC (60) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: From: ;tag=6839F264-10C5 (56) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: To: "ivo test" ;tag=as5876cc43 (65) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Date: Wed, 07 Mar 2007 09:45:54 GMT (35) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Supported: 100rel,timer,replaces (32) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Min-SE: 1800 (13) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Cisco-Guid: 1950127346-3418821083-3210644656-3299621967 (55) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: CSeq: 101 INVITE (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 13: Max-Forwards: 69 (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 14: Timestamp: 1173260754 (21) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 15: Contact: (45) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 16: Expires: 180 (12) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 17: Allow-Events: telephone-event (29) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 18: Content-Type: application/sdp (29) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 19: Content-Length: 769 (19) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 20: (0) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8912 8952 IN IP4 10.3.0.1 (61) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=SIP Call (10) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=image 17366 udptl 101 t38 t38 (31) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38MaxBitRate:7200 (20) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38MaxBitRate:7200 (20) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.3.0.1 (22) --- (20 headers 30 lines) --- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,replaces" [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1686 parse_sip_options: Found SIP option: -100rel- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1692 parse_sip_options: Matched SIP option: 100rel [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1686 parse_sip_options: Found SIP option: -timer- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1692 parse_sip_options: Matched SIP option: timer [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1686 parse_sip_options: Found SIP option: -replaces- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1692 parse_sip_options: Matched SIP option: replaces Sending to 10.0.0.1 : 5060 (NAT) Got T.38 offer in SDP in dialog 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4839 process_sdp: T38 state changed to 4 on channel SIP/ser-08220f78 Found RTP video format 34 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4889 process_sdp: Peer T.38 UDPTL is at port 10.3.0.1:17366 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5055 process_sdp: FaxVersion: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5031 process_sdp: T38MaxBitRate: 7200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5069 process_sdp: FillBitRemoval: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5075 process_sdp: Transcoding MMR: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5082 process_sdp: Transcoding JBIG: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5088 process_sdp: RateMangement: transferredTCF [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5027 process_sdp: MaxBufferSize:200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5063 process_sdp: FaxMaxDatagram: 72 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5096 process_sdp: UDP EC: t38UDPRedundancy [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5055 process_sdp: FaxVersion: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5031 process_sdp: T38MaxBitRate: 7200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5069 process_sdp: FillBitRemoval: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5075 process_sdp: Transcoding MMR: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5082 process_sdp: Transcoding JBIG: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5088 process_sdp: RateMangement: transferredTCF [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5027 process_sdp: MaxBufferSize:200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5063 process_sdp: FaxMaxDatagram: 72 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5096 process_sdp: UDP EC: t38UDPRedundancy [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5116 process_sdp: Our T38 capability = (3856), peer T38 capability (1824), joint T38 capability (1824) Capabilities: us - 0x18050b (g723|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:17366 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x80000 (h263) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:13431 handle_request_invite: Got a SIP re-invite for call 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:13526 handle_request_invite: SIP/ser-08220f78: This call is UP.... [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:16709 sip_handle_t38_reinvite: Sending reinvite on SIP 'd1a6837-d8cbae54@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 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:6036 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4790 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:6042 add_t38_sdp: Our T38 capability (3856), peer T38 capability (1824), joint capability (1824) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5973 t38_get_rate: T38MaxFaxRate 7200 found [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1619 initialize_initreq: Initializing already initialized SIP dialog d1a6837-d8cbae54@10.2.0.1 (presumably reinvite) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:2222@10.2.0.1:5387 SIP/2.0 (48) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK22066fa3;rport (65) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Route: (57) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: From: ;tag=as1ce304e5 (51) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: To: ivo test ;tag=6ecb56db440cf000o0 (71) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Contact: (34) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: User-Agent: asterisk(27) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Max-Forwards: 70 (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 12: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 14: Content-Length: 351 (19) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=root 32120 32122 IN IP4 10.0.0.2 (40) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=image 4790 udptl t38 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38MaxBitRate:7200 (20) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) Reliably Transmitting (NAT) to 10.0.0.1:5060: INVITE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK22066fa3;rport Route: From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Contact: Call-ID: d1a6837-d8cbae54@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 32120 32122 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4790 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 --- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #36 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=z9hG4bK22066fa3;rport=5060 From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 102 INVITE Content-Length: 0 <-------------> [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK22066fa3;rport=5060 (70) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=as1ce304e5 (51) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: To: ivo test ;tag=6ecb56db440cf000o0 (71) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: (0) --- (7 headers 0 lines) --- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #36 - INVITE (got response) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on 'd1a6837-d8cbae54@10.2.0.1' Request 102: Found [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:11619 handle_response_invite: SIP response 100 to RE-invite on outgoing call d1a6837-d8cbae54@10.2.0.1 a-node2*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ivo test ;tag=6ecb56db440cf000o0 From: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK22066fa3;rport=5060 Contact: ivo test Server: Linksys/SPA2102-3.3.6 Content-Length: 265 Content-Type: application/sdp v=0 o=- 8843 8843 IN IP4 10.2.0.1 s=- c=IN IP4 10.2.0.1 t=0 0 m=image 16468 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:200 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: To: ivo test ;tag=6ecb56db440cf000o0 (71) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=as1ce304e5 (51) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 INVITE (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK22066fa3;rport=5060 (70) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Contact: ivo test (53) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Server: Linksys/SPA2102-3.3.6 (29) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 265 (19) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: (0) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: o=- 8843 8843 IN IP4 10.2.0.1 (35) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: s=- (3) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: m=image 16468 udptl t38 (23) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxVersion:0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38MaxBitRate:14400 (21) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxMaxDatagram:200 (23) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4603 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (10 headers 12 lines) --- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2069 __sip_ack: Acked pending invite 102 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2087 __sip_ack: Stopping retransmission on 'd1a6837-d8cbae54@10.2.0.1' of Request 102: Match Not Found [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:11619 handle_response_invite: SIP response 200 to RE-invite on outgoing call d1a6837-d8cbae54@10.2.0.1 Got T.38 offer in SDP in dialog d1a6837-d8cbae54@10.2.0.1 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4839 process_sdp: T38 state changed to 4 on channel SIP/mydomain.tld-081d7b50 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4889 process_sdp: Peer T.38 UDPTL is at port 10.2.0.1:16468 Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid d1a6837-d8cbae54@10.2.0.1 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5055 process_sdp: FaxVersion: 0 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5031 process_sdp: T38MaxBitRate: 14400 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5088 process_sdp: RateMangement: transferredTCF [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5027 process_sdp: MaxBufferSize:200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5063 process_sdp: FaxMaxDatagram: 200 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5096 process_sdp: UDP EC: t38UDPRedundancy [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5116 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x18050b (g723|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) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5158 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:7964 build_route: build_route: Contact hop: ivo test list_route: hop: [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:16737 sip_handle_t38_reinvite: Responding 200 OK on SIP '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' - It's UDPTL soon redirected to us (IP 10.0.0.2) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:16742 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/mydomain.tld-081d7b50 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:16743 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/ser-08220f78 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:6036 add_t38_sdp: T.38 UDPTL is at 10.0.0.2 port 4780 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:6042 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5969 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=z9hG4bKa074.5e8539f1.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK2173D16BC From: ;tag=6839F264-10C5 To: "ivo test" ;tag=as5876cc43 Call-ID: 4ccf86cf7c203b5634f874282352f8e3@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 32120 32121 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=image 4780 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 <------------> [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:5637 reqprep: Strict routing enforced for session d1a6837-d8cbae54@10.2.0.1 set_destination: Parsing for address/port to send to set_destination: set destination to 10.2.0.1, port 5387 Transmitting (NAT) to 10.0.0.1:5060: ACK sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK151a23e7;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Contact: Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 102 ACK User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:45:54] DEBUG[32310]: 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=z9hG4bKa074.5e8539f1.2 Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK2173E22D4 From: ;tag=6839F264-10C5 To: "ivo test" ;tag=as5876cc43 Date: Wed, 07 Mar 2007 09:45:54 GMT Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld Max-Forwards: 69 CSeq: 101 ACK Content-Length: 0 <-------------> [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: ACK sip:2222@10.0.0.2:5060 SIP/2.0 (45) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKa074.5e8539f1.2 (61) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Via: SIP/2.0/UDP 10.3.0.1:5060;branch=z9hG4bK2173E22D4 (60) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: From: ;tag=6839F264-10C5 (56) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: To: "ivo test" ;tag=as5876cc43 (65) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Date: Wed, 07 Mar 2007 09:45:54 GMT (35) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Max-Forwards: 69 (16) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: CSeq: 101 ACK (13) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [Mar 7 11:45:54] DEBUG[32128]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' of Response 101: Match Not Found [Mar 7 11:46:29] DEBUG[32310]: rtp.c:871 ast_rtcp_read: Got RTCP report of 96 bytes [Mar 7 11:46:42] NOTICE[32128]: chan_sip.c:14958 do_monitor: Disconnecting call 'SIP/ser-08220f78' for lack of RTP activity in 16 seconds [Mar 7 11:46:42] DEBUG[32128]: channel.c:1480 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/ser-08220f78' [Mar 7 11:46:42] DEBUG[32310]: channel.c:3800 ast_generic_bridge: Didn't get a frame from channel: SIP/ser-08220f78 [Mar 7 11:46:42] DEBUG[32310]: channel.c:4118 ast_channel_bridge: Bridge stops bridging channels SIP/mydomain.tld-081d7b50 and SIP/ser-08220f78 [Mar 7 11:46:42] DEBUG[32310]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/ser-08220f78' [Mar 7 11:46:42] DEBUG[32310]: chan_sip.c:3310 sip_hangup: Hangup call SIP/ser-08220f78, SIP callid 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld) Scheduling destruction of SIP dialog '4ccf86cf7c203b5634f874282352f8e3@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=z9hG4bK28eb5457;rport Route: From: "ivo test" ;tag=as5876cc43 To: ;tag=6839F264-10C5 Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Remote-Party-ID: "ivo test" ;privacy=off;screen=no Content-Length: 0 --- [Mar 7 11:46:42] DEBUG[32310]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #39 [Mar 7 11:46:42] DEBUG[32310]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08220f78 [Mar 7 11:46:42] DEBUG[32310]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Mar 7 11:46:42] DEBUG[32310]: app_dial.c:1670 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Mar 7 11:46:42] DEBUG[32310]: pbx.c:2389 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-081d7b50' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-081d7b50' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '"ivo test" <2222>' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2222' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1234' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-081d7b50' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-08220f78' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'Dial' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-07 11:45:44' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-07 11:45:49' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-07 11:46:42' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '58' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '53' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1173260744.2' [Mar 7 11:46:42] DEBUG[32310]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 7 11:46:42] DEBUG[32310]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/mydomain.tld-081d7b50' [Mar 7 11:46:42] DEBUG[32310]: chan_sip.c:3310 sip_hangup: Hangup call SIP/mydomain.tld-081d7b50, SIP callid d1a6837-d8cbae54@10.2.0.1) Scheduling destruction of SIP dialog 'd1a6837-d8cbae54@10.2.0.1' in 32000 ms (Method: ACK) [Mar 7 11:46:42] DEBUG[32310]: chan_sip.c:5637 reqprep: Strict routing enforced for session d1a6837-d8cbae54@10.2.0.1 set_destination: Parsing for address/port to send to set_destination: set destination to 10.2.0.1, port 5387 Reliably Transmitting (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:42] DEBUG[32310]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #41 [Mar 7 11:46:42] DEBUG[32310]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-081d7b50 [Mar 7 11:46:42] DEBUG[32123]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Mar 7 11:46:42] DEBUG[32123]: chan_sip.c:15201 sip_devicestate: Checking device state for peer ser [Mar 7 11:46:42] DEBUG[32123]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Mar 7 11:46:42] DEBUG[32123]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Mar 7 11:46:42] DEBUG[32123]: chan_sip.c:15201 sip_devicestate: Checking device state for peer mydomain.tld [Mar 7 11:46:42] DEBUG[32123]: 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=z9hG4bK28eb5457;rport=5060 From: "ivo test" ;tag=as5876cc43 To: ;tag=6839F264-10C5 Date: Wed, 07 Mar 2007 09:46:42 GMT Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE <-------------> [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK28eb5457;rport=5060 (70) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: From: "ivo test" ;tag=as5876cc43 (67) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=6839F264-10C5 (54) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: Date: Wed, 07 Mar 2007 09:46:42 GMT (35) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4ccf86cf7c203b5634f874282352f8e3@mydomain.tld (61) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Content-Length: 0 (17) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: CSeq: 103 BYE (13) [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #39 [Mar 7 11:46:42] DEBUG[32128]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' of Request 103: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '4ccf86cf7c203b5634f874282352f8e3@mydomain.tld' Method: ACK [Mar 7 11:46:43] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (1) BYE - 8 [Mar 7 11:46:43] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #41)) Retransmitting #1 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:44] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (2) BYE - 8 [Mar 7 11:46:44] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #41)) Retransmitting #2 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:46] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (3) BYE - 8 [Mar 7 11:46:46] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #41)) Retransmitting #3 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:50] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (4) BYE - 8 [Mar 7 11:46:50] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #41)) Retransmitting #4 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:54] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (5) BYE - 8 [Mar 7 11:46:54] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #41)) Retransmitting #5 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- [Mar 7 11:46:58] DEBUG[32128]: chan_sip.c:1864 retrans_pkt: SIP TIMER: Rescheduling retransmission #41 (6) BYE - 8 [Mar 7 11:46:58] DEBUG[32128]: chan_sip.c:1878 retrans_pkt: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #41)) Retransmitting #6 (NAT) to 10.0.0.1:5060: BYE sip:2222@10.2.0.1:5387 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK59b1a664;rport From: ;tag=as1ce304e5 To: ivo test ;tag=6ecb56db440cf000o0 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE User-Agent: asterisk Max-Forwards: 70 Content-Length: 0 --- a-node2*CLI> a-node2*CLI> a-node2*CLI> [Mar 7 11:47:02] WARNING[32128]: chan_sip.c:1897 retrans_pkt: Maximum retries exceeded on transmission d1a6837-d8cbae54@10.2.0.1 for seqno 103 (Non-critical Request) 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=z9hG4bKc219.055a1a16.0 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-a8b5ce32;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@10.2.0.1 CSeq: 103 BYE Max-Forwards: 69 Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45ee8af4c1c00fb16beea77b659dcbd1deb45bcd",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="2000cfcd7df3f1172203a8a1f6708e3d" User-Agent: Linksys/SPA2102-3.3.6 Content-Length: 0 <-------------> [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 0: BYE sip:1234@10.0.0.2:5060 SIP/2.0 (40) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKc219.055a1a16.0 (61) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 2: Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-a8b5ce32;rport=5387 (71) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 3: From: ivo test ;tag=6ecb56db440cf000o0 (73) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 4: To: ;tag=as1ce304e5 (49) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 5: Call-ID: d1a6837-d8cbae54@10.2.0.1 (40) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 6: CSeq: 103 BYE (13) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 7: Max-Forwards: 69 (16) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="45ee8af4c1c00fb16beea77b659dcbd1deb45bcd",uri="sip:1234@10.0.0.2:5060",algorithm=MD5,response="2000cfcd7df3f1172203a8a1f6708e3d" (218) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Linksys/SPA2102-3.3.6 (33) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:4571 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:14590 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 10.0.0.1 : 5060 (NAT) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:1631 sip_alreadygone: Setting SIP_ALREADYGONE on dialog d1a6837-d8cbae54@10.2.0.1 Scheduling destruction of SIP dialog 'd1a6837-d8cbae54@10.2.0.1' in 32000 ms (Method: BYE) [Mar 7 11:47:07] DEBUG[32128]: chan_sip.c:14171 handle_request_bye: Received bye, no owner, selfdestruct soon. <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKc219.055a1a16.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:5387;branch=z9hG4bK-a8b5ce32;rport=5387 From: ivo test ;tag=6ecb56db440cf000o0 To: ;tag=as1ce304e5 Call-ID: d1a6837-d8cbae54@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 <------------>