[Dec 5 22:45:15] <--- 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=z9hG4bKad17.d369d905.0 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 Max-Forwards: 69 Contact: To: "1234" From: ;tag=ee6b6e5b Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1003s stamp 31159 Content-Length: 369 X-Custom-Duration: 7200000 v=0 o=- 7 2 IN IP4 10.2.0.1 s=CounterPath eyeBeam 1.5 c=IN IP4 10.2.0.1 t=0 0 m=audio 52154 RTP/AVP 98 101 a=alt:1 2 : onGe5HAr Ea5yp7Yc 192.168.77.106 52154 a=alt:2 1 : f5Ko9+OD mDtKXYnG 10.2.0.1 52154 a=fmtp:101 0-15 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:7B9EBD27425B4A81BE3CE8916BA9EC37 <-------------> [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@10.0.0.2 SIP/2.0 (38) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Record-Route: (54) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0 (61) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 (99) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Max-Forwards: 69 (16) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Contact: (45) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: To: "1234" (43) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: From: ;tag=ee6b6e5b (57) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. (69) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: CSeq: 2 INVITE (14) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 11: Content-Type: application/sdp (29) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 12: User-Agent: eyeBeam release 1003s stamp 31159 (45) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 13: Content-Length: 369 (19) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 14: X-Custom-Duration: 7200000 (32) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: o=- 7 2 IN IP4 10.2.0.1 (29) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: s=CounterPath eyeBeam 1.5 (25) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.2.0.1 (23) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: m=audio 52154 RTP/AVP 98 101 (28) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=alt:1 2 : onGe5HAr Ea5yp7Yc 192.168.77.106 52154 (50) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=alt:2 1 : f5Ko9+OD mDtKXYnG 10.2.0.1 52154 (50) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=rtpmap:98 iLBC/8000 (21) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=x-rtp-session-id:7B9EBD27425B4A81BE3CE8916BA9EC37 (51) [Dec 5 22:45:15] --- (15 headers 13 lines) --- [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to Off [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to Off [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to Off [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. - INVITE (With RTP) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:14440 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 5 22:45:15] Sending to 10.0.0.1 : 5060 (no NAT) [Dec 5 22:45:15] Using INVITE request as basis request - 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. [Dec 5 22:45:15] Found peer 'ser' [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to On [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On [Dec 5 22:45:15] Found RTP audio format 98 [Dec 5 22:45:15] Found RTP audio format 101 [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL [Dec 5 22:45:15] Peer audio RTP is at port 10.2.0.1:52154 [Dec 5 22:45:15] Got unsupported a:fmtp in SDP offer [Dec 5 22:45:15] Found description format iLBC for ID 98 [Dec 5 22:45:15] Found description format telephone-event for ID 101 [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel [Dec 5 22:45:15] Capabilities: us - 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p), peer - audio=0x400 (ilbc)/video=0x0 (nothing), combined - 0x400 (ilbc) [Dec 5 22:45:15] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 5 22:45:15] Peer audio RTP is at port 10.2.0.1:52154 [Dec 5 22:45:15] Peer video RTP is at port 10.2.0.1:13572 [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:13224 handle_request_invite: Checking SIP call limits for device [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call [Dec 5 22:45:15] Looking for 1234 in pre-process (domain 10.0.0.2) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:3766 sip_new: *** Our native formats are 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:7859 build_route: build_route: Record-Route hop: [Dec 5 22:45:15] list_route: hop: [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:13297 handle_request_invite: SIP/mydomain.tld-0942b910: New call is still down.... Trying... [Dec 5 22:45:15] <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 From: ;tag=ee6b6e5b To: "1234" Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 5 22:45:15] DEBUG[15126]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-0942b910 [Dec 5 22:45:15] DEBUG[15094]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 5 22:45:15] DEBUG[15094]: chan_sip.c:15035 sip_devicestate: Checking device state for peer mydomain.tld [Dec 5 22:45:15] DEBUG[15094]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 5 22:45:15] DEBUG[19205]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' [Dec 5 22:45:15] -- Executing [1234@pre-process:1] SIPAddHeader("SIP/mydomain.tld-0942b910", "X-Custom-Test3: ") in new stack [Dec 5 22:45:15] DEBUG[19206]: app_queue.c:546 changethread: Device 'SIP/mydomain.tld' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:16800 sip_addheader: SIP Header added "X-Custom-Test3: " as _SIPADDHEADER01 [Dec 5 22:45:15] DEBUG[19205]: pbx.c:1767 pbx_extension_helper: Launching 'SIPAddHeader' [Dec 5 22:45:15] -- Executing [1234@pre-process:2] SIPAddHeader("SIP/mydomain.tld-0942b910", "X-Custom-Network: class4") in new stack [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:16800 sip_addheader: SIP Header added "X-Custom-Network: class4" as _SIPADDHEADER02 [Dec 5 22:45:15] DEBUG[19205]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' [Dec 5 22:45:15] -- Executing [1234@pre-process:3] Dial("SIP/mydomain.tld-0942b910", "SIP/1234@ser") in new stack [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:15093 sip_request_call: Asked to create a SIP channel with formats: 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4262 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2605 create_addr_from_peer: Our T38 capability (3856) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2559 do_setnat: Setting NAT on RTP to On [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2564 do_setnat: Setting NAT on VRTP to On [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2569 do_setnat: Setting NAT on UDPTL to On [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3766 sip_new: *** Our native formats are 0x100 (g729) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3767 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3768 sip_new: *** Our capabilities are 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3769 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3771 sip_new: *** Our preferred formats from the incoming channel are 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:3792 sip_new: This channel will not be able to handle video. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-3. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER02. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-2. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SIPADDHEADER01. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-pre-process-1234-1. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable NODE_IP. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_DB. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable TRANSFER_CONTEXT. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable EMER_NUMS. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable FAX_PROXY. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable PROXY. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable STRIP_CALLEE_CC. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_GENERIC_NUM. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable VM_NUM. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_LANGUAGE. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_MAX_DURATION. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable GLOBAL_NOANS_TIMEOUT. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable MAX_LOOP. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable DEFAULT_COUNTRY_CODE. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3172 ast_channel_inherit_variables: Copying soft-transferable variable SERVICE_PROVIDER. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 5 22:45:15] DEBUG[19205]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2812 sip_call: Outgoing Call for 1234 [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:2826 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6756 transmit_invite: Adding SIP Header "X-Custom-Network" with content :class4: [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6756 transmit_invite: Adding SIP Header "X-Custom-Test3" with content :: [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6119 add_sdp: ** Our capability: 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p) Video flag: False [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6120 add_sdp: ** Our prefcodec: 0x400 (ilbc) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6135 add_sdp: This call needs video offers! [Dec 5 22:45:15] Video is at 10.0.0.2 port 19388 [Dec 5 22:45:15] Audio is at 10.0.0.2 port 13920 [Dec 5 22:45:15] Adding codec 0x400 (ilbc) to SDP [Dec 5 22:45:15] Adding codec 0x100 (g729) to SDP [Dec 5 22:45:15] Adding codec 0x8 (alaw) to SDP [Dec 5 22:45:15] Adding codec 0x4 (ulaw) to SDP [Dec 5 22:45:15] Adding codec 0x2 (gsm) to SDP [Dec 5 22:45:15] Adding codec 0x80000 (h263) to SDP [Dec 5 22:45:15] Adding codec 0x100000 (h263p) to SDP [Dec 5 22:45:15] Adding non-codec 0x1 (telephone-event) to SDP [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6251 add_sdp: -- Done with adding codecs to SDP [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:6296 add_sdp: Done building SDP. Settling with this capability: 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 0: INVITE sip:1234@10.0.0.1 SIP/2.0 (46) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport (65) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 3: To: (37) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 4: Contact: (39) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 7: User-Agent: Asterisk (27) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 9: Remote-Party-ID: "2222" ;privacy=off;screen=no (89) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 10: Date: Tue, 05 Dec 2006 20:45:15 GMT (35) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 12: Supported: replaces (19) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 13: X-Custom-Network: class4 (26) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 14: X-Custom-Test3: (24) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 16: Content-Length: 487 (19) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4525 parse_request: Header 17: (0) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: o=root 3026 3026 IN IP4 10.0.0.2 (38) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: s=session (9) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.0.0.2 (23) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: b=CT:384 (8) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: m=audio 13920 RTP/AVP 97 18 8 0 3 101 (37) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=fmtp:97 mode=30 (17) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: m=video 19388 RTP/AVP 34 103 (28) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:4557 parse_request: Line: a=sendrecv (10) [Dec 5 22:45:15] 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=z9hG4bK7e37ba42;rport From: "2222" ;tag=as40b41896 To: Contact: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "2222" ;privacy=off;screen=no Date: Tue, 05 Dec 2006 20:45:15 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-Custom-Network: class4 X-Custom-Test3: Content-Type: application/sdp Content-Length: 487 v=0 o=root 3026 3026 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 b=CT:384 t=0 0 m=audio 13920 RTP/AVP 97 18 8 0 3 101 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 19388 RTP/AVP 34 103 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=sendrecv --- [Dec 5 22:45:15] DEBUG[19205]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12 [Dec 5 22:45:15] -- Called 1234@ser [Dec 5 22:45:15] DEBUG[19205]: channel.c:2731 set_format: Set channel SIP/ser-093c2768 to read format slin [Dec 5 22:45:15] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld CSeq: 102 INVITE Server: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: (37) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: OpenSER (1.1.0-notls (i386/linux)) (50) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: (0) [Dec 5 22:45:15] --- (8 headers 0 lines) --- [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2104 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #12 - INVITE (got response) [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' Request 102: Found [Dec 5 22:45:15] DEBUG[15126]: chan_sip.c:11528 handle_response_invite: SIP response 100 to standard invite [Dec 5 22:45:15] DEBUG[19205]: channel.c:2731 set_format: Set channel SIP/mydomain.tld-0942b910 to write format slin [Dec 5 22:45:15] DEBUG[19205]: channel.c:2731 set_format: Set channel SIP/mydomain.tld-0942b910 to read format slin [Dec 5 22:45:15] DEBUG[19205]: channel.c:2731 set_format: Set channel SIP/ser-093c2768 to write format slin ovz*CLI> ovz*CLI> ovz*CLI> ovz*CLI> [Dec 5 22:45:21] <--- 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=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Date: Tue, 05 Dec 2006 20:45:15 GMT Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@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 8516 5084 IN IP4 10.3.0.1 s=SIP Call c=IN IP4 10.3.0.1 t=0 0 m=audio 18702 RTP/AVP 18 101 c=IN IP4 10.3.0.1 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=silenceSupp:off - - - - m=video 0 RTP/AVP 34 c=IN IP4 10.3.0.1 <-------------> [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=1D8D5AC8-260C (55) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Date: Tue, 05 Dec 2006 20:45:15 GMT (35) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER (104) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: Allow-Events: telephone-event (29) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: Contact: (46) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 11: Record-Route: (56) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 14: Content-Length: 346 (19) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 15: (0) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: v=0 (3) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 8516 5084 IN IP4 10.3.0.1 (61) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: s=SIP Call (10) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: t=0 0 (5) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: m=audio 18702 RTP/AVP 18 101 (28) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=ptime:20 (10) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: m=video 0 RTP/AVP 34 (20) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4557 parse_request: Line: c=IN IP4 10.3.0.1 (22) [Dec 5 22:45:21] --- (15 headers 15 lines) --- [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:2113 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' Request 102: Found [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:11528 handle_response_invite: SIP response 183 to standard invite [Dec 5 22:45:21] Found RTP audio format 18 [Dec 5 22:45:21] Found RTP audio format 101 [Dec 5 22:45:21] Found RTP video format 34 [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:4836 process_sdp: Peer doesn't provide T.38 UDPTL [Dec 5 22:45:21] Peer audio RTP is at port 10.3.0.1:18702 [Dec 5 22:45:21] Found description format G729 for ID 18 [Dec 5 22:45:21] Got unsupported a:fmtp in SDP offer [Dec 5 22:45:21] Found description format telephone-event for ID 101 [Dec 5 22:45:21] Got unsupported a:fmtp in SDP offer [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:5066 process_sdp: T38 state changed to 0 on channel SIP/ser-093c2768 [Dec 5 22:45:21] Capabilities: us - 0x18050e (gsm|ulaw|alaw|g729|ilbc|h263|h263p), peer - audio=0x80100 (g729|h263)/video=0x80000 (h263), combined - 0x80100 (g729|h263) [Dec 5 22:45:21] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 5 22:45:21] Peer audio RTP is at port 10.3.0.1:18702 [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:5143 process_sdp: We're settling with these formats: 0x80100 (g729|h263) [Dec 5 22:45:21] DEBUG[15126]: chan_sip.c:5150 process_sdp: We have an owner, now see if we need to change this call [Dec 5 22:45:21] -- SIP/ser-093c2768 is making progress passing it to SIP/mydomain.tld-0942b910 [Dec 5 22:45:21] DEBUG[19205]: chan_sip.c:6351 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 5 22:45:21] DEBUG[19205]: chan_sip.c:6119 add_sdp: ** Our capability: 0x400 (ilbc) Video flag: True [Dec 5 22:45:21] DEBUG[19205]: chan_sip.c:6120 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 5 22:45:21] Audio is at 10.0.0.2 port 19002 [Dec 5 22:45:21] Adding codec 0x400 (ilbc) to SDP [Dec 5 22:45:21] Adding non-codec 0x1 (telephone-event) to SDP [Dec 5 22:45:21] DEBUG[19205]: chan_sip.c:6251 add_sdp: -- Done with adding codecs to SDP [Dec 5 22:45:21] DEBUG[19205]: chan_sip.c:6296 add_sdp: Done building SDP. Settling with this capability: 0x400 (ilbc) [Dec 5 22:45:21] <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 From: ;tag=ee6b6e5b To: "1234";tag=as6a3c9eb8 Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 263 v=0 o=root 3026 3026 IN IP4 10.0.0.2 s=session c=IN IP4 10.0.0.2 t=0 0 m=audio 19002 RTP/AVP 98 101 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 a=sendrecv <------------> [Dec 5 22:45:21] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 132 bytes [Dec 5 22:45:21] DEBUG[19205]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to g729 [Dec 5 22:45:21] DEBUG[19205]: rtp.c:2638 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Dec 5 22:45:21] DEBUG[19205]: rtp.c:2621 ast_rtp_write: Ooh, format changed from unknown to ilbc [Dec 5 22:45:21] DEBUG[19205]: rtp.c:2638 ast_rtp_write: Created smoother: format: 1024 ms: 30 len: 50 [Dec 5 22:45:23] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 88 bytes [Dec 5 22:45:25] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 176 bytes ovz*CLI> [Dec 5 22:45:26] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 88 bytes ovz*CLI> ovz*CLI> [Dec 5 22:45:27] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 44 bytes [Dec 5 22:45:27] DEBUG[19205]: rtp.c:961 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 10.2.0.1:52155 [Dec 5 22:45:28] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 176 bytes [Dec 5 22:45:31] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 176 bytes [Dec 5 22:45:33] DEBUG[19205]: rtp.c:866 ast_rtcp_read: Got RTCP report of 160 bytes [Dec 5 22:45:33] <--- SIP read from 10.0.0.1:5060 ---> CANCEL sip:1234@10.0.0.2 SIP/2.0 Max-Forwards: 10 Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 To: "1234" From: ;tag=ee6b6e5b Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 CANCEL Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="4575db87d888a00b88f9ba26035e5b84b6898602",uri="sip:1234@mydomain.tld",response="9708fc1e07ca162c834bb8fd3aee13f6",algorithm=MD5 User-Agent: eyeBeam release 1003s stamp 31159 Content-Length: 0 <-------------> [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: CANCEL sip:1234@10.0.0.2 SIP/2.0 (38) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Max-Forwards: 10 (16) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0 (61) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 (99) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: To: "1234" (43) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: From: ;tag=ee6b6e5b (57) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. (69) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 2 CANCEL (14) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Proxy-Authorization: Digest username="2222",realm="mydomain.tld",nonce="4575db87d888a00b88f9ba26035e5b84b6898602",uri="sip:1234@mydomain.tld",response="9708fc1e07ca162c834bb8fd3aee13f6",algorithm=MD5 (224) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: User-Agent: eyeBeam release 1003s stamp 31159 (45) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: Content-Length: 0 (17) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 11: (0) [Dec 5 22:45:33] --- (11 headers 0 lines) --- [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:14440 handle_request: **** Received CANCEL (14) - Command in SIP CANCEL [Dec 5 22:45:33] Sending to 10.0.0.1 : 5060 (NAT) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:1615 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. [Dec 5 22:45:33] <--- Reliably Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 From: ;tag=ee6b6e5b To: "1234";tag=as6a3c9eb8 Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #16 [Dec 5 22:45:33] <--- Transmitting (NAT) to 10.0.0.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0;received=10.0.0.1 Via: SIP/2.0/UDP 10.2.0.1:44784;branch=z9hG4bK-d87543-9505332d2e31aa74-1--d87543-;rport=44784 From: ;tag=ee6b6e5b To: "1234";tag=as6a3c9eb8 Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. CSeq: 2 CANCEL User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 5 22:45:33] DEBUG[19205]: rtp.c:1477 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 5 22:45:33] DEBUG[19205]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/ser-093c2768' [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3278 sip_hangup: Hangup call SIP/ser-093c2768, SIP callid 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld) [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3286 sip_hangup: update_call_counter(1234) - decrement call limit counter on hangup [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3299 sip_hangup: Hanging up channel in state Down (not UP) [Dec 5 22:45:33] Scheduling destruction of SIP dialog '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' in 32000 ms (Method: INVITE) [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:2053 __sip_ack: Acked pending invite 102 [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' of Request 102: Match Not Found [Dec 5 22:45:33] Reliably Transmitting (NAT) to 10.0.0.1:5060: CANCEL sip:1234@10.0.0.1 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport From: "2222" ;tag=as40b41896 To: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld CSeq: 102 CANCEL User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "2222" ;privacy=off;screen=no Content-Length: 0 --- [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 [Dec 5 22:45:33] Scheduling destruction of SIP dialog '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' in 32000 ms (Method: INVITE) [Dec 5 22:45:33] DEBUG[19205]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ser-093c2768 [Dec 5 22:45:33] DEBUG[19205]: app_dial.c:1640 dial_exec_full: Exiting with DIALSTATUS=CANCEL. [Dec 5 22:45:33] DEBUG[19205]: pbx.c:2363 __ast_pbx_run: Spawn extension (pre-process,1234,3) exited non-zero on 'SIP/mydomain.tld-0942b910' [Dec 5 22:45:33] == Spawn extension (pre-process, 1234, 3) exited non-zero on 'SIP/mydomain.tld-0942b910' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2222' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2222' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'pre-process' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/mydomain.tld-0942b910' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/ser-093c2768' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/1234@ser' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-05 22:45:15' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-12-05 22:45:33' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '18' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '0' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'NO ANSWER' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1165351515.2' [Dec 5 22:45:33] DEBUG[19205]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Dec 5 22:45:33] DEBUG[19205]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/mydomain.tld-0942b910' [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3278 sip_hangup: Hangup call SIP/mydomain.tld-0942b910, SIP callid 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE.) [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3286 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:2978 update_call_counter: Updating call counter for incoming call [Dec 5 22:45:33] DEBUG[19205]: chan_sip.c:3299 sip_hangup: Hanging up channel in state Ring (not UP) [Dec 5 22:45:33] DEBUG[19205]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/mydomain.tld-0942b910 [Dec 5 22:45:33] <--- 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=z9hG4bKad17.d369d905.0 From: ;tag=ee6b6e5b Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. To: "1234";tag=as6a3c9eb8 CSeq: 2 ACK User-Agent: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: ACK sip:1234@10.0.0.2 SIP/2.0 (35) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.1;branch=z9hG4bKad17.d369d905.0 (61) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: ;tag=ee6b6e5b (57) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: Call-ID: 7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE. (69) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: To: "1234";tag=as6a3c9eb8 (58) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: CSeq: 2 ACK (11) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: User-Agent: OpenSER (1.1.0-notls (i386/linux)) (54) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: (0) [Dec 5 22:45:33] --- (8 headers 0 lines) --- [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:14440 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #16 [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE.' of Response 2: Match Not Found [Dec 5 22:45:33] Really destroying SIP dialog '7266e9695279993eYjA4Y2Y4ZmYwNTEwNDQ5YzRmYzIzNzdhNzgxOWIyMmE.' Method: ACK [Dec 5 22:45:33] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 200 Canceling Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=b52076c0a0343c742375afff6878b100-6397 Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld CSeq: 102 CANCEL Server: OpenSER (1.1.0-notls (i386/linux)) Content-Length: 0 <-------------> [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 200 Canceling (21) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=b52076c0a0343c742375afff6878b100-6397 (79) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: CSeq: 102 CANCEL (16) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: OpenSER (1.1.0-notls (i386/linux)) (50) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: Content-Length: 0 (17) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: (0) [Dec 5 22:45:33] --- (8 headers 0 lines) --- [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18 [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' of Request 102: Match Not Found [Dec 5 22:45:33] DEBUG[15094]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ser [Dec 5 22:45:33] DEBUG[15094]: chan_sip.c:15035 sip_devicestate: Checking device state for peer ser [Dec 5 22:45:33] DEBUG[15094]: devicestate.c:287 do_state_change: Changing state for SIP/ser - state 1 (Not in use) [Dec 5 22:45:33] DEBUG[15094]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - mydomain.tld [Dec 5 22:45:33] DEBUG[15094]: chan_sip.c:15035 sip_devicestate: Checking device state for peer mydomain.tld [Dec 5 22:45:33] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Date: Tue, 05 Dec 2006 20:45:33 GMT Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 487 Request Cancelled (29) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=1D8D5AC8-260C (55) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Date: Tue, 05 Dec 2006 20:45:33 GMT (35) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Allow-Events: telephone-event (29) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 5 22:45:33] --- (10 headers 0 lines) --- [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' of Request 102: Match Found [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:2978 update_call_counter: Updating call counter for outgoing call [Dec 5 22:45:33] Transmitting (NAT) to 10.0.0.1:5060: ACK sip:1234@10.0.0.1 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Contact: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Remote-Party-ID: "2222" ;privacy=off;screen=no Content-Length: 0 --- [Dec 5 22:45:33] DEBUG[15126]: chan_sip.c:1615 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld [Dec 5 22:45:33] Really destroying SIP dialog '0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld' Method: INVITE [Dec 5 22:45:33] DEBUG[19208]: app_queue.c:546 changethread: Device 'SIP/ser' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 5 22:45:33] DEBUG[15094]: devicestate.c:287 do_state_change: Changing state for SIP/mydomain.tld - state 4 (Invalid) [Dec 5 22:45:33] DEBUG[19209]: app_queue.c:546 changethread: Device 'SIP/mydomain.tld' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Dec 5 22:45:34] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Date: Tue, 05 Dec 2006 20:45:33 GMT Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 487 Request Cancelled (29) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=1D8D5AC8-260C (55) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Date: Tue, 05 Dec 2006 20:45:33 GMT (35) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Allow-Events: telephone-event (29) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 5 22:45:34] --- (10 headers 0 lines) --- [Dec 5 22:45:34] DEBUG[15126]: chan_sip.c:14618 sipsock_read: Invalid SIP message - rejected , no callid, len 441 [Dec 5 22:45:36] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Date: Tue, 05 Dec 2006 20:45:33 GMT Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 487 Request Cancelled (29) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=1D8D5AC8-260C (55) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Date: Tue, 05 Dec 2006 20:45:33 GMT (35) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Allow-Events: telephone-event (29) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 5 22:45:36] --- (10 headers 0 lines) --- [Dec 5 22:45:36] DEBUG[15126]: chan_sip.c:14618 sipsock_read: Invalid SIP message - rejected , no callid, len 441 [Dec 5 22:45:40] <--- SIP read from 10.0.0.1:5060 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 From: "2222" ;tag=as40b41896 To: ;tag=1D8D5AC8-260C Date: Tue, 05 Dec 2006 20:45:33 GMT Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 0: SIP/2.0 487 Request Cancelled (29) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 1: Via: SIP/2.0/UDP 10.0.0.2:5060;branch=z9hG4bK7e37ba42;rport=5060 (70) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 2: From: "2222" ;tag=as40b41896 (71) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 3: To: ;tag=1D8D5AC8-260C (55) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 4: Date: Tue, 05 Dec 2006 20:45:33 GMT (35) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 5: Call-ID: 0d3074797b28dd3e1d283f3d7ad9cebe@mydomain.tld (64) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 8: Allow-Events: telephone-event (29) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 9: Content-Length: 0 (17) [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:4525 parse_request: Header 10: (0) [Dec 5 22:45:40] --- (10 headers 0 lines) --- [Dec 5 22:45:40] DEBUG[15126]: chan_sip.c:14618 sipsock_read: Invalid SIP message - rejected , no callid, len 441 ovz*CLI>