Asterisk 1.4.1, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'core show license' for details. ========================================================================= Connected to Asterisk 1.4.1 currently running on poweredge (pid = 18286) Verbosity is at least 4 poweredge*CLI> sip set debug SIP Debugging re-enabled poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> NOTIFY sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-30132ac3 From: "Beith" ;tag=b669e2452194b008o0 To: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 190 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 <-------------> [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: NOTIFY sip:phonegw.xarin.com SIP/2.0 (36) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-30132ac3 (57) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (27) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 (38) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 190 NOTIFY (16) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Event: keep-alive (17) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 86.139.222.79:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-30132ac3;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: ;tag=as23d2cfd3 Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 190 NOTIFY User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:10] DEBUG[18338]: chan_sip.c:14774 sipsock_read: Invalid SIP message - rejected , no callid, len 350 [Mar 19 20:43:20] DEBUG[18322]: chan_iax2.c:7725 iax2_do_register: Allocate call number [Mar 19 20:43:20] DEBUG[18322]: chan_iax2.c:7731 iax2_do_register: Registration created on call 2 [Mar 19 20:43:20] DEBUG[18324]: chan_iax2.c:7725 iax2_do_register: Allocate call number [Mar 19 20:43:20] DEBUG[18324]: chan_iax2.c:7731 iax2_do_register: Registration created on call 3 poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> NOTIFY sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-5d353828 From: "Beith" ;tag=b669e2452194b008o0 To: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 191 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 <-------------> [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: NOTIFY sip:phonegw.xarin.com SIP/2.0 (36) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-5d353828 (57) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (27) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 (38) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 191 NOTIFY (16) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Event: keep-alive (17) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- poweredge*CLI> <--- Transmitting (no NAT) to 86.139.222.79:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-5d353828;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: ;tag=as3f832c27 Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 191 NOTIFY User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:25] DEBUG[18338]: chan_sip.c:14774 sipsock_read: Invalid SIP message - rejected , no callid, len 350 poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:27] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-80cd2682 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1085 REGISTER Max-Forwards: 70 Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="2c6c0b7b",uri="sip:phonegw.xarin.com",algorithm=MD5,response="32fb07a7c5b4c552a663c7a45d4bfdc2" Contact: 1003 ;expires=3600 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura <-------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-80cd2682 (59) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=a74cf819cb9e7206o0 (65) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: 1003 (40) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: d933aca5-7b9e66ea@192.168.48.92 (40) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 1085 REGISTER (19) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="2c6c0b7b",uri="sip:phonegw.xarin.com",algorithm=MD5,response="32fb07a7c5b4c552a663c7a45d4bfdc2" (169) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Contact: 1003 ;expires=3600 (59) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Supported: x-sipura (19) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 13: (0) --- (13 headers 0 lines) --- [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for d933aca5-7b9e66ea@192.168.48.92 - REGISTER (No RTP) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.48.92 : 5060 (no NAT) poweredge*CLI> <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-80cd2682;received=192.168.48.92 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1085 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> poweredge*CLI> <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-80cd2682;received=192.168.48.92 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 ;tag=as09d95959 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1085 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="phonegw.xarin.com", nonce="5af6d43b" Content-Length: 0 <------------> Scheduling destruction of SIP dialog 'd933aca5-7b9e66ea@192.168.48.92' in 32000 ms (Method: REGISTER) poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-a955a913 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1086 REGISTER Max-Forwards: 70 Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="5af6d43b",uri="sip:phonegw.xarin.com",algorithm=MD5,response="9b16555dc92eca48352214c001e14e8b" Contact: 1003 ;expires=3600 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura <-------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-a955a913 (59) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=a74cf819cb9e7206o0 (65) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: 1003 (40) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: d933aca5-7b9e66ea@192.168.48.92 (40) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 1086 REGISTER (19) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="5af6d43b",uri="sip:phonegw.xarin.com",algorithm=MD5,response="9b16555dc92eca48352214c001e14e8b" (169) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Contact: 1003 ;expires=3600 (59) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Supported: x-sipura (19) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 13: (0) --- (13 headers 0 lines) --- [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.48.92 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-a955a913;received=192.168.48.92 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1086 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> -- Saved useragent "Sipura/SPA2000-3.1.5" for peer sipura3 <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-a955a913;received=192.168.48.92 From: 1003 ;tag=a74cf819cb9e7206o0 To: 1003 ;tag=as09d95959 Call-ID: d933aca5-7b9e66ea@192.168.48.92 CSeq: 1086 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 3600 Contact: ;expires=3600 Date: Mon, 19 Mar 2007 20:43:27 GMT Content-Length: 0 <------------> [Mar 19 20:43:27] DEBUG[18338]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/sipura3 Scheduling destruction of SIP dialog 'd933aca5-7b9e66ea@192.168.48.92' in 32000 ms (Method: REGISTER) [Mar 19 20:43:27] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - sipura3 [Mar 19 20:43:27] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer sipura3 [Mar 19 20:43:27] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/sipura3 - state 1 (Not in use) [Mar 19 20:43:27] DEBUG[18384]: app_queue.c:546 changethread: Device 'SIP/sipura3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:27] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:27] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:28] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:28] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) poweredge*CLI> <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:30] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Scheduling destruction of SIP dialog '1dcb263925a0467101aed9497824b64c@192.168.48.1' in 6400 ms (Method: NOTIFY) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: NOTIFY sip:sipura3@192.168.48.92:5060 SIP/2.0 (45) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK41d239dd;rport (63) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as7dfc30fb (59) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (36) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Contact: (36) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 1dcb263925a0467101aed9497824b64c@192.168.48.1 (54) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Event: message-summary (22) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Content-Length: 93 (18) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: Messages-Waiting: no (20) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: Message-Account: sip:asterisk@192.168.48.1 (42) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: Voice-Message: 0/24 (0/0) (25) Reliably Transmitting (no NAT) to 192.168.48.92:5060: NOTIFY sip:sipura3@192.168.48.92:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK41d239dd;rport From: "asterisk" ;tag=as7dfc30fb To: Contact: Call-ID: 1dcb263925a0467101aed9497824b64c@192.168.48.1 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 93 Messages-Waiting: no Message-Account: sip:asterisk@192.168.48.1 Voice-Message: 0/24 (0/0) --- [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #52 poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> SIP/2.0 200 OK To: ;tag=a1bd83d57172f97ai0 From: "asterisk" ;tag=as7dfc30fb Call-ID: 1dcb263925a0467101aed9497824b64c@192.168.48.1 CSeq: 102 NOTIFY Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK41d239dd Server: Sipura/SPA2000-3.1.5 Content-Length: 0 <-------------> [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: To: ;tag=a1bd83d57172f97ai0 (59) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as7dfc30fb (59) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: Call-ID: 1dcb263925a0467101aed9497824b64c@192.168.48.1 (54) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 NOTIFY (16) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK41d239dd (57) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Server: Sipura/SPA2000-3.1.5 (28) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Content-Length: 0 (17) [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #52 [Mar 19 20:43:30] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '1dcb263925a0467101aed9497824b64c@192.168.48.1' of Request 102: Match Not Found Really destroying SIP dialog '1dcb263925a0467101aed9497824b64c@192.168.48.1' Method: NOTIFY poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> INVITE sip:1005@phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-1321dcb3 From: 1003 ;tag=f383821579837c63o0 To: Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 101 INVITE Max-Forwards: 70 Contact: 1003 Expires: 240 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 430 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 191393013 191393013 IN IP4 192.168.48.92 s=- c=IN IP4 192.168.48.92 t=0 0 m=audio 16386 RTP/AVP 18 0 2 4 8 96 97 98 100 101 a=rtpmap:18 G729a/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:1005@phonegw.xarin.com SIP/2.0 (41) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-1321dcb3 (59) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=f383821579837c63o0 (65) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (32) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: aa8517d-ea42b41b@192.168.48.92 (39) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 101 INVITE (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: 1003 (46) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Expires: 240 (12) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 430 (19) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Supported: x-sipura (19) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 14: (0) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: o=- 191393013 191393013 IN IP4 192.168.48.92 (44) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: s=- (3) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: c=IN IP4 192.168.48.92 (22) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: m=audio 16386 RTP/AVP 18 0 2 4 8 96 97 98 100 101 (49) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=ptime:30 (10) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) --- (14 headers 19 lines) --- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for aa8517d-ea42b41b@192.168.48.92 - INVITE (With RTP) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1686 parse_sip_options: Found SIP option: -x-sipura- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1698 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 192.168.48.92 : 5060 (no NAT) Using INVITE request as basis request - aa8517d-ea42b41b@192.168.48.92 [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off <--- Reliably Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-1321dcb3;received=192.168.48.92 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as05804d4d Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="phonegw.xarin.com", nonce="6c5d5e80" Content-Length: 0 <------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 Scheduling destruction of SIP dialog 'aa8517d-ea42b41b@192.168.48.92' in 32000 ms (Method: INVITE) Found user 'sipura3' poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> ACK sip:1005@phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-1321dcb3 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as05804d4d Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 101 ACK Max-Forwards: 70 Contact: 1003 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 0 <-------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: ACK sip:1005@phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-1321dcb3 (59) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=f383821579837c63o0 (65) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=as05804d4d (47) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: aa8517d-ea42b41b@192.168.48.92 (39) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 101 ACK (13) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: 1003 (46) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on 'aa8517d-ea42b41b@192.168.48.92' of Response 101: Match Not Found poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> INVITE sip:1005@phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097 From: 1003 ;tag=f383821579837c63o0 To: Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="6c5d5e80",uri="sip:1005@phonegw.xarin.com",algorithm=MD5,response="687d52f53366ba54edab406a2704817b" Contact: 1003 Expires: 240 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 430 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 191393013 191393013 IN IP4 192.168.48.92 s=- c=IN IP4 192.168.48.92 t=0 0 m=audio 16386 RTP/AVP 18 0 2 4 8 96 97 98 100 101 a=rtpmap:18 G729a/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:96 G726-40/8000 =rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:1005@phonegw.xarin.com SIP/2.0 (41) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097 (59) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=f383821579837c63o0 (65) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (32) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: aa8517d-ea42b41b@192.168.48.92 (39) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Proxy-Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="6c5d5e80",uri="sip:1005@phonegw.xarin.com",algorithm=MD5,response="687d52f53366ba54edab406a2704817b" (180) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Contact: 1003 (46) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Expires: 240 (12) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Content-Length: 430 (19) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 13: Supported: x-sipura (19) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 14: Content-Type: application/sdp (29) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: o=- 191393013 191393013 IN IP4 192.168.48.92 (44) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: s=- (3) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: c=IN IP4 192.168.48.92 (22) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: m=audio 16386 RTP/AVP 18 0 2 4 8 96 97 98 100 101 (49) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=ptime:30 (10) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) --- (15 headers 19 lines) --- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1686 parse_sip_options: Found SIP option: -x-sipura- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:1698 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 192.168.48.92 : 5060 (no NAT) Using INVITE request as basis request - aa8517d-ea42b41b@192.168.48.92 [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off Found user 'sipura3' Found RTP audio format 18 Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 4 Found RTP audio format 8 Found RTP audio format 96 Found RTP audio format 97 Found RTP audio format 98 Found RTP audio format 100 Found RTP audio format 101 Peer audio RTP is at port 192.168.48.92:16386 Found description format G729a for ID 18 Found description format PCMU for ID 0 Found description format G726-32 for ID 2 Found description format G723 for ID 4 Found description format PCMA for ID 8 Found description format G726-40 for ID 96 Found description format G726-24 for ID 97 Found description format G726-16 for ID 98 Found description format NSE for ID 100 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x3f19ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|g722|jpeg|png|h261|h263|h263p|h264), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x90d (g723|ulaw|alaw|g726|g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.48.92:16386 [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x90d (g723|ulaw|alaw|g726|g729) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:13378 handle_request_invite: Checking SIP call limits for device sipura3 [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call Looking for 1005 in internal (domain phonegw.xarin.com) [Mar 19 20:43:32] DEBUG[18338]: frame.c:1267 ast_codec_choose: Could not find preferred codec - Going for the best codec [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3803 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x90d (g723|ulaw|alaw|g726|g729) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x3f19ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|g722|jpeg|png|h261|h263|h263p|h264) [Mar 19 20:43:32] DEBUG[18338]: frame.c:1267 ast_codec_choose: Could not find preferred codec - Going for the best codec [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:7964 build_route: build_route: Contact hop: 1003 list_route: hop: [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:13453 handle_request_invite: SIP/sipura3-0979fa30: New call is still down.... Trying... poweredge*CLI> <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097;received=192.168.48.92 From: 1003 ;tag=f383821579837c63o0 To: Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 19 20:43:32] DEBUG[18338]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/sipura3-0979fa30 [Mar 19 20:43:32] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - sipura3 [Mar 19 20:43:32] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer sipura3 [Mar 19 20:43:32] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/sipura3 - state 1 (Not in use) [Mar 19 20:43:32] DEBUG[18385]: app_queue.c:546 changethread: Device 'SIP/sipura3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 19 20:43:32] DEBUG[18386]: pbx.c:1791 pbx_extension_helper: Launching 'Dial' -- Executing [1005@internal:1] Dial("SIP/sipura3-0979fa30", "SIP/polycom1|20|rh") in new stack [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:15267 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 19 20:43:32] DEBUG[18386]: frame.c:1267 ast_codec_choose: Could not find preferred codec - Going for the best codec [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3803 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x0 (nothing) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x3f19ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|g722|jpeg|png|h261|h263|h263p|h264) [Mar 19 20:43:32] DEBUG[18386]: frame.c:1267 ast_codec_choose: Could not find preferred codec - Going for the best codec [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3808 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 19 20:43:32] DEBUG[18386]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-internal-1005-1. [Mar 19 20:43:32] DEBUG[18386]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Mar 19 20:43:32] DEBUG[18386]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Mar 19 20:43:32] DEBUG[18386]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Mar 19 20:43:32] DEBUG[18386]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPURI. [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:2828 sip_call: Outgoing Call for polycom1 [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:2843 sip_call: Our T38 capability (0), joint T38 capability (0) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:6182 add_sdp: ** Our capability: 0x3f09ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|jpeg|png|h261|h263|h263p|h264) Video flag: False [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:6198 add_sdp: This call needs video offers! Video is at 192.168.48.1 port 16116 Audio is at 192.168.48.1 port 11958 Adding codec 0x4 (ulaw) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x10 (g726aal2) to SDP Adding codec 0x20 (adpcm) to SDP Adding codec 0x40 (slin) to SDP Adding codec 0x80 (lpc10) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x800 (g726) to SDP Adding codec 0x10000 (jpeg) to SDP Adding codec 0x20000 (png) to SDP Adding codec 0x40000 (h261) to SDP Adding codec 0x80000 (h263) to SDP Adding codec 0x100000 (h263p) to SDP Adding codec 0x200000 (h264) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x3f09ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|jpeg|png|h261|h263|h263p|h264) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:polycom1@192.168.48.93 SIP/2.0 (41) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport (63) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 2: From: "48 Lounge" ;tag=as35d62332 (56) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 3: To: (32) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 4: Contact: (32) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 (54) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 9: Date: Mon, 19 Mar 2007 20:43:32 GMT (35) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 13: Content-Length: 684 (19) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4571 parse_request: Header 14: (0) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: o=root 18286 18286 IN IP4 192.168.48.1 (38) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: c=IN IP4 192.168.48.1 (21) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: b=CT:384 (8) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: m=audio 11958 RTP/AVP 0 4 3 8 112 5 10 7 18 111 101 (51) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:112 AAL2-G726-32/8000 (30) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:10 L16/8000 (20) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:7 LPC/8000 (19) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=fmtp:18 annexb=no (19) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:111 G726-32/8000 (25) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: m=video 16116 RTP/AVP 26 31 34 103 99 (37) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:26 JPEG/90000 (22) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:31 H261/90000 (22) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:34 H263/90000 (22) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=rtpmap:99 H264/90000 (22) [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.48.93:5060: INVITE sip:polycom1@192.168.48.93 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport From: "48 Lounge" ;tag=as35d62332 To: Contact: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 19 Mar 2007 20:43:32 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 684 v=0 o=root 18286 18286 IN IP4 192.168.48.1 s=session c=IN IP4 192.168.48.1 b=CT:384 t=0 0 m=audio 11958 RTP/AVP 0 4 3 8 112 5 10 7 18 111 101 a=rtpmap:0 PCMU/8000 a=rtpmap:4 G723/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:112 AAL2-G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 16116 RTP/AVP 26 31 34 103 99 a=rtpmap:26 JPEG/90000 a=rtpmap:31 H261/90000 a=rtpmap:34 H263/90000 a=rtpmap:103 h263-1998/90000 a=rtpmap:99 H264/90000 a=sendrecv --- [Mar 19 20:43:32] DEBUG[18386]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #55 -- Called polycom1 poweredge*CLI> <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097;received=192.168.48.92 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as6312eb86 Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> poweredge*CLI> <--- SIP read from 192.168.48.93:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport From: "48 Lounge" ;tag=as35d62332 To: ;tag=FE99365D-1E78B044 CSeq: 102 INVITE Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 Contact: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 Content-Length: 0 <-------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport (63) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "48 Lounge" ;tag=as35d62332 (56) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=FE99365D-1E78B044 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 INVITE (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Contact: (37) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 0 (17) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #55 - INVITE (got response) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '379eaa6948044d5957e0f2551f39e988@192.168.48.1' Request 102: Found [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:11621 handle_response_invite: SIP response 100 to standard invite poweredge*CLI> <--- SIP read from 192.168.48.93:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport From: "48 Lounge" ;tag=as35d62332 To: ;tag=FE99365D-1E78B044 CSeq: 102 INVITE Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 Contact: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 Allow-Events: talk,hold,conference Content-Length: 0 <-------------> [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport (63) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "48 Lounge" ;tag=as35d62332 (56) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=FE99365D-1E78B044 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 INVITE (16) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Contact: (37) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 (54) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Allow-Events: talk,hold,conference (34) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '379eaa6948044d5957e0f2551f39e988@192.168.48.1' Request 102: Found [Mar 19 20:43:32] DEBUG[18338]: chan_sip.c:11621 handle_response_invite: SIP response 180 to standard invite [Mar 19 20:43:32] DEBUG[18338]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/polycom1-097a7a28 -- SIP/polycom1-097a7a28 is ringing [Mar 19 20:43:32] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - polycom1 [Mar 19 20:43:32] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer polycom1 [Mar 19 20:43:32] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/polycom1 - state 1 (Not in use) [Mar 19 20:43:32] DEBUG[18387]: app_queue.c:546 changethread: Device 'SIP/polycom1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:34] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:34] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) poweredge*CLI> <--- SIP read from 192.168.48.93:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport From: "48 Lounge" ;tag=as35d62332 To: ;tag=FE99365D-1E78B044 CSeq: 102 INVITE Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 Content-Type: application/sdp Content-Length: 374 v=0 o=- 1174332903 1174332903 IN IP4 192.168.48.93 s=Polycom IP Phone c=IN IP4 192.168.48.93 t=0 0 m=audio 2236 RTP/AVP 0 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 m=video 0 RTP/AVP 26 31 34 103 99 a=inactive a=rtpmap:26 jpeg/90000 a=rtpmap:31 h261/90000 a=rtpmap:34 h263/90000 a=rtpmap:103 h263-1998/90000 a=rtpmap:99 h264/90000 <-------------> [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK1384817a;rport (63) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "48 Lounge" ;tag=as35d62332 (56) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=FE99365D-1E78B044 (54) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 INVITE (16) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 (54) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Contact: (37) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 (54) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Type: application/sdp (29) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 374 (19) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: (0) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: o=- 1174332903 1174332903 IN IP4 192.168.48.93 (46) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: s=Polycom IP Phone (18) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: c=IN IP4 192.168.48.93 (22) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: m=audio 2236 RTP/AVP 0 101 (26) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: m=video 0 RTP/AVP 26 31 34 103 99 (33) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=inactive (10) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:26 jpeg/90000 (22) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:31 h261/90000 (22) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:34 h263/90000 (22) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:103 h263-1998/90000 (28) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4603 parse_request: Line: a=rtpmap:99 h264/90000 (22) --- (11 headers 16 lines) --- [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:2069 __sip_ack: Acked pending invite 102 [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '379eaa6948044d5957e0f2551f39e988@192.168.48.1' of Request 102: Match Not Found [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:11621 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Found RTP video format 26 Found RTP video format 31 Found RTP video format 34 Found RTP video format 103 Found RTP video format 99 Peer audio RTP is at port 192.168.48.93:2236 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Found description format jpeg for ID 26 Found description format h261 for ID 31 Found description format h263 for ID 34 Found description format h263-1998 for ID 103 Found description format h264 for ID 99 [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/polycom1-097a7a28 Capabilities: us - 0x3f19ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|g726aal2|g722|jpeg|png|h261|h263|h263p|h264), peer - audio=0x3d0004 (ulaw|jpeg|h261|h263|h263p|h264)/video=0x3d0000 (jpeg|h261|h263|h263p|h264), combined - 0x3d0004 (ulaw|jpeg|h261|h263|h263p|h264) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.48.93:2236 [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x3d0004 (ulaw|jpeg|h261|h263|h263p|h264) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:7964 build_route: build_route: Contact hop: list_route: hop: [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:5637 reqprep: Strict routing enforced for session 379eaa6948044d5957e0f2551f39e988@192.168.48.1 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.48.93, port 5060 Transmitting (no NAT) to 192.168.48.93:5060: ACK sip:polycom1@192.168.48.93 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK29e3b1b8;rport From: "48 Lounge" ;tag=as35d62332 To: ;tag=FE99365D-1E78B044 Contact: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- Call on SIP/polycom1-097a7a28 placed on hold [Mar 19 20:43:36] DEBUG[18386]: channel.c:2587 ast_prod: Prodding channel 'SIP/sipura3-0979fa30' [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6182 add_sdp: ** Our capability: 0x90d (g723|ulaw|alaw|g726|g729) Video flag: True [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.48.1 port 17640 Adding codec 0x1 (g723) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x800 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x90d (g723|ulaw|alaw|g726|g729) <--- Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097;received=192.168.48.92 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as6312eb86 Call-ID: aa8517d-ea42b41b@192.168.48.92 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: 362 v=0 o=root 18286 18286 IN IP4 192.168.48.1 s=session c=IN IP4 192.168.48.1 t=0 0 m=audio 17640 RTP/AVP 4 0 8 18 2 101 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> -- Started music on hold, class 'default', on SIP/sipura3-0979fa30 [Mar 19 20:43:36] DEBUG[18386]: channel.c:1997 ast_settimeout: Scheduling timer at 160 sample intervals [Mar 19 20:43:36] DEBUG[18386]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/polycom1-097a7a28 -- SIP/polycom1-097a7a28 answered SIP/sipura3-0979fa30 -- Stopped music on hold on SIP/sipura3-0979fa30 [Mar 19 20:43:36] DEBUG[18386]: channel.c:1997 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 19 20:43:36] DEBUG[18386]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/sipura3-0979fa30 [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:3461 sip_answer: SIP answering channel: SIP/sipura3-0979fa30 [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 19 20:43:36] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - polycom1 [Mar 19 20:43:36] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer polycom1 [Mar 19 20:43:36] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/polycom1 - state 1 (Not in use) [Mar 19 20:43:36] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - sipura3 [Mar 19 20:43:36] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer sipura3 [Mar 19 20:43:36] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/sipura3 - state 1 (Not in use) [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6182 add_sdp: ** Our capability: 0x90d (g723|ulaw|alaw|g726|g729) Video flag: True [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.48.1 port 17640 Adding codec 0x1 (g723) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x100 (g729) to SDP Adding codec 0x800 (g726) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x90d (g723|ulaw|alaw|g726|g729) <--- Reliably Transmitting (no NAT) to 192.168.48.92:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-c35d9097;received=192.168.48.92 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as6312eb86 Call-ID: aa8517d-ea42b41b@192.168.48.92 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: 362 v=0 o=root 18286 18287 IN IP4 192.168.48.1 s=session c=IN IP4 192.168.48.1 t=0 0 m=audio 17640 RTP/AVP 4 0 8 18 2 101 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #58 [Mar 19 20:43:36] DEBUG[18389]: app_queue.c:546 changethread: Device 'SIP/sipura3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 19 20:43:36] DEBUG[18388]: app_queue.c:546 changethread: Device 'SIP/polycom1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> ACK sip:1005@192.168.48.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-9ae3f160 From: 1003 ;tag=f383821579837c63o0 To: ;tag=as6312eb86 Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="6c5d5e80",uri="sip:1005@192.168.48.1",algorithm=MD5,response="19112b086a8c6e05a510d174f3ea9128" Contact: 1003 User-Agent: Sipura/SPA2000-3.1.5 Content-Length: 0 <-------------> [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: ACK sip:1005@192.168.48.1 SIP/2.0 (33) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.92:5060;branch=z9hG4bK-9ae3f160 (59) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: 1003 ;tag=f383821579837c63o0 (65) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=as6312eb86 (47) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: aa8517d-ea42b41b@192.168.48.92 (39) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 ACK (13) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Proxy-Authorization: Digest username="sipura3",realm="phonegw.xarin.com",nonce="6c5d5e80",uri="sip:1005@192.168.48.1",algorithm=MD5,response="19112b086a8c6e05a510d174f3ea9128" (175) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Contact: 1003 (46) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA2000-3.1.5 (32) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #58 [Mar 19 20:43:36] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on 'aa8517d-ea42b41b@192.168.48.92' of Response 102: Match Not Found [Mar 19 20:43:36] DEBUG[18386]: chan_sip.c:4090 sip_rtp_read: Oooh, format changed to 256 [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/sipura3-0979fa30 to read format ulaw [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/sipura3-0979fa30 to write format ulaw [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/sipura3-0979fa30 to read format slin [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/polycom1-097a7a28 to write format slin [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/polycom1-097a7a28 to read format slin [Mar 19 20:43:36] DEBUG[18386]: channel.c:2845 set_format: Set channel SIP/sipura3-0979fa30 to write format slin [Mar 19 20:43:36] DEBUG[18386]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to g729 [Mar 19 20:43:36] DEBUG[18386]: rtp.c:2687 ast_rtp_write: Created smoother: format: 256 ms: 20 len: 20 [Mar 19 20:43:38] DEBUG[18386]: rtp.c:871 ast_rtcp_read: Got RTCP report of 88 bytes poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:38] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:38] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER) [Mar 19 20:43:40] DEBUG[18331]: chan_iax2.c:7112 socket_process: Peer voiptalk: got pong, lastms 27, historicms 27, maxms 2000 [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: OPTIONS sip:sipura3@192.168.48.92:5060 SIP/2.0 (46) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK38c9af90;rport (63) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as2b9efee4 (59) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (36) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Contact: (36) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 2800a9e9548744ee73598c9f5397b10b@192.168.48.1 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Date: Mon, 19 Mar 2007 20:43:40 GMT (35) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Content-Length: 0 (17) Reliably Transmitting (no NAT) to 192.168.48.92:5060: OPTIONS sip:sipura3@192.168.48.92:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK38c9af90;rport From: "asterisk" ;tag=as2b9efee4 To: Contact: Call-ID: 2800a9e9548744ee73598c9f5397b10b@192.168.48.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 19 Mar 2007 20:43:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #61 [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: OPTIONS sip:polycom1@192.168.48.93 SIP/2.0 (42) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK71a0aba0;rport (63) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as09411677 (59) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (32) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Contact: (36) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 627761516073924d5e75db1827a36091@192.168.48.1 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Date: Mon, 19 Mar 2007 20:43:40 GMT (35) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: Content-Length: 0 (17) Reliably Transmitting (no NAT) to 192.168.48.93:5060: OPTIONS sip:polycom1@192.168.48.93 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK71a0aba0;rport From: "asterisk" ;tag=as09411677 To: Contact: Call-ID: 627761516073924d5e75db1827a36091@192.168.48.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 19 Mar 2007 20:43:40 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #63 poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> SIP/2.0 200 OK To: ;tag=a1bd83d57172f97ai0 From: "asterisk" ;tag=as2b9efee4 Call-ID: 2800a9e9548744ee73598c9f5397b10b@192.168.48.1 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK38c9af90 Server: Sipura/SPA2000-3.1.5 Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura <-------------> [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: To: ;tag=a1bd83d57172f97ai0 (59) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as2b9efee4 (59) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: Call-ID: 2800a9e9548744ee73598c9f5397b10b@192.168.48.1 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 OPTIONS (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK38c9af90 (57) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Server: Sipura/SPA2000-3.1.5 (28) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Content-Length: 0 (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Supported: x-sipura (19) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #61 [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '2800a9e9548744ee73598c9f5397b10b@192.168.48.1' of Request 102: Match Not Found Really destroying SIP dialog '2800a9e9548744ee73598c9f5397b10b@192.168.48.1' Method: OPTIONS [Mar 19 20:43:40] DEBUG[18323]: chan_iax2.c:7112 socket_process: Peer iaxtel: got pong, lastms 128, historicms 128, maxms 2000 poweredge*CLI> <--- SIP read from 192.168.48.93:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK71a0aba0;rport From: "asterisk" ;tag=as09411677 To: ;tag=64C1C210-31945AD3 CSeq: 102 OPTIONS Call-ID: 627761516073924d5e75db1827a36091@192.168.48.1 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 ontent-Length: 0 <-------------> [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK71a0aba0;rport (63) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "asterisk" ;tag=as09411677 (59) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=64C1C210-31945AD3 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 OPTIONS (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 627761516073924d5e75db1827a36091@192.168.48.1 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Contact: (37) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 (54) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #63 [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '627761516073924d5e75db1827a36091@192.168.48.1' of Request 102: Match Not Found Really destroying SIP dialog '627761516073924d5e75db1827a36091@192.168.48.1' Method: OPTIONS poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> NOTIFY sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-bdf606fc From: "Beith" ;tag=b669e2452194b008o0 To: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 192 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 <-------------> [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: NOTIFY sip:phonegw.xarin.com SIP/2.0 (36) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-bdf606fc (57) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: (27) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: f1f63f78-ccdb3c78@192.168.1.2 (38) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 192 NOTIFY (16) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Event: keep-alive (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- <--- Transmitting (no NAT) to 86.139.222.79:5060 ---> SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-bdf606fc;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: ;tag=as7467b656 Call-ID: f1f63f78-ccdb3c78@192.168.1.2 CSeq: 192 NOTIFY User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:40] DEBUG[18338]: chan_sip.c:14774 sipsock_read: Invalid SIP message - rejected , no callid, len 350 poweredge*CLI> <--- SIP read from 192.168.48.93:5060 ---> BYE sip:1003@192.168.48.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.93;branch=z9hG4bKb474c8796C9554DE From: ;tag=FE99365D-1E78B044 To: "48 Lounge" ;tag=as35d62332 CSeq: 1 BYE Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 Contact: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 Max-Forwards: 70 Content-Length: 0 <-------------> [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: BYE sip:1003@192.168.48.1 SIP/2.0 (33) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.48.93;branch=z9hG4bKb474c8796C9554DE (61) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=FE99365D-1E78B044 (56) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "48 Lounge" ;tag=as35d62332 (54) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 1 BYE (11) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 (54) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Contact: (37) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: User-Agent: PolycomSoundPointIP-SPIP_501-UA/1.6.3.0067 (54) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.48.93 : 5060 (no NAT) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:1631 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 379eaa6948044d5957e0f2551f39e988@192.168.48.1 [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:14167 handle_request_bye: Received bye, issuing owner hangup <--- Transmitting (no NAT) to 192.168.48.93:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.48.93;branch=z9hG4bKb474c8796C9554DE;received=192.168.48.93 From: ;tag=FE99365D-1E78B044 To: "48 Lounge" ;tag=as35d62332 Call-ID: 379eaa6948044d5957e0f2551f39e988@192.168.48.1 CSeq: 1 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 19 20:43:41] DEBUG[18386]: channel.c:3800 ast_generic_bridge: Didn't get a frame from channel: SIP/polycom1-097a7a28 [Mar 19 20:43:41] DEBUG[18386]: channel.c:4118 ast_channel_bridge: Bridge stops bridging channels SIP/sipura3-0979fa30 and SIP/polycom1-097a7a28 [Mar 19 20:43:41] DEBUG[18386]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/polycom1-097a7a28' [Mar 19 20:43:41] DEBUG[18386]: chan_sip.c:3310 sip_hangup: Hangup call SIP/polycom1-097a7a28, SIP callid 379eaa6948044d5957e0f2551f39e988@192.168.48.1) [Mar 19 20:43:41] DEBUG[18386]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/polycom1-097a7a28 [Mar 19 20:43:41] DEBUG[18386]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Mar 19 20:43:41] DEBUG[18386]: app_dial.c:1670 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Mar 19 20:43:41] DEBUG[18386]: pbx.c:2389 __ast_pbx_run: Spawn extension (internal,1005,1) exited non-zero on 'SIP/sipura3-0979fa30' == Spawn extension (internal, 1005, 1) exited non-zero on 'SIP/sipura3-0979fa30' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1791 pbx_extension_helper: Launching 'Hangup' -- Executing [h@internal:1] Hangup("SIP/sipura3-0979fa30", "") in new stack [Mar 19 20:43:41] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - polycom1 [Mar 19 20:43:41] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer polycom1 [Mar 19 20:43:41] DEBUG[18386]: pbx.c:2510 __ast_pbx_run: Spawn extension (internal,h,1) exited non-zero on 'SIP/sipura3-0979fa30' [Mar 19 20:43:41] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/polycom1 - state 1 (Not in use) == Spawn extension (internal, h, 1) exited non-zero on 'SIP/sipura3-0979fa30' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '"48 Lounge" <1003>' [Mar 19 20:43:41] DEBUG[18391]: app_queue.c:546 changethread: Device 'SIP/polycom1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1003' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1005' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'internal' Really destroying SIP dialog '379eaa6948044d5957e0f2551f39e988@192.168.48.1' Method: BYE [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/sipura3-0979fa30' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/polycom1-097a7a28' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'Hangup' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-19 20:43:32' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-19 20:43:36' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-19 20:43:41' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '9' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '5' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1174337012.2' [Mar 19 20:43:41] DEBUG[18386]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 19 20:43:41] DEBUG[18386]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/sipura3-0979fa30' [Mar 19 20:43:41] DEBUG[18386]: chan_sip.c:3310 sip_hangup: Hangup call SIP/sipura3-0979fa30, SIP callid aa8517d-ea42b41b@192.168.48.92) Scheduling destruction of SIP dialog 'aa8517d-ea42b41b@192.168.48.92' in 32000 ms (Method: ACK) [Mar 19 20:43:41] DEBUG[18386]: chan_sip.c:5637 reqprep: Strict routing enforced for session aa8517d-ea42b41b@192.168.48.92 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.48.92, port 5060 Reliably Transmitting (no NAT) to 192.168.48.92:5060: BYE sip:sipura3@192.168.48.92:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK60779af7;rport From: ;tag=as6312eb86 To: 1003 ;tag=f383821579837c63o0 Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 19 20:43:41] DEBUG[18386]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #68 [Mar 19 20:43:41] DEBUG[18386]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/sipura3-0979fa30 [Mar 19 20:43:41] DEBUG[18311]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - sipura3 [Mar 19 20:43:41] DEBUG[18311]: chan_sip.c:15201 sip_devicestate: Checking device state for peer sipura3 [Mar 19 20:43:41] DEBUG[18311]: devicestate.c:287 do_state_change: Changing state for SIP/sipura3 - state 1 (Not in use) [Mar 19 20:43:41] DEBUG[18392]: app_queue.c:546 changethread: Device 'SIP/sipura3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. poweredge*CLI> <--- SIP read from 192.168.48.92:5060 ---> SIP/2.0 200 OK To: 1003 ;tag=f383821579837c63o0 From: ;tag=as6312eb86 Call-ID: aa8517d-ea42b41b@192.168.48.92 CSeq: 102 BYE Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK60779af7 Server: Sipura/SPA2000-3.1.5 Content-Length: 0 <-------------> [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: To: 1003 ;tag=f383821579837c63o0 (63) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=as6312eb86 (49) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: Call-ID: aa8517d-ea42b41b@192.168.48.92 (39) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: CSeq: 102 BYE (13) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.48.1:5060;branch=z9hG4bK60779af7 (57) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Server: Sipura/SPA2000-3.1.5 (28) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Content-Length: 0 (17) [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #68 [Mar 19 20:43:41] DEBUG[18338]: chan_sip.c:2087 __sip_ack: Stopping retransmission on 'aa8517d-ea42b41b@192.168.48.92' of Request 102: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog 'aa8517d-ea42b41b@192.168.48.92' Method: ACK poweredge*CLI> <--- SIP read from 86.139.222.79:5060 ---> REGISTER sip:phonegw.xarin.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER Max-Forwards: 70 Contact: "Beith" ;expires=3600 Warning: 399 spa "Full Cone NAT Detected" User-Agent: Sipura/SPA841-3.1.4(a) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER <-------------> [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 0: REGISTER sip:phonegw.xarin.com SIP/2.0 (38) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13 (57) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 2: From: "Beith" ;tag=b669e2452194b008o0 (70) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 3: To: "Beith" (45) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 4: Call-ID: e318bb78-dbbaf078@192.168.1.2 (38) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 5: CSeq: 64 REGISTER (17) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 6: Max-Forwards: 70 (16) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 7: Contact: "Beith" ;expires=3600 (64) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 8: Warning: 399 spa "Full Cone NAT Detected" (41) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 9: User-Agent: Sipura/SPA841-3.1.4(a) (34) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 10: Content-Length: 0 (17) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:4571 parse_request: Header 12: (0) --- (12 headers 0 lines) --- [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:14590 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:14609 handle_request: Ignoring SIP message because of retransmit (REGISTER Seqno 64, ours 64) Using latest REGISTER request as basis request Sending to 192.168.1.2 : 5060 (no NAT) <--- Transmitting (no NAT) to 192.168.1.2:5060 ---> SIP/2.0 404 Not found Via: SIP/2.0/UDP 192.168.1.2:5060;branch=z9hG4bK-a404ea13;received=86.139.222.79 From: "Beith" ;tag=b669e2452194b008o0 To: "Beith" ;tag=as67c153d8 Call-ID: e318bb78-dbbaf078@192.168.1.2 CSeq: 64 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 19 20:43:42] DEBUG[18338]: chan_sip.c:8390 register_verify: SIP REGISTER attempt failed for (null) : Peer not found [Mar 19 20:43:42] NOTICE[18338]: chan_sip.c:14491 handle_request_register: Registration from '"Beith" ' failed for '86.139.222.79' - No matching peer found Scheduling destruction of SIP dialog 'e318bb78-dbbaf078@192.168.1.2' in 32000 ms (Method: REGISTER)