a-node0*CLI> <--- SIP read from 10.0.0.1:5060 ---> INVITE sip:1234@10.0.0.2 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK569d632e;rport=5060 From: "Bob" ;tag=as48481452 To: Contact: Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld CSeq: 103 INVITE User-Agent: Asterisk Max-Forwards: 69 Remote-Party-ID: "Bob" ;privacy=off;screen=yes Proxy-Authorization: Digest username="a-node0", realm="mydomain.tld", algorithm=MD5, uri="sip:1234@10.0.0.1", nonce="45d32f97df04bc58427c5f48163ebd0447094b9f", response="c934fdb88de30e1b2a921f9181e367e4", opaque="" Date: Wed, 14 Feb 2007 15:44:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Diversion: "anonymous" ;reason=no-answer X-Custom-Forward-Profile: 2222,Bob,2,0,0,0,1,1,,00,0,359,1,0,1,EET,0,1,9,2001,,en,1,0,0 X-Custom-Caller-Profile: 0,1,Mark X-Custom-Loop: 1 X-Custom-Orig-ANI: 3333 Alert-Info: Bellcore-r3 X-Custom-Network: class5 X-Custom-Init-Leg: 1972BB06-BB7911DB-A800D7B6-4EC83CA6@10.3.0.1 Content-Type: application/sdp Content-Length: 465 X-Custom-Max-Duration: 7200000 v=0 o=root 11334 11335 IN IP4 10.0.0.3 s=session c=IN IP4 10.0.0.3 b=CT:384 t=0 0 m=audio 12302 RTP/AVP 18 8 3 97 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv m=video 13462 RTP/AVP 34 103 99 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=rtpmap:99 H264/90000 a=sendrecv <-------------> [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: INVITE sip:1234@10.0.0.2 SIP/2.0 (38) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: Record-Route: (56) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0 (61) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK569d632e;rport=5060 (70) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: From: "Bob" ;tag=as48481452 (60) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: To: (29) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: Contact: (46) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld (57) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: CSeq: 103 INVITE (16) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 9: User-Agent: Asterisk (27) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 10: Max-Forwards: 69 (16) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 11: Remote-Party-ID: "Bob" ;privacy=off;screen=yes (79) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 12: Proxy-Authorization: Digest username="a-node0", realm="mydomain.tld", algorithm=MD5, uri="sip:1234@10.0.0.1", nonce="45d32f97df04bc58427c5f48163ebd0447094b9f", response="c934fdb88de30e1b2a921f9181e367e4", opaque="" (223) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 13: Date: Wed, 14 Feb 2007 15:44:43 GMT (35) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 14: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 15: Supported: replaces (19) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 16: Diversion: "anonymous" ;reason=no-answer (72) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 17: X-Custom-Forward-Profile: 2222,Bob,2,0,0,0,1,1,,00,0,359,1,0,1,EET,0,1,9,2001,,en,1,0,0 (96) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 18: X-Custom-Caller-Profile: 0,1,Mark (43) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 19: X-Custom-Loop: 1 (18) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 20: X-Custom-Orig-ANI: 3333 (32) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 21: Alert-Info: Bellcore-r3 (23) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 22: X-Custom-Network: class5 (26) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 23: X-Custom-Init-Leg: 1972BB06-BB7911DB-A800D7B6-4EC83CA6@10.3.0.1 (70) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 24: Content-Type: application/sdp (29) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 25: Content-Length: 465 (19) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 26: X-Custom-Max-Duration: 7200000 (32) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 27: (0) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: v=0 (3) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: o=root 11334 11335 IN IP4 10.0.0.3 (40) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: s=session (9) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: c=IN IP4 10.0.0.3 (23) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: b=CT:384 (8) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: t=0 0 (5) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: m=audio 12302 RTP/AVP 18 8 3 97 101 (35) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=fmtp:18 annexb=no (19) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=fmtp:97 mode=30 (17) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=fmtp:101 0-16 (15) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=ptime:20 (10) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=sendrecv (10) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: m=video 13462 RTP/AVP 34 103 99 (31) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:99 H264/90000 (22) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=sendrecv (10) --- (27 headers 22 lines) --- [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2572 do_setnat: Setting NAT on RTP to Off [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2577 do_setnat: Setting NAT on VRTP to Off [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2582 do_setnat: Setting NAT on UDPTL to Off [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4292 sip_alloc: Allocating new SIP dialog for 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld - INVITE (With RTP) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:14560 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:1677 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:1685 parse_sip_options: Found SIP option: -replaces- [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:1691 parse_sip_options: Matched SIP option: replaces Sending to 10.0.0.1 : 5060 (no NAT) Using INVITE request as basis request - 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld Found peer 'ser' [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2572 do_setnat: Setting NAT on RTP to On [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2577 do_setnat: Setting NAT on VRTP to On [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2582 do_setnat: Setting NAT on UDPTL to On Found RTP audio format 18 Found RTP audio format 8 Found RTP audio format 3 Found RTP audio format 97 Found RTP audio format 101 Found RTP video format 34 Found RTP video format 103 Found RTP video format 99 [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4867 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.0.0.3:12302 Found description format G729 for ID 18 Got unsupported a:fmtp in SDP offer Found description format PCMA for ID 8 Found description format GSM for ID 3 Found description format iLBC for ID 97 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Found description format H263 for ID 34 Found description format h263-1998 for ID 103 Found description format H264 for ID 99 [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:5097 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264), peer - audio=0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264)/video=0x380000 (h263|h263p|h264), combined - 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.0.0.3:12302 Peer video RTP is at port 10.0.0.3:13462 [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:5177 process_sdp: We're settling with these formats: 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:13348 handle_request_invite: Checking SIP call limits for device [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3000 update_call_counter: Updating call counter for incoming call Looking for 1234 in pre-process (domain 10.0.0.2) RDNIS is 2222 [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3795 sip_new: *** Our native formats are 0x380100 (g729|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3796 sip_new: *** Joint capabilities are 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3797 sip_new: *** Our capabilities are 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3798 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:3819 sip_new: This channel can handle video! HOLLYWOOD next! [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:7909 build_route: build_route: Record-Route hop: list_route: hop: [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:13423 handle_request_invite: SIP/mydomain.tld-081ff6e0: 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=z9hG4bK0ed8.1bc4b082.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK569d632e;rport=5060 From: "Bob" ;tag=as48481452 To: Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 14 17:44:43] DEBUG[5472]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-081ff6e0 [Feb 14 17:44:43] DEBUG[5469]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Feb 14 17:44:43] DEBUG[5469]: chan_sip.c:15165 sip_devicestate: Checking device state for peer mydomain.tld [Feb 14 17:44:43] DEBUG[5469]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Feb 14 17:44:43] DEBUG[5583]: pbx.c:1769 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-081ff6e0", "X-Custom-Tech-Prefix: ") in new stack [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:16936 sip_addheader: SIP Header added "X-Custom-Tech-Prefix: " as _SIPADDHEADER01 [Feb 14 17:44:43] DEBUG[5583]: pbx.c:1769 pbx_extension_helper: Launching 'SIPAddHeader' -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-081ff6e0", "X-Custom-Network: class5") in new stack [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:16936 sip_addheader: SIP Header added "X-Custom-Network: class5" as _SIPADDHEADER02 [Feb 14 17:44:43] DEBUG[5583]: pbx.c:1769 pbx_extension_helper: Launching 'Dial' -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-081ff6e0", "SIP/1234@ser") in new stack [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:15231 sip_request_call: Asked to create a SIP channel with formats: 0x380100 (g729|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4292 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2618 create_addr_from_peer: Our T38 capability (3856) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2572 do_setnat: Setting NAT on RTP to On [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2577 do_setnat: Setting NAT on VRTP to On [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2582 do_setnat: Setting NAT on UDPTL to On [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3795 sip_new: *** Our native formats are 0x100 (g729) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3796 sip_new: *** Joint capabilities are 0x0 (nothing) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3797 sip_new: *** Our capabilities are 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3798 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3800 sip_new: *** Our preferred formats from the incoming channel are 0x380100 (g729|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3819 sip_new: This channel can handle video! HOLLYWOOD next! [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable IN_SIP_PROXY. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable IN_SIP_DOMAIN. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable NODE_IP. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_DB. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable EMER_NUMS. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3284 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Feb 14 17:44:43] DEBUG[5583]: channel.c:3297 ast_channel_inherit_variables: Not copying variable SIPURI. [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2827 sip_call: Outgoing Call for 1234 [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:3000 update_call_counter: Updating call counter for outgoing call [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:2842 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6793 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class5: [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6793 transmit_invite: Adding SIP Header "X-Custom-Tech-Prefix" with content :: [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6156 add_sdp: ** Our capability: 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) Video flag: False [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6157 add_sdp: ** Our prefcodec: 0x380100 (g729|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6172 add_sdp: This call needs video offers! Video is at 10.0.0.2 port 17464 Audio is at 10.0.0.2 port 10124 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x400 (ilbc) to SDP Adding codec 0x80000 (h263) to SDP Adding codec 0x100000 (h263p) to SDP Adding codec 0x200000 (h264) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6288 add_sdp: -- Done with adding codecs to SDP [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:6333 add_sdp: Done building SDP. Settling with this capability: 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (43) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport (65) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as466264fb (60) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 3: To: (34) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 4: Contact: (41) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 5: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld (57) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 6: CSeq: 102 INVITE (16) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 7: User-Agent: Asterisk (27) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 8: Max-Forwards: 70 (16) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 9: Remote-Party-ID: "Bob" ;privacy=off;screen=no (78) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 10: Date: Wed, 14 Feb 2007 15:44:43 GMT (35) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 12: Supported: replaces (19) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 13: X-Custom-Network: class5 (26) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 14: X-Custom-Tech-Prefix: (24) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 15: Content-Type: application/sdp (29) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 16: Content-Length: 465 (19) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4555 parse_request: Header 17: (0) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: v=0 (3) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: o=root 10056 10056 IN IP4 10.0.0.2 (40) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: s=session (9) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: b=CT:384 (8) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: t=0 0 (5) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: m=audio 10124 RTP/AVP 18 8 3 97 101 (35) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=fmtp:18 annexb=no (19) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=fmtp:97 mode=30 (17) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=fmtp:101 0-16 (15) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=ptime:20 (10) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=sendrecv (10) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: m=video 17464 RTP/AVP 34 103 99 (31) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 parse_request: Line: a=rtpmap:99 H264/90000 (22) [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:4587 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=z9hG4bK4133e252;rport From: "Bob" ;tag=as466264fb To: Contact: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "Bob" ;privacy=off;screen=no Date: Wed, 14 Feb 2007 15:44:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-Custom-Network: class5 X-Custom-Tech-Prefix: Content-Type: application/sdp Content-Length: 465 v=0 o=root 10056 10056 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 b=CT:384 t=0 0 m=audio 10124 RTP/AVP 18 8 3 97 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv m=video 17464 RTP/AVP 34 103 99 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=rtpmap:99 H264/90000 a=sendrecv --- [Feb 14 17:44:43] DEBUG[5583]: chan_sip.c:1972 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14 -- Called 1234@ser a-node0*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=z9hG4bK4133e252;rport=5060 From: "Bob" ;tag=as466264fb To: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 102 INVITE Server: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: SIP/2.0 100 trying -- your call is important to us (50) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport=5060 (70) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as466264fb (60) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: To: (34) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld (57) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: CSeq: 102 INVITE (16) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: Server: OpenSer (1.1.0-notls (i386/linux)) (42) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Content-Length: 0 (17) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2119 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #14 - INVITE (got response) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2128 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' Request 102: Found [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:11595 handle_response_invite: SIP response 100 to standard invite a-node0*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 180 Ringing To: ;tag=ee5e53277a2ba025i1 From: "Bob" ;tag=as466264fb Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport=5060 Record-Route: Server: Linksys/PAP2T-5.1.1(LS) Content-Length: 0 <-------------> [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: To: ;tag=ee5e53277a2ba025i1 (57) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as466264fb (60) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld (57) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: CSeq: 102 INVITE (16) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport=5060 (70) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: Record-Route: (56) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Server: Linksys/PAP2T-5.1.1(LS) (31) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: Content-Length: 0 (17) [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:2128 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' Request 102: Found [Feb 14 17:44:43] DEBUG[5472]: chan_sip.c:11595 handle_response_invite: SIP response 180 to standard invite [Feb 14 17:44:43] DEBUG[5472]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08230148 [Feb 14 17:44:43] DEBUG[5469]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Feb 14 17:44:43] DEBUG[5469]: chan_sip.c:15165 sip_devicestate: Checking device state for peer ser [Feb 14 17:44:43] DEBUG[5469]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) -- SIP/ser-08230148 is ringing a-node0*CLI> <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK569d632e;rport=5060 From: "Bob" ;tag=as48481452 To: ;tag=as59d7e55f Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ;tag=ee5e53277a2ba025i1 From: "Bob" ;tag=as466264fb Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 102 INVITE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport=5060 Record-Route: Contact: SWAT Server: Linksys/PAP2T-5.1.1(LS) Content-Length: 286 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp v=0 o=- 294561 294561 IN IP4 10.5.0.1 s=- c=IN IP4 10.5.0.1 t=0 0 m=audio 16468 RTP/AVP 8 100 101 a=rtpmap:8 PCMA/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 m=video 0 RTP/AVP 34 103 99 <-------------> [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: To: ;tag=ee5e53277a2ba025i1 (57) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as466264fb (60) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld (57) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: CSeq: 102 INVITE (16) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK4133e252;rport=5060 (70) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: Record-Route: (56) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Contact: SWAT (49) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: Server: Linksys/PAP2T-5.1.1(LS) (31) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 9: Content-Length: 286 (19) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 11: Supported: x-sipura, replaces (29) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 12: Content-Type: application/sdp (29) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 13: (0) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: v=0 (3) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: o=- 294561 294561 IN IP4 10.5.0.1 (39) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: s=- (3) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: c=IN IP4 10.5.0.1 (23) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: t=0 0 (5) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: m=audio 16468 RTP/AVP 8 100 101 (31) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=fmtp:100 192-193 (18) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=fmtp:101 0-15 (15) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=ptime:30 (10) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: a=sendrecv (10) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4587 parse_request: Line: m=video 0 RTP/AVP 34 103 99 (27) --- (13 headers 14 lines) --- [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2068 __sip_ack: Acked pending invite 102 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2086 __sip_ack: Stopping retransmission on '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' of Request 102: Match Not Found [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:11595 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 100 Found RTP audio format 101 Found RTP video format 34 Found RTP video format 103 Found RTP video format 99 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4867 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.5.0.1:16468 Found description format PCMA for ID 8 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 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:5097 process_sdp: T38 state changed to 0 on channel SIP/ser-08230148 Capabilities: us - 0x38050a (gsm|alaw|g729|ilbc|h263|h263p|h264), peer - audio=0x380008 (alaw|h263|h263p|h264)/video=0x380000 (h263|h263p|h264), combined - 0x380008 (alaw|h263|h263p|h264) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.5.0.1:16468 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:5177 process_sdp: We're settling with these formats: 0x380008 (alaw|h263|h263p|h264) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:5184 process_sdp: We have an owner, now see if we need to change this call [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:5189 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x380008 (alaw|h263|h263p|h264) and not 0x100 (g729) [Feb 14 17:44:47] DEBUG[5472]: channel.c:2841 set_format: Set channel SIP/ser-08230148 to read format g729 [Feb 14 17:44:47] DEBUG[5472]: channel.c:2841 set_format: Set channel SIP/ser-08230148 to write format g729 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:3000 update_call_counter: Updating call counter for outgoing call [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:7909 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.5.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK39993d51;rport Route: From: "Bob" ;tag=as466264fb To: ;tag=ee5e53277a2ba025i1 Contact: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "Bob" ;privacy=off;screen=no Content-Length: 0 --- -- Call on SIP/ser-08230148 left from hold [Feb 14 17:44:47] DEBUG[5583]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08230148 [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Feb 14 17:44:47] DEBUG[5469]: chan_sip.c:15165 sip_devicestate: Checking device state for peer ser [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) -- SIP/ser-08230148 answered SIP/mydomain.tld-081ff6e0 [Feb 14 17:44:47] WARNING[5583]: channel.c:2812 set_format: Unable to find a codec translation path from unknown to unknown [Feb 14 17:44:47] WARNING[5583]: channel.c:3155 ast_channel_make_compatible: Unable to set read format on channel SIP/mydomain.tld-081ff6e0 to 524288 [Feb 14 17:44:47] WARNING[5583]: app_dial.c:1607 dial_exec_full: Had to drop call because I couldn't make SIP/mydomain.tld-081ff6e0 compatible with SIP/ser-08230148 [Feb 14 17:44:47] DEBUG[5583]: channel.c:1689 ast_hangup: Hanging up channel 'SIP/ser-08230148' [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3304 sip_hangup: Hangup call SIP/ser-08230148, SIP callid 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld) [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3312 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3000 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' in 32000 ms (Method: INVITE) set_destination: Parsing for address/port to send to set_destination: set destination to 10.0.0.1, port 5060 Reliably Transmitting (NAT) to 10.0.0.1:5060: BYE sip:1234@10.5.0.1:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK332981f7;rport Route: From: "Bob" ;tag=as466264fb To: ;tag=ee5e53277a2ba025i1 Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 103 BYE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "Bob" ;privacy=off;screen=no Content-Length: 0 --- [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:1972 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #17 [Feb 14 17:44:47] DEBUG[5583]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-08230148 [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Feb 14 17:44:47] DEBUG[5469]: chan_sip.c:15165 sip_devicestate: Checking device state for peer ser [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Feb 14 17:44:47] DEBUG[5583]: pbx.c:2367 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-081ff6e0' == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-081ff6e0' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '"Bob" <2222>' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '2222' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '1234' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-081ff6e0' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-08230148' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'Dial' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '2007-02-14 17:44:43' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '2007-02-14 17:44:47' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '4' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '0' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'NO ANSWER' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '1171467883.2' [Feb 14 17:44:47] DEBUG[5583]: pbx.c:1622 pbx_substitute_variables_helper_full: Function result is '' [Feb 14 17:44:47] DEBUG[5583]: channel.c:1689 ast_hangup: Hanging up channel 'SIP/mydomain.tld-081ff6e0' [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3304 sip_hangup: Hangup call SIP/mydomain.tld-081ff6e0, SIP callid 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld) [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3312 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3000 update_call_counter: Updating call counter for incoming call [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3325 sip_hangup: Hanging up channel in state Ring (not UP) Scheduling destruction of SIP dialog '55eb307c27eba5294d0c764a40cbc31b@mydomain.tld' in 32000 ms (Method: INVITE) [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:3263 hangup_cause2sip: AST hangup cause 16 (no match found in SIP) a-node0*CLI> <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 603 Declined Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.0.0.3:5060;branch=z9hG4bK569d632e;rport=5060 From: "Bob" ;tag=as48481452 To: ;tag=as59d7e55f Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Feb 14 17:44:47] DEBUG[5583]: chan_sip.c:1972 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #19 [Feb 14 17:44:47] DEBUG[5583]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-081ff6e0 [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Feb 14 17:44:47] DEBUG[5469]: chan_sip.c:15165 sip_devicestate: Checking device state for peer mydomain.tld [Feb 14 17:44:47] DEBUG[5469]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) a-node0*CLI> <--- SIP read from 10.0.0.1:5060 ---> ACK sip:1234@10.0.0.2 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0 From: "Bob" ;tag=as48481452 Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld To: ;tag=as59d7e55f CSeq: 103 ACK User-Agent: OpenSer (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: ACK sip:1234@10.0.0.2 SIP/2.0 (35) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bK0ed8.1bc4b082.0 (61) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as48481452 (60) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: Call-ID: 55eb307c27eba5294d0c764a40cbc31b@mydomain.tld (57) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: To: ;tag=as59d7e55f (44) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: CSeq: 103 ACK (13) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: User-Agent: OpenSer (1.1.0-notls (i386/linux)) (46) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Content-Length: 0 (17) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:14560 handle_request: **** Received ACK (6) - Command in SIP ACK [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2076 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #19 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2086 __sip_ack: Stopping retransmission on '55eb307c27eba5294d0c764a40cbc31b@mydomain.tld' of Response 103: Match Not Found a-node0*CLI> <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 OK To: ;tag=ee5e53277a2ba025i1 From: "Bob" ;tag=as466264fb Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld CSeq: 103 BYE Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK332981f7;rport=5060 Server: Linksys/PAP2T-5.1.1(LS) Content-Length: 0 <-------------> [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 0: SIP/2.0 200 OK (14) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 1: To: ;tag=ee5e53277a2ba025i1 (57) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 2: From: "Bob" ;tag=as466264fb (60) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 3: Call-ID: 7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld (57) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 4: CSeq: 103 BYE (13) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 5: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK332981f7;rport=5060 (70) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 6: Server: Linksys/PAP2T-5.1.1(LS) (31) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 7: Content-Length: 0 (17) [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:4555 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2076 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #17 [Feb 14 17:44:47] DEBUG[5472]: chan_sip.c:2086 __sip_ack: Stopping retransmission on '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' of Request 103: Match Not Found Really destroying SIP dialog '7cddf5524b0fef7f741ce9015ac4e4b9@mydomain.tld' Method: INVITE a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> a-node0*CLI> exit Executing last minute cleanups Asterisk cleanly ending (0). [root@a-node0 /]#