*CLI> set verbose 4 Verbosity is at least 4 *CLI> set debug 4 Core debug is at least 4 *CLI> sip debug SIP Debugging re-enabled *CLI> Jun 29 14:46:04 DEBUG[9062]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Zap/1-1 -- Accepting call from '07803034440' to '444607' on channel 0/1, span 1 Jun 29 14:46:04 DEBUG[9062]: chan_zap.c:1383 zt_enable_ec: Enabled echo cancellation on channel 1 Jun 29 14:46:04 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for Zap - 1 Jun 29 14:46:04 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for Zap/1 - state 2 (In use) Jun 29 14:46:04 DEBUG[9248]: pbx.c:1675 pbx_extension_helper: Launching 'Goto' -- Executing [444607@isdn10:1] Goto("Zap/1-1", "common|7707|1") in new stack -- Goto (common,7707,1) Jun 29 14:46:04 DEBUG[9248]: pbx.c:1675 pbx_extension_helper: Launching 'Answer' -- Executing [7707@common:1] Answer("Zap/1-1", "") in new stack Jun 29 14:46:04 DEBUG[9248]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Zap/1-1 Jun 29 14:46:04 DEBUG[9248]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [7707@common:2] Dial("Zap/1-1", "SIP/7707") in new stack Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:14611 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4107 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:2504 create_addr_from_peer: Setting NAT on RTP to Off Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3602 sip_new: *** Our native formats are 0x4 (ulaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3603 sip_new: *** Joint capabilities are 0x0 (nothing) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3604 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3605 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3607 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:3628 sip_new: This channel will not be able to handle video. Jun 29 14:46:04 DEBUG[9248]: rtp.c:1388 ast_rtp_make_compatible: Channel 'Zap/1-1' has no RTP, not doing anything Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable STACK-common-7707-2. Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable STACK-common-7707-1. Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable STACK-isdn10-444607-1. Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable CALLEDTON. Jun 29 14:46:04 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for Zap - 1 Jun 29 14:46:04 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for Zap/1 - state 2 (In use) Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable ANI2. Jun 29 14:46:04 DEBUG[9248]: channel.c:2929 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY. Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:2706 sip_call: Outgoing Call for 7707 Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:2714 sip_call: Our T38 capability (0), joint T38 capability (0) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 192.168.6.6 port 19538 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7707@192.168.6.215:5060 SIP/2.0 (42) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport (62) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 2: From: "07803034440" ;tag=as5fda500b (64) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 3: To: (33) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 4: Contact: (38) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 5: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 8: Max-Forwards: 70 (16) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 9: Date: Thu, 29 Jun 2006 13:46:04 GMT (35) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 11: Supported: replaces (19) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 12: Content-Type: application/sdp (29) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 13: Content-Length: 271 (19) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4327 parse_request: Header 14: (0) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: o=root 9049 9049 IN IP4 192.168.6.6 (35) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: s=session (9) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.6 (20) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: m=audio 19538 RTP/AVP 8 0 3 101 (31) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-16 (15) Jun 29 14:46:04 DEBUG[9249]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 29 14:46:04 DEBUG[9250]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=silenceSupp:off - - - - (25) Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:4359 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.6.215:5060: INVITE sip:7707@192.168.6.215:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport From: "07803034440" ;tag=as5fda500b To: Contact: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 29 Jun 2006 13:46:04 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 271 v=0 o=root 9049 9049 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 19538 RTP/AVP 8 0 3 101 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=sendrecv --- Jun 29 14:46:04 DEBUG[9248]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #118 -- Called 7707 Jun 29 14:46:04 DEBUG[9248]: channel.c:2484 set_format: Set channel SIP/7707-08409040 to read format alaw Jun 29 14:46:04 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to write format alaw Jun 29 14:46:04 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to read format ulaw Jun 29 14:46:04 DEBUG[9248]: channel.c:2484 set_format: Set channel SIP/7707-08409040 to write format ulaw <-- SIP read from 192.168.6.215:53047: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport From: "07803034440" ;tag=as5fda500b To: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:04 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 100 Trying (18) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport (62) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "07803034440" ;tag=as5fda500b (64) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: (33) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:04 GMT (35) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:2033 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #118 - INVITE (got response) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:2042 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7831f2f003dfeb3361f7d87229ec124e@192.168.6.6' Request 102: Found Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 192.168.6.215:53048: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport From: "07803034440" ;tag=as5fda500b To: ;tag=000ccebdcfc60008195dfdfd-10866f77 Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:04 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport (62) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "07803034440" ;tag=as5fda500b (64) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=000ccebdcfc60008195dfdfd-10866f77 (71) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:04 GMT (35) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:2042 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7831f2f003dfeb3361f7d87229ec124e@192.168.6.6' Request 102: Found Jun 29 14:46:04 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 180 to standard invite Jun 29 14:46:04 DEBUG[9065]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-08409040 -- SIP/7707-08409040 is ringing Jun 29 14:46:04 DEBUG[9248]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 29 14:46:04 DEBUG[9248]: chan_zap.c:4867 zt_indicate: Requested indication 3 on channel Zap/1-1 Jun 29 14:46:04 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:46:04 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:46:04 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:46:04 DEBUG[9251]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. <-- SIP read from 192.168.6.215:53049: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport From: "07803034440" ;tag=as5fda500b To: ;tag=000ccebdcfc60008195dfdfd-10866f77 Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:07 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=Cisco-SIPUA 18490 4815 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 192.168.6.215 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5ef932c8;rport (62) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "07803034440" ;tag=as5fda500b (64) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=000ccebdcfc60008195dfdfd-10866f77 (71) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:07 GMT (35) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 198 (19) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: (0) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 18490 4815 IN IP4 192.168.6.215 (45) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.215 (22) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines)--- Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:1982 __sip_ack: Acked pending invite 102 Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '7831f2f003dfeb3361f7d87229ec124e@192.168.6.6' of Request 102: Match Not Found Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.215:25312 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel SIP/7707-08409040 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.6.215:25312 Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:4912 process_sdp: We have an owner, now see if we need to change this call Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:7591 build_route: build_route: Contact hop: list_route: hop: Jun 29 14:46:07 DEBUG[9065]: chan_sip.c:5340 reqprep: Strict routing enforced for session 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.215, port 5060 Transmitting (no NAT) to 192.168.6.215:5060: ACK sip:7707@192.168.6.215:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK3b788959;rport From: "07803034440" ;tag=as5fda500b To: ;tag=000ccebdcfc60008195dfdfd-10866f77 Contact: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 29 14:46:07 DEBUG[9248]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-08409040 -- SIP/7707-08409040 answered Zap/1-1 Jun 29 14:46:07 DEBUG[9248]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 29 14:46:07 DEBUG[9248]: chan_zap.c:4867 zt_indicate: Requested indication -1 on channel Zap/1-1 Jun 29 14:46:07 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to read format ulaw Jun 29 14:46:07 DEBUG[9248]: channel.c:2484 set_format: Set channel SIP/7707-08409040 to write format ulaw Jun 29 14:46:07 DEBUG[9248]: channel.c:2484 set_format: Set channel SIP/7707-08409040 to read format alaw Jun 29 14:46:07 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to write format alaw Jun 29 14:46:07 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:46:07 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:46:07 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:46:07 DEBUG[9252]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:46:07 DEBUG[9248]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.6.99:50300: REGISTER sip:192.168.6.9 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK4814a146 From: sip:6086@192.168.6.9 To: sip:6086@192.168.6.9 Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 Date: Thu, 29 Jun 2006 13:46:11 GMT CSeq: 156 REGISTER User-Agent: CSCO/7 Contact: Content-Length: 0 Expires: 3600 Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: REGISTER sip:192.168.6.9 SIP/2.0 (32) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK4814a146 (57) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: sip:6086@192.168.6.9 (26) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: sip:6086@192.168.6.9 (24) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 (57) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:11 GMT (35) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 156 REGISTER (18) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (37) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Expires: 3600 (13) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:4107 sip_alloc: Allocating new SIP dialog for 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 - REGISTER (No RTP) Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.6.99 : 5060 (no NAT) Transmitting (no NAT) to 192.168.6.99:5060: SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK4814a146;received=192.168.6.99 From: sip:6086@192.168.6.9 To: sip:6086@192.168.6.9;tag=as49a46bb3 Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 CSeq: 156 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 29 14:46:11 DEBUG[9065]: chan_sip.c:7988 register_verify: SIP REGISTER attempt failed for (null) : Peer not found Jun 29 14:46:11 NOTICE[9065]: chan_sip.c:13883 handle_request_register: Registration from 'sip:6086@192.168.6.9' failed for '192.168.6.99' - No matching peer found Scheduling destruction of SIP dialog '0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99' in 15000 ms (Method: REGISTER) <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.215 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:25312 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel SIP/7707-08409040 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 0.0.0.0:25312 Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:4912 process_sdp: We have an owner, now see if we need to change this call -- Started music on hold, class 'default', on Zap/1-1 Jun 29 14:46:14 DEBUG[9065]: channel.c:1785 ast_settimeout: Scheduling timer at 160 sample intervals Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:12851 handle_request_invite: Got a SIP re-invite for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:14 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... Jun 29 14:46:14 DEBUG[9248]: channel.c:2065 __ast_read: Generator got voice, switching to phase locked mode Jun 29 14:46:14 DEBUG[9248]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:46:14 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to write format ulaw Jun 29 14:46:14 DEBUG[9248]: res_musiconhold.c:248 ast_moh_files_next: Zap/1-1 Opened file 11 '/var/lib/asterisk/sounds/custom/moh/track20' <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:15 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... <-- SIP read from 192.168.6.215:53050: INVITE sip:7747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5ce580fb From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:16 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Expires: 180 Content-Type: application/sdp Content-Length: 248 Accept: application/sdp Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 7053 11360 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 192.168.6.215 t=0 0 m=audio 25314 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7747@192.168.6.6 SIP/2.0 (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5ce580fb (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: (26) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Expires: 180 (12) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Type: application/sdp (29) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Content-Length: 248 (19) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: Accept: application/sdp (23) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 13: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 14: (0) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 7053 11360 IN IP4 192.168.6.215 (45) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.215 (22) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25314 RTP/AVP 0 8 18 101 (32) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (14 headers 11 lines)--- Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4107 sip_alloc: Allocating new SIP dialog for 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 - INVITE (With RTP) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.215 : 5060 (no NAT) Using INVITE request as basis request - 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:8628 check_user_full: Setting NAT on RTP to Off Reliably Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5ce580fb;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as1a3c0321 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="5497d7de" Content-Length: 0 --- Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #122 Scheduling destruction of SIP dialog '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' in 32000 ms (Method: INVITE) Found user '7707' <-- SIP read from 192.168.6.215:53051: ACK sip:7747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5ce580fb From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as1a3c0321 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:16 GMT CSeq: 101 ACK Content-Length: 0 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: ACK sip:7747@192.168.6.6 SIP/2.0 (32) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5ce580fb (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as1a3c0321 (41) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 ACK (13) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Content-Length: 0 (17) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:1990 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #122 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' of Response 101: Match Not Found <-- SIP read from 192.168.6.215:53052: INVITE sip:7747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK3edda7e5 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:16 GMT CSeq: 102 INVITE User-Agent: CSCO/7 Contact: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 Expires: 180 Content-Type: application/sdp Content-Length: 248 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 7053 11360 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 192.168.6.215 t=0 0 m=audio 25314 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7747@192.168.6.6 SIP/2.0 (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK3edda7e5 (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: (26) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Expires: 180 (12) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Content-Type: application/sdp (29) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: Content-Length: 248 (19) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 13: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 14: (0) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 7053 11360 IN IP4 192.168.6.215 (45) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.215 (22) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25314 RTP/AVP 0 8 18 101 (32) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (14 headers 11 lines)--- Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.215 : 5060 (no NAT) Using INVITE request as basis request - 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:8628 check_user_full: Setting NAT on RTP to Off Found user '7707' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.215:25314 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.6.215:25314 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:12803 handle_request_invite: Checking SIP call limits for device 7707 Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:2867 update_call_counter: Updating call counter for incoming call Looking for 7747 in from-sip (domain 192.168.6.6) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:3602 sip_new: *** Our native formats are 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:3603 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:3604 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:3605 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:3628 sip_new: This channel will not be able to handle video. Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:7591 build_route: build_route: Contact hop: list_route: hop: Jun 29 14:46:16 DEBUG[9065]: chan_sip.c:12873 handle_request_invite: SIP/7707-083fd250: New call is still down.... Trying... Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK3edda7e5;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 29 14:46:16 DEBUG[9065]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-083fd250 Jun 29 14:46:16 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:46:16 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:46:16 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:46:16 DEBUG[9253]: pbx.c:1675 pbx_extension_helper: Launching 'Answer' -- Executing [7747@from-sip:1] Answer("SIP/7707-083fd250", "") in new stack Jun 29 14:46:16 DEBUG[9253]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-083fd250 Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3308 sip_answer: SIP answering channel: SIP/7707-083fd250 Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 16766 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK3edda7e5;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 271 v=0 o=root 9049 9049 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 16766 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #124 Jun 29 14:46:16 DEBUG[9253]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [7747@from-sip:2] Dial("SIP/7707-083fd250", "SIP/7747") in new stack Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:14611 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4107 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:2504 create_addr_from_peer: Setting NAT on RTP to Off Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3602 sip_new: *** Our native formats are 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3603 sip_new: *** Joint capabilities are 0x0 (nothing) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3604 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3605 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3607 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:3628 sip_new: This channel will not be able to handle video. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable STACK-from-sip-7747-2. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable STACK-from-sip-7747-1. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jun 29 14:46:16 DEBUG[9253]: channel.c:2929 ast_channel_inherit_variables: Not copying variable SIPURI. Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:2706 sip_call: Outgoing Call for 7747 Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:2714 sip_call: Our T38 capability (0), joint T38 capability (0) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 192.168.6.6 port 12060 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7747@192.168.6.159:5060 SIP/2.0 (42) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport (62) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 2: From: "Test 707" ;tag=as590170ab (54) Jun 29 14:46:16 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:46:16 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:46:16 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 3: To: (33) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 4: Contact: (31) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 5: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 (53) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 8: Max-Forwards: 70 (16) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 9: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 11: Supported: replaces (19) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 12: Content-Type: application/sdp (29) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 13: Content-Length: 271 (19) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4327 parse_request: Header 14: (0) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: o=root 9049 9049 IN IP4 192.168.6.6 (35) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: s=session (9) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.6 (20) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: m=audio 12060 RTP/AVP 0 8 3 101 (31) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-16 (15) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=silenceSupp:off - - - - (25) Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:4359 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.6.159:5060: INVITE sip:7747@192.168.6.159:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport From: "Test 707" ;tag=as590170ab To: Contact: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 29 Jun 2006 13:46:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 271 v=0 o=root 9049 9049 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 12060 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 29 14:46:16 DEBUG[9253]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #125 -- Called 7747 Jun 29 14:46:16 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to read format ulaw Jun 29 14:46:16 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to write format ulaw Jun 29 14:46:16 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to read format ulaw Jun 29 14:46:16 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to write format ulaw Jun 29 14:46:16 DEBUG[9254]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:46:16 DEBUG[9255]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:46:17 DEBUG[9253]: rtp.c:641 process_rfc2833: - RTP 2833 Event: 00000007 (len = 4) Jun 29 14:46:17 DEBUG[9253]: rtp.c:641 process_rfc2833: - RTP 2833 Event: 00000007 (len = 4) Jun 29 14:46:17 DEBUG[9253]: rtp.c:641 process_rfc2833: - RTP 2833 Event: 00000007 (len = 4) <-- SIP read from 192.168.6.215:53053: ACK sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK37fed0ec From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:17 GMT CSeq: 102 ACK User-Agent: CSCO/7 Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 Content-Length: 0 Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: ACK sip:7747@192.168.6.6:5060 SIP/2.0 (37) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK37fed0ec (58) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:17 GMT (35) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 ACK (13) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:1990 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #124 Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' of Response 102: Match Not Found <-- SIP read from 192.168.6.159:51016: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport From: "Test 707" ;tag=as590170ab To: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:16 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 100 Trying (18) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport (62) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "Test 707" ;tag=as590170ab (54) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: (33) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 (53) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:2033 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #125 - INVITE (got response) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:2042 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6' Request 102: Found Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 192.168.6.159:51017: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport From: "Test 707" ;tag=as590170ab To: ;tag=00059bf197bc005f248912cd-2ed9a286 Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:16 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport (62) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "Test 707" ;tag=as590170ab (54) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=00059bf197bc005f248912cd-2ed9a286 (71) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 (53) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:16 GMT (35) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:2042 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6' Request 102: Found Jun 29 14:46:17 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 180 to standard invite Jun 29 14:46:17 DEBUG[9065]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7747-08401fb8 -- SIP/7747-08401fb8 is ringing Jun 29 14:46:17 DEBUG[9253]: channel.c:2164 ast_indicate_data: Driver for channel 'SIP/7707-083fd250' does not support indication 3, emulating it Jun 29 14:46:17 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to write format slin Jun 29 14:46:17 DEBUG[9253]: channel.c:1785 ast_settimeout: Scheduling timer at 160 sample intervals Jun 29 14:46:17 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7747 Jun 29 14:46:17 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7747 Jun 29 14:46:17 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7747 - state 1 (Not in use) Jun 29 14:46:17 DEBUG[9256]: app_queue.c:529 changethread: Device 'SIP/7747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:46:17 DEBUG[9253]: channel.c:2065 __ast_read: Generator got voice, switching to phase locked mode Jun 29 14:46:17 DEBUG[9253]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:46:17 DEBUG[9253]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw RTCP SR transmission error, rtcp halted Interrupted system call Jun 29 14:46:17 NOTICE[9065]: sched.c:287 ast_sched_del: Attempted to delete nonexistent schedule entry 120! <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:18 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... <-- SIP read from 192.168.6.159:51018: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport From: "Test 707" ;tag=as590170ab To: ;tag=00059bf197bc005f248912cd-2ed9a286 Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:21 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 199 v=0 o=Cisco-SIPUA 18316 28212 IN IP4 192.168.6.159 s=SIP Call c=IN IP4 192.168.6.159 t=0 0 m=audio 21478 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK5fe3eda6;rport (62) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "Test 707" ;tag=as590170ab (54) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=00059bf197bc005f248912cd-2ed9a286 (71) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 (53) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:21 GMT (35) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 199 (19) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: (0) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 18316 28212 IN IP4 192.168.6.159 (46) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.159 (22) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 21478 RTP/AVP 0 101 (27) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines)--- Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:1982 __sip_ack: Acked pending invite 102 Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6' of Request 102: Match Not Found Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:11160 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.159:21478 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel SIP/7747-08401fb8 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.6.159:21478 Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:4912 process_sdp: We have an owner, now see if we need to change this call Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:7591 build_route: build_route: Contact hop: list_route: hop: Jun 29 14:46:21 DEBUG[9065]: chan_sip.c:5340 reqprep: Strict routing enforced for session 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.159, port 5060 Transmitting (no NAT) to 192.168.6.159:5060: ACK sip:7747@192.168.6.159:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK325d5c8a;rport From: "Test 707" ;tag=as590170ab To: ;tag=00059bf197bc005f248912cd-2ed9a286 Contact: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 29 14:46:21 DEBUG[9253]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7747-08401fb8 -- SIP/7747-08401fb8 answered SIP/7707-083fd250 Jun 29 14:46:21 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to write format ulaw Jun 29 14:46:21 DEBUG[9253]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:46:21 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to read format ulaw Jun 29 14:46:21 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to write format ulaw Jun 29 14:46:21 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to read format ulaw Jun 29 14:46:21 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7707-083fd250 to write format ulaw Jun 29 14:46:21 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7747 Jun 29 14:46:21 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7747 Jun 29 14:46:21 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7747 - state 1 (Not in use) Jun 29 14:46:21 DEBUG[9257]: app_queue.c:529 changethread: Device 'SIP/7747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:46:21 DEBUG[9253]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:22 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... <-- SIP read from 192.168.6.215:53027: INVITE sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK66e007af From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:24 GMT CSeq: 103 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 242 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 v=0 o=Cisco-SIPUA 5408 20628 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25314 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7747@192.168.6.6:5060 SIP/2.0 (40) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK66e007af (58) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:24 GMT (35) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 103 INVITE (16) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 242 (19) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 13: (0) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 5408 20628 IN IP4 192.168.6.215 (45) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25314 RTP/AVP 0 8 18 101 (32) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (13 headers 11 lines)--- Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.215 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:25314 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel SIP/7707-083fd250 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 0.0.0.0:25314 Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4912 process_sdp: We have an owner, now see if we need to change this call -- Started music on hold, class 'default', on SIP/7747-08401fb8 Jun 29 14:46:25 DEBUG[9065]: channel.c:1785 ast_settimeout: Scheduling timer at 160 sample intervals Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:12851 handle_request_invite: Got a SIP re-invite for call 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-083fd250: New call is UP.... Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 16766 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK66e007af;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 271 v=0 o=root 9049 9050 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 16766 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #129 Jun 29 14:46:25 DEBUG[9253]: channel.c:2065 __ast_read: Generator got voice, switching to phase locked mode Jun 29 14:46:25 DEBUG[9253]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:46:25 DEBUG[9253]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to write format ulaw Jun 29 14:46:25 DEBUG[9253]: res_musiconhold.c:248 ast_moh_files_next: SIP/7747-08401fb8 Opened file 14 '/var/lib/asterisk/sounds/custom/moh/track10' Jun 29 14:46:25 DEBUG[9253]: rtp.c:2240 ast_rtp_raw_write: Difference is 744, ms is 113 <-- SIP read from 192.168.6.215:53027: ACK sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK68978f0d From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:25 GMT CSeq: 103 ACK User-Agent: CSCO/7 Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 Content-Length: 0 Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: ACK sip:7747@192.168.6.6:5060 SIP/2.0 (37) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK68978f0d (58) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:25 GMT (35) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 103 ACK (13) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:1990 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #129 Jun 29 14:46:25 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' of Response 103: Match Not Found <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:1929 __sip_autodestruct: Auto destroying call '0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99' Jun 29 14:46:26 DEBUG[9065]: chan_sip.c:2973 sip_destroy: Destroying SIP dialog 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 Really destroying SIP dialog '0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99' Method: REGISTER RTCP SR transmission error, rtcp halted No such file or directory Jun 29 14:46:27 NOTICE[9065]: sched.c:287 ast_sched_del: Attempted to delete nonexistent schedule entry 127! <-- SIP read from 192.168.6.215:53027: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 From: ;tag=000ccebdcfc60008195dfdfd-10866f77 To: "07803034440" ;tag=as5fda500b Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:14 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 192 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 25312 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6:5060 SIP/2.0 (47) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK44e8f5b3 (58) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: ;tag=000ccebdcfc60008195dfdfd-10866f77 (73) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: "07803034440" ;tag=as5fda500b (62) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 (53) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:14 GMT (35) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 192 (19) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: (0) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 4316 12517 IN IP4 192.168.6.215 (45) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25312 RTP/AVP 0 101 (27) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:14005 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:12853 handle_request_invite: Got a SIP re-transmit of INVITE for call 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6 Jun 29 14:46:30 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-08409040: New call is UP.... <-- SIP read from 192.168.6.215:53027: INVITE sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK4dbe1ba2 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:35 GMT CSeq: 104 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 248 Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 v=0 o=Cisco-SIPUA 13357 8932 IN IP4 192.168.6.215 s=SIP Call c=IN IP4 192.168.6.215 t=0 0 m=audio 25314 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: INVITE sip:7747@192.168.6.6:5060 SIP/2.0 (40) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK4dbe1ba2 (58) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:35 GMT (35) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 104 INVITE (16) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (38) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Type: application/sdp (29) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Content-Length: 248 (19) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: Remote-Party-ID: "7707" ;party=calling;id-type=subscriber;privacy=off;screen=no (103) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 12: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 13: (0) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: v=0 (3) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: o=Cisco-SIPUA 13357 8932 IN IP4 192.168.6.215 (45) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: s=SIP Call (10) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: c=IN IP4 192.168.6.215 (22) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: t=0 0 (5) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: m=audio 25314 RTP/AVP 0 8 18 101 (32) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4359 parse_request: Line: a=fmtp:101 0-15 (15) --- (13 headers 11 lines)--- Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.215 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.215:25314 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4835 process_sdp: T38 state changed to 0 on channel SIP/7707-083fd250 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.6.215:25314 Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4905 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4912 process_sdp: We have an owner, now see if we need to change this call -- Stopped music on hold on SIP/7747-08401fb8 Jun 29 14:46:35 DEBUG[9065]: channel.c:2484 set_format: Set channel SIP/7747-08401fb8 to write format ulaw Jun 29 14:46:35 DEBUG[9065]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:12851 handle_request_invite: Got a SIP re-invite for call 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:12940 handle_request_invite: SIP/7707-083fd250: New call is UP.... Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 16766 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK4dbe1ba2;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 271 v=0 o=root 9049 9051 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 16766 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #130 <-- SIP read from 192.168.6.215:53027: ACK sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK4a83e2b3 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:35 GMT CSeq: 104 ACK User-Agent: CSCO/7 Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 Content-Length: 0 Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: ACK sip:7747@192.168.6.6:5060 SIP/2.0 (37) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK4a83e2b3 (58) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:35 GMT (35) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 104 ACK (13) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="927fde92704573fa7dc55bc80d8a1771",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:1990 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #130 Jun 29 14:46:35 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' of Response 104: Match Not Found <-- SIP read from 192.168.6.215:53027: BYE sip:7747@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5614a84e From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 Date: Thu, 29 Jun 2006 13:46:40 GMT CSeq: 105 BYE User-Agent: CSCO/7 Content-Length: 0 Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="341e03a9152b08b745bd01d130ebacc3",nonce="5497d7de",algorithm=md5 Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: BYE sip:7747@192.168.6.6:5060 SIP/2.0 (37) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5614a84e (58) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 (73) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=as11a8e740 (41) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 (58) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:40 GMT (35) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 105 BYE (13) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Content-Length: 0 (17) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Proxy-Authorization: Digest username="7707",realm="asterisk",uri="sip:192.168.6.6",response="341e03a9152b08b745bd01d130ebacc3",nonce="5497d7de",algorithm=md5 (157) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.6.215 : 5060 (no NAT) Transmitting (no NAT) to 192.168.6.215:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.215:5060;branch=z9hG4bK5614a84e;received=192.168.6.215 From: "7707" ;tag=000ccebdcfc600093eeca59b-1d8eaae1 To: ;tag=as11a8e740 Call-ID: 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215 CSeq: 105 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 29 14:46:40 DEBUG[9253]: channel.c:3390 ast_generic_bridge: Didn't get a frame from channel: SIP/7707-083fd250 Jun 29 14:46:40 DEBUG[9253]: channel.c:3676 ast_channel_bridge: Bridge stops bridging channels SIP/7707-083fd250 and SIP/7747-08401fb8 Jun 29 14:46:40 DEBUG[9253]: channel.c:1485 ast_hangup: Hanging up channel 'SIP/7747-08401fb8' Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:3167 sip_hangup: Hangup call SIP/7747-08401fb8, SIP callid 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6) Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:3175 sip_hangup: update_call_counter(7747) - decrement call limit counter on hangup Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:5340 reqprep: Strict routing enforced for session 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.159, port 5060 Reliably Transmitting (no NAT) to 192.168.6.159:5060: BYE sip:7747@192.168.6.159:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2ff825cf;rport From: "Test 707" ;tag=as590170ab To: ;tag=00059bf197bc005f248912cd-2ed9a286 Contact: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:1897 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #132 Jun 29 14:46:40 DEBUG[9253]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7747-08401fb8 Jun 29 14:46:40 DEBUG[9253]: rtp.c:1321 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything Jun 29 14:46:40 DEBUG[9253]: app_dial.c:1621 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jun 29 14:46:40 DEBUG[9253]: pbx.c:2258 __ast_pbx_run: Spawn extension (from-sip,7747,2) exited non-zero on 'SIP/7707-083fd250' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1675 pbx_extension_helper: Launching 'NoOp' -- Executing [h@from-sip:1] NoOp("SIP/7707-083fd250", "Reached Hangup Extension") in new stack Jun 29 14:46:40 DEBUG[9253]: pbx.c:1675 pbx_extension_helper: Launching 'Hangup' -- Executing [h@from-sip:2] Hangup("SIP/7707-083fd250", "") in new stack Jun 29 14:46:40 DEBUG[9253]: pbx.c:2378 __ast_pbx_run: Spawn extension (from-sip,h,2) exited non-zero on 'SIP/7707-083fd250' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '"Test 707" <7707>' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '7707' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '7747' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'from-sip' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/7707-083fd250' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/7747-08401fb8' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Hangup' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:46:16' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:46:16' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:46:40' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '24' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '24' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1151588776.30' Jun 29 14:46:40 DEBUG[9253]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 29 14:46:40 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7747 Jun 29 14:46:40 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7747 Jun 29 14:46:40 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7747 - state 1 (Not in use) Jun 29 14:46:40 DEBUG[9258]: app_queue.c:529 changethread: Device 'SIP/7747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Warning: [DataDirect][ODBC Progress OpenEdge Wire Protocol driver]File not found 'IVPG.LIC'.[DataDirect][ODBC Progress OpenEdge Wire Protocol driver]You are not licensed to use this DataDirect Technologies ODBC Driver under the license you have purchased. If you wish to purchase a license for use with this application, then you may use this driver for a period of 15 days, during which time you are required to obtain a license. You can order a license for a DataDirect Technologies ODBC Driver for use with this application by calling DataDirect Technologies at 800-876-3101 in North America and +44 1727 812812 elsewhere. Thank you for your cooperation. Jun 29 14:46:40 DEBUG[9253]: channel.c:1485 ast_hangup: Hanging up channel 'SIP/7707-083fd250' Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:3167 sip_hangup: Hangup call SIP/7707-083fd250, SIP callid 000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215) Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:3175 sip_hangup: update_call_counter(7707) - decrement call limit counter on hangup Jun 29 14:46:40 DEBUG[9253]: chan_sip.c:2867 update_call_counter: Updating call counter for incoming call Jun 29 14:46:40 DEBUG[9253]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-083fd250 Jun 29 14:46:40 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:46:40 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:46:40 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:46:40 DEBUG[9259]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. <-- SIP read from 192.168.6.159:51019: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2ff825cf;rport From: "Test 707" ;tag=as590170ab To: ;tag=00059bf197bc005f248912cd-2ed9a286 Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 Date: Thu, 29 Jun 2006 13:46:40 GMT CSeq: 103 BYE Server: CSCO/7 Content-Length: 0 Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2ff825cf;rport (62) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: "Test 707" ;tag=as590170ab (54) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: ;tag=00059bf197bc005f248912cd-2ed9a286 (71) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6 (53) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:46:40 GMT (35) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 103 BYE (13) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: Server: CSCO/7 (14) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Content-Length: 0 (17) Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:1990 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #132 Jun 29 14:46:40 DEBUG[9065]: chan_sip.c:2000 __sip_ack: Stopping retransmission on '13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6' of Request 103: Match Not Found Really destroying SIP dialog '13c2b0cd4553ddb3553416ec1bdded17@192.168.6.6' Method: INVITE Really destroying SIP dialog '000ccebd-cfc60008-57cb4170-66ce0f95@192.168.6.215' Method: BYE -- Channel 0/1, span 1 got hangup request -- Stopped music on hold on Zap/1-1 Jun 29 14:47:07 DEBUG[9248]: channel.c:2484 set_format: Set channel Zap/1-1 to write format alaw Jun 29 14:47:07 DEBUG[9248]: channel.c:1785 ast_settimeout: Scheduling timer at 0 sample intervals Jun 29 14:47:07 DEBUG[9248]: channel.c:3390 ast_generic_bridge: Didn't get a frame from channel: Zap/1-1 Jun 29 14:47:07 DEBUG[9248]: channel.c:3676 ast_channel_bridge: Bridge stops bridging channels Zap/1-1 and SIP/7707-08409040 Jun 29 14:47:07 DEBUG[9248]: channel.c:1485 ast_hangup: Hanging up channel 'SIP/7707-08409040' Jun 29 14:47:07 DEBUG[9248]: chan_sip.c:3167 sip_hangup: Hangup call SIP/7707-08409040, SIP callid 7831f2f003dfeb3361f7d87229ec124e@192.168.6.6) Jun 29 14:47:07 DEBUG[9248]: chan_sip.c:3175 sip_hangup: update_call_counter(7707) - decrement call limit counter on hangup Jun 29 14:47:07 DEBUG[9248]: chan_sip.c:2867 update_call_counter: Updating call counter for outgoing call Jun 29 14:47:07 DEBUG[9248]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/7707-08409040 Jun 29 14:47:07 DEBUG[9248]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 29 14:47:07 DEBUG[9248]: app_dial.c:1621 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jun 29 14:47:07 DEBUG[9248]: pbx.c:2258 __ast_pbx_run: Spawn extension (common,7707,2) exited non-zero on 'Zap/1-1' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '07803034440' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '07803034440' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '7707' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'common' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Zap/1-1' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/7707-08409040' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Dial' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/7707' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:46:04' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:46:04' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-29 14:47:07' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '63' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '63' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1151588764.28' Jun 29 14:47:07 DEBUG[9248]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 29 14:47:07 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for SIP - 7707 Jun 29 14:47:07 DEBUG[9053]: chan_sip.c:14555 sip_devicestate: Checking device state for peer 7707 Jun 29 14:47:07 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for SIP/7707 - state 1 (Not in use) Jun 29 14:47:07 DEBUG[9260]: app_queue.c:529 changethread: Device 'SIP/7707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 14:47:07 DEBUG[9248]: channel.c:1485 ast_hangup: Hanging up channel 'Zap/1-1' Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2341 zt_hangup: zt_hangup(Zap/1-1) Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2883 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2374 zt_hangup: Hangup: channel: 1 index = 0, normal = 14, callwait = -1, thirdcall = -1 Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2522 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:1415 zt_disable_ec: disabled echo cancellation on channel 1 Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2800 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1 Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:1352 update_conf: Updated conferencing on 1, with 0 conference users Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:2879 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 Jun 29 14:47:07 DEBUG[9248]: chan_zap.c:1415 zt_disable_ec: disabled echo cancellation on channel 1 -- Hungup 'Zap/1-1' Jun 29 14:47:07 DEBUG[9248]: devicestate.c:301 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Zap/1-1 Jun 29 14:47:07 DEBUG[9053]: devicestate.c:159 ast_device_state: No provider found, checking channel drivers for Zap - 1 Jun 29 14:47:07 DEBUG[9053]: devicestate.c:285 do_state_change: Changing state for Zap/1 - state 0 (Unknown) Jun 29 14:47:07 DEBUG[9261]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Really destroying SIP dialog '7831f2f003dfeb3361f7d87229ec124e@192.168.6.6' Method: INVITE <-- SIP read from 192.168.6.99:50301: REGISTER sip:192.168.6.9 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK3f9924e6 From: sip:6086@192.168.6.9 To: sip:6086@192.168.6.9 Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 Date: Thu, 29 Jun 2006 13:47:11 GMT CSeq: 157 REGISTER User-Agent: CSCO/7 Contact: Content-Length: 0 Expires: 3600 Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 0: REGISTER sip:192.168.6.9 SIP/2.0 (32) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK3f9924e6 (57) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 2: From: sip:6086@192.168.6.9 (26) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 3: To: sip:6086@192.168.6.9 (24) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 4: Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 (57) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 5: Date: Thu, 29 Jun 2006 13:47:11 GMT (35) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 6: CSeq: 157 REGISTER (18) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 8: Contact: (37) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 9: Content-Length: 0 (17) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 10: Expires: 3600 (13) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4327 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:4107 sip_alloc: Allocating new SIP dialog for 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 - REGISTER (No RTP) Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:13986 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.6.99 : 5060 (no NAT) Transmitting (no NAT) to 192.168.6.99:5060: SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.6.99:5060;branch=z9hG4bK3f9924e6;received=192.168.6.99 From: sip:6086@192.168.6.9 To: sip:6086@192.168.6.9;tag=as21c0bda0 Call-ID: 0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99 CSeq: 157 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 29 14:47:11 DEBUG[9065]: chan_sip.c:7988 register_verify: SIP REGISTER attempt failed for (null) : Peer not found Jun 29 14:47:11 NOTICE[9065]: chan_sip.c:13883 handle_request_register: Registration from 'sip:6086@192.168.6.9' failed for '192.168.6.99' - No matching peer found Scheduling destruction of SIP dialog '0003e3a5-22690002-23a4ef3d-0331cf87@192.168.6.99' in 15000 ms (Method: REGISTER) *CLI> show version Asterisk SVN-trunk-r36262M built by root @ foxtrot.tessera.co.uk on a i686 running Linux on 2006-06-29 11:24:29 UTC *CLI>