[Mar 1 06:49:01] Asterisk 1.4.0, Copyright (C) 1999 - 2006 Digium, Inc. and others. [Mar 1 06:49:01] Created by Mark Spencer [Mar 1 06:49:01] Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details. [Mar 1 06:49:01] This is free software, with components licensed under the GNU General Public [Mar 1 06:49:01] License version 2 and other licenses; you are welcome to redistribute it under [Mar 1 06:49:01] certain conditions. Type 'core show license' for details. [trimmed] [Mar 1 06:49:05] Asterisk Ready. *CLI> set debug 4 Core debug was 5 and is now 4 The 'set debug' command is deprecated and will be removed in a future release. Please use 'core set debug' instead. *CLI> core set debug 4 Core debug is at least 4 *CLI> core set verbose 4 Verbosity is at least 4 The 'set verbose' command is deprecated and will be removed in a future release. Please use 'core set verbose' instead. *CLI> core set verbose 4 Verbosity is at least 4 *CLI> sip debug SIP Debugging enabled The 'sip debug' command is deprecated and will be removed in a future release. Please use 'sip set debug' instead. *CLI> sip set debug SIP Debugging re-enabled *CLI> [Mar 1 06:50:09] <--- SIP read from 192.168.5.203:5067 ---> REGISTER sip:register SIP/2.0 Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-15073 To: sip:6001@10.7.1.111 From: sip:6001@10.7.1.111 Call-Id: 16833-5067@192.168.5.203 Contact: ;expires=3600 CSeq: 1 REGISTER Accept: text/plain Accept: application/sdp Accept: application/x-cw-user-profile Subject: Registration User-Agent: Citel-Handset-Gateway (Meridian M2008) (http://192.168.5.203/mgmt/port/3) (Citel SIP Handset Gateway SW:3.61.3x03x srl HW:224/1) Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, SUBSCRIBE, NOTIFY, PRACK, REFER Supported: replaces Content-Length: 0 <-------------> [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 0: REGISTER sip:register SIP/2.0 (29) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-15073 (62) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 2: To: sip:6001@10.7.1.111 (23) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 3: From: sip:6001@10.7.1.111 (25) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 4: Call-Id: 16833-5067@192.168.5.203 (33) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 5: Contact: ;expires=3600 (53) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 REGISTER (16) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 7: Accept: text/plain (18) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 8: Accept: application/sdp (23) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 9: Accept: application/x-cw-user-profile (37) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 10: Subject: Registration (21) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 11: User-Agent: Citel-Handset-Gateway (Meridian M2008) (http://192.168.5.203/mgmt/port/3) (Citel SIP Handset Gateway SW:3.61.3x03x srl HW:224/1) (140) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 12: Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, SUBSCRIBE, NOTIFY, PRACK, REFER (73) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 13: Supported: replaces (19) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 14: Content-Length: 0 (17) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 15: (0) [Mar 1 06:50:09] --- (15 headers 0 lines) --- [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 16833-5067@192.168.5.203 - REGISTER (No RTP) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:14453 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 1 06:50:09] Using latest REGISTER request as basis request [Mar 1 06:50:09] Sending to 192.168.5.203 : 5067 (no NAT) [Mar 1 06:50:09] <--- Transmitting (no NAT) to 192.168.5.203:5067 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-15073;received=192.168.5.203 From: sip:6001@10.7.1.111 To: sip:6001@10.7.1.111 Call-ID: 16833-5067@192.168.5.203 CSeq: 1 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 1 06:50:09] -- Saved useragent "Citel-Handset-Gateway (Meridian M2008) (http://192.168.5.203/mgmt/port/3) (Citel SIP Handset Gateway SW:3.61.3x03x srl HW:224/1)" for peer 6001 [Mar 1 06:50:09] <--- Transmitting (no NAT) to 192.168.5.203:5067 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-15073;received=192.168.5.203 From: sip:6001@10.7.1.111 To: sip:6001@10.7.1.111;tag=as5b190fdf Call-ID: 16833-5067@192.168.5.203 CSeq: 1 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 3600 Contact: ;expires=3600 Date: Thu, 01 Mar 2007 06:50:09 GMT Content-Length: 0 <------------> [Mar 1 06:50:09] DEBUG[5866]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/6001 [Mar 1 06:50:09] Scheduling destruction of SIP dialog '16833-5067@192.168.5.203' in 32000 ms (Method: REGISTER) [Mar 1 06:50:09] DEBUG[5859]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 6001 [Mar 1 06:50:09] DEBUG[5859]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 6001 [Mar 1 06:50:09] DEBUG[5859]: devicestate.c:287 do_state_change: Changing state for SIP/6001 - state 1 (Not in use) [Mar 1 06:50:09] DEBUG[5859]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 6001 [Mar 1 06:50:09] DEBUG[5859]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 6001 [Mar 1 06:50:09] DEBUG[5887]: app_queue.c:546 changethread: Device 'SIP/6001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 1 06:50:09] <--- SIP read from 192.168.5.203:5067 ---> SUBSCRIBE sip:6000@register SIP/2.0 Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-4506 To: From: ;tag=23820 Call-Id: 5985-0xc9fd78-5067@192.168.5.203 Max-Forwards: 70 CSeq: 1 SUBSCRIBE Contact: sip:line52@192.168.5.203:5067 User-Agent: Citel-Handset-Gateway (Meridian M2008) Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, SUBSCRIBE, NOTIFY, PRACK, REFER Allow-Events: dialog, refer, message-summary, call-info, line-seize, presence Event: dialog Accept: application/dialog-info+xml Expires: 3600 Content-Length: 0 <-------------> [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 0: SUBSCRIBE sip:6000@register SIP/2.0 (35) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-4506 (61) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 2: To: (23) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=23820 (37) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 4: Call-Id: 5985-0xc9fd78-5067@192.168.5.203 (41) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 5: Max-Forwards: 70 (16) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 6: CSeq: 1 SUBSCRIBE (17) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 7: Contact: sip:line52@192.168.5.203:5067 (38) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 8: User-Agent: Citel-Handset-Gateway (Meridian M2008) (50) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, SUBSCRIBE, NOTIFY, PRACK, REFER (73) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 10: Allow-Events: dialog, refer, message-summary, call-info, line-seize, presence (77) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 11: Event: dialog (13) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 12: Accept: application/dialog-info+xml (35) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 13: Expires: 3600 (13) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 14: Content-Length: 0 (17) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 15: (0) [Mar 1 06:50:09] --- (15 headers 0 lines) --- [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for 5985-0xc9fd78-5067@192.168.5.203 - SUBSCRIBE (No RTP) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:14453 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Mar 1 06:50:09] Creating new subscription [Mar 1 06:50:09] Sending to 192.168.5.203 : 5067 (no NAT) [Mar 1 06:50:09] Found peer '6001' [Mar 1 06:50:09] Looking for 6000 in numberplan-custom-1 (domain register) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:14262 handle_request_subscribe: Adding subscription for extension 6000 context numberplan-custom-1 for peer line52 [Mar 1 06:50:09] Scheduling destruction of SIP dialog '5985-0xc9fd78-5067@192.168.5.203' in 3610000 ms (Method: SUBSCRIBE) [Mar 1 06:50:09] DEBUG[5866]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 6000 [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 6000 [Mar 1 06:50:09] <--- Transmitting (no NAT) to 192.168.5.203:5067 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.5.203:5067;branch=z9hG4bKline52-4506;received=192.168.5.203 From: ;tag=23820 To: ;tag=as024246a4 Call-ID: 5985-0xc9fd78-5067@192.168.5.203 CSeq: 1 SUBSCRIBE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 3600 Contact: ;expires=3600 Content-Length: 0 <------------> [Mar 1 06:50:09] DEBUG[5866]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 6000 [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:15048 sip_devicestate: Checking device state for peer 6000 [Mar 1 06:50:09] Reliably Transmitting (no NAT) to 192.168.5.203:5067: NOTIFY sip:6001@10.7.1.111 SIP/2.0 Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK3ffa5972;rport From: ;tag=as024246a4 To: ;tag=23820 Contact: Call-ID: 5985-0xc9fd78-5067@192.168.5.203 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 200 confirmed --- [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #10 [Mar 1 06:50:09] <--- SIP read from 192.168.5.203:5067 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK3ffa5972;rport To: ;tag=23820 From: ;tag=as024246a4 Call-Id: 5985-0xc9fd78-5067@192.168.5.203 CSeq: 102 NOTIFY Content-Length: 0 <-------------> [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 404 Not Found (21) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK3ffa5972;rport (61) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 2: To: ;tag=23820 (35) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 3: From: ;tag=as024246a4 (40) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 4: Call-Id: 5985-0xc9fd78-5067@192.168.5.203 (41) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 6: Content-Length: 0 (17) [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 7: (0) [Mar 1 06:50:09] --- (7 headers 0 lines) --- [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #10 [Mar 1 06:50:09] DEBUG[5866]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '5985-0xc9fd78-5067@192.168.5.203' of Request 102: Match Not Found [Mar 1 06:50:09] SIP Response message for INCOMING dialog NOTIFY arrived [Mar 1 06:50:09] -- Incoming call: Got SIP response 404 "Not Found" back from 192.168.5.203 [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4264 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Mar 1 06:50:20] Scheduling destruction of SIP dialog '2a5a06f34d75d470294b02e445386a00@10.7.1.111' in 32000 ms (Method: NOTIFY) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 0: NOTIFY sip:line52@192.168.5.203:5067 SIP/2.0 (44) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK27f670e5;rport (61) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 2: From: "asterisk" ;tag=as2cc9741d (57) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 3: To: (35) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 4: Contact: (34) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 5: Call-ID: 2a5a06f34d75d470294b02e445386a00@10.7.1.111 (52) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 9: Event: message-summary (22) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 11: Content-Length: 90 (18) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 12: (0) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4559 parse_request: Line: Messages-Waiting: no (20) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4559 parse_request: Line: Message-Account: sip:asterisk@10.7.1.111 (40) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4559 parse_request: Line: Voice-Message: 0/0 (0/0) (24) [Mar 1 06:50:20] Reliably Transmitting (no NAT) to 192.168.5.203:5067: NOTIFY sip:line52@192.168.5.203:5067 SIP/2.0 Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK27f670e5;rport From: "asterisk" ;tag=as2cc9741d To: Contact: Call-ID: 2a5a06f34d75d470294b02e445386a00@10.7.1.111 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 90 Messages-Waiting: no Message-Account: sip:asterisk@10.7.1.111 Voice-Message: 0/0 (0/0) --- [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:1957 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12 [Mar 1 06:50:20] <--- SIP read from 192.168.5.203:5067 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK27f670e5;rport To: From: "asterisk" ;tag=as2cc9741d Call-Id: 2a5a06f34d75d470294b02e445386a00@10.7.1.111 CSeq: 102 NOTIFY Content-Length: 0 <-------------> [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 1: Via: SIP/2.0/UDP 10.7.1.111:5060;branch=z9hG4bK27f670e5;rport (61) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 2: To: (35) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 3: From: "asterisk" ;tag=as2cc9741d (57) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 4: Call-Id: 2a5a06f34d75d470294b02e445386a00@10.7.1.111 (52) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 5: CSeq: 102 NOTIFY (16) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 6: Content-Length: 0 (17) [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:4527 parse_request: Header 7: (0) [Mar 1 06:50:20] --- (7 headers 0 lines) --- [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:2061 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Mar 1 06:50:20] DEBUG[5866]: chan_sip.c:2071 __sip_ack: Stopping retransmission on '2a5a06f34d75d470294b02e445386a00@10.7.1.111' of Request 102: Match Not Found [Mar 1 06:50:20] Really destroying SIP dialog '2a5a06f34d75d470294b02e445386a00@10.7.1.111' Method: NOTIFY *CLI> asteristop [Mar 1 06:50:41] DEBUG[5866]: chan_sip.c:1992 __sip_autodestruct: Auto destroying SIP dialog '16833-5067@192.168.5.203' [Mar 1 06:50:41] DEBUG[5866]: chan_sip.c:3080 sip_destroy: Destroying SIP dialog 16833-5067@192.168.5.203 [Mar 1 06:50:41] Really destroying SIP dialog '16833-5067@192.168.5.203' Method: REGISTER gracefully [Mar 1 06:50:46] Waiting for inactivity to perform halt... [Mar 1 06:50:46] Executing last minute cleanups [Mar 1 06:50:46] == Destroying musiconhold processes [Mar 1 06:50:46] Asterisk cleanly ending (0). [Mar 1 06:50:46] DEBUG[5853]: asterisk.c:1193 quit_handler: Asterisk ending (0).