[Home]

Summary:ASTERISK-15298: SIP qualify fails unless NAT is enabled
Reporter:Dave Hawkes (hevad)Labels:
Date Opened:2009-12-10 13:33:08.000-0600Date Closed:2011-07-26 14:34:14
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/TCP-TLS
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Using a SIP device on the same subnet as asterisk fails to qualify unless nat option is enabled. The device will register fine and can make outgoing calls but will not receive calls.

****** ADDITIONAL INFORMATION ******

Trace from asterisk log:

[Dec 10 14:26:03] VERBOSE[11109] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.16.158:62316:
OPTIONS sip:203@192.168.16.158:62316;rinstance=40ebf61df7c86f5d;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.16.62:5060;branch=z9hG4bK44372a09;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@a.cadlink.com>;tag=as564eee80
To: <sip:203@192.168.16.158:62316;rinstance=40ebf61df7c86f5d;transport=TCP>
Contact: <sip:Unknown@192.168.16.62;transport=TCP>
Call-ID: 4c4de6273af17ab7763339c10542db89@a.cadlink.com
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX SVN-branch-1.6.1-r233730M
Date: Thu, 10 Dec 2009 19:26:03 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[Dec 10 14:26:03] WARNING[11109] chan_sip.c: sip_xmit of 0x2aaac81001e0 (len 648) to 192.168.16.158:62316 returned -2: No such file or directory
Comments:By: Elazar Broad (ebroad) 2009-12-10 13:38:44.000-0600

I had a similar issue in the past with qualify in general regarding TCP/TLS devices, so I ended disabling qualify on those peers and I haven't tested it recently. With that said, from a design standpoint, I don't see why we need to qualify TCP/TLS peers to begin with.


By: Dave Hawkes (hevad) 2009-12-10 13:56:46.000-0600

Just to add the easiest client to reproduce this is with X-Lite V3 with transport set to TCP and Topology "IP Address" set to "Use local IP address".

The problem appears to occur when the SIP client listens on a different port to that which it sends on.
By: Elazar Broad (ebroad) 2009-12-10 14:36:34.000-0600

"The problem appears to occur when the SIP client listens on a different port to that which it sends on. "

Which is fine since Asterisk is supposed to use the existing connection to send the OPTIONS message. Qualify merely lets Asterisk know that the peer is still functional, which is why your inbound calls are failing. Asterisk probably lists the peer as UNREACHABLE because the attempt to send the message fails. What happens if you disable qualify on the peer?
By: Dave Hawkes (hevad) 2009-12-10 14:52:34.000-0600

If I disable qualify then the peer is unable to receive calls and dialling it just produces no ringing tone or anything. It does not even reject the call...


By: Dave Hawkes (hevad) 2009-12-10 14:54:02.000-0600

Also note that from the log the OPTIONS message is NOT being sent on the existing connection but the port reported by the peer, which is different from the send port of the peer.


By: Elazar Broad (ebroad) 2009-12-10 15:05:20.000-0600

So Asterisk is using the port listed in the peers Contact header?
By: Dave Hawkes (hevad) 2009-12-10 15:23:05.000-0600

Yes, here is the relevant contact and log extracts, note "illegal seek" error at end of log:

* Name       : 203
 Nat          : RFC3581
 ToHost       : 192.168.16.158
 Addr->IP     : 192.168.16.158 Port 19820
 Defaddr->IP  : 0.0.0.0 Port 5060
 Transport    : TCP
 Status       : Unmonitored
 Useragent    : X-Lite release 1103k stamp 53621
 Reg. Contact : sip:203@192.168.16.158:19820;rinstance=8b6bbc950decfb5f;transport=TCP

Log:

INVITE sip:203@192.168.16.158:19820;rinstance=8b6bbc950decfb5f;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.16.62:5060;branch=z9hG4bK74cbe763;rport
Max-Forwards: 70
From: "Dave Hawkes" <sip:223@a.cadlink.com>;tag=as7f6a447a
To: <sip:203@192.168.16.158:19820;rinstance=8b6bbc950decfb5f;transport=TCP>
Contact: <sip:223@192.168.16.62;transport=TCP>
Call-ID: 0de1333a796cf1927125175a16be5e94@a.cadlink.com
CSeq: 102 INVITE
User-Agent: Asterisk PBX SVN-branch-1.6.1-r233730M
Date: Thu, 10 Dec 2009 21:17:34 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 361

v=0
o=root 1036138110 1036138110 IN IP4 192.168.16.62
s=Asterisk PBX SVN-branch-1.6.1-r233730M
c=IN IP4 192.168.16.62
t=0 0
m=audio 13950 RTP/AVP 0 8 3 111 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
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

---
[Dec 10 16:17:34] WARNING[15393] chan_sip.c: sip_xmit of 0x1d86e2c0 (len 1036) to 192.168.16.158:19820 returned -2: Illegal seek
[Dec 10 16:17:34] VERBOSE[15393] app_dial.c:     -- Called 203
By: Elazar Broad (ebroad) 2009-12-10 15:36:37.000-0600

Can you post a debug of this UA registering. Thanks!
By: Dave Hawkes (hevad) 2009-12-10 15:48:54.000-0600

Here's the log:

[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:
<--- SIP read from TCP://192.168.16.158:15373 --->
REGISTER sip:ast2t.ottawa.cadlink.com SIP/2.0
Via: SIP/2.0/TCP 192.168.16.158:54282;branch=z9hG4bK-d8754z-4f102615d27d024d-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:203@192.168.16.158:54282;rinstance=4ed5c72adb5290dd;transport=TCP>
To: "Test"<sip:203@ast2t.ottawa.cadlink.com>
From: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=636b9213
Call-ID: NjEyYmM1Y2FkNmU2ZTk1YzNkMjRhNzBlNGEyMjc3YjU.
CSeq: 1 REGISTER
Expires: 3600
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
User-Agent: X-Lite release 1103k stamp 53621
Content-Length: 0


<------------->
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: --- (12 headers 0 lines) ---
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: Sending to 192.168.16.158 : 15373 (NAT)
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:
<--- Transmitting (no NAT) to 192.168.16.158:54282 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TCP 192.168.16.158:54282;branch=z9hG4bK-d8754z-4f102615d27d024d-1---d8754z-;received=192.168.16.158;rport=15373
From: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=636b9213
To: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=as76c94cf8
Call-ID: NjEyYmM1Y2FkNmU2ZTk1YzNkMjRhNzBlNGEyMjc3YjU.
CSeq: 1 REGISTER
Server: Asterisk PBX SVN-branch-1.6.1-r233730M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="ottawa.cadlink.com", nonce="1ae04ccb"
Content-Length: 0


<------------>
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: Scheduling destruction of SIP dialog 'NjEyYmM1Y2FkNmU2ZTk1YzNkMjRhNzBlNGEyMjc3YjU.' in 32000 ms (Method: REGISTER)
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:
<--- SIP read from TCP://192.168.16.158:15373 --->
REGISTER sip:ast2t.ottawa.cadlink.com SIP/2.0
Via: SIP/2.0/TCP 192.168.16.158:54282;branch=z9hG4bK-d8754z-ec6f76615021f52f-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:203@192.168.16.158:54282;rinstance=4ed5c72adb5290dd;transport=TCP>
To: "Test"<sip:203@ast2t.ottawa.cadlink.com>
From: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=636b9213
Call-ID: NjEyYmM1Y2FkNmU2ZTk1YzNkMjRhNzBlNGEyMjc3YjU.
CSeq: 2 REGISTER
Expires: 3600
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
User-Agent: X-Lite release 1103k stamp 53621
Authorization: Digest username="203",realm="ottawa.cadlink.com",nonce="1ae04ccb",uri="sip:ast2t.ottawa.cadlink.com",response="9ba223dcb8b69fb042bf70f13bd01dd7",algorithm=MD5
Content-Length: 0


<------------->
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: --- (13 headers 0 lines) ---
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: Sending to 192.168.16.158 : 54282 (no NAT)
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:     -- Registered SIP '203' at 192.168.16.158 port 54282
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.16.158:54282:
OPTIONS sip:203@192.168.16.158:54282;rinstance=4ed5c72adb5290dd;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.16.62:5060;branch=z9hG4bK744a0c22;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@a.cadlink.com>;tag=as4072bc43
To: <sip:203@192.168.16.158:54282;rinstance=4ed5c72adb5290dd;transport=TCP>
Contact: <sip:Unknown@192.168.16.62;transport=TCP>
Call-ID: 554a05216000166d157b8bde63c28c95@a.cadlink.com
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX SVN-branch-1.6.1-r233730M
Date: Thu, 10 Dec 2009 21:44:00 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[Dec 10 16:44:00] WARNING[15565] chan_sip.c: sip_xmit of 0x1ce52e80 (len 648) to 192.168.16.158:54282 returned -2: Illegal seek
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:
<--- Transmitting (no NAT) to 192.168.16.158:54282 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.16.158:54282;branch=z9hG4bK-d8754z-ec6f76615021f52f-1---d8754z-;received=192.168.16.158;rport=15373
From: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=636b9213
To: "Test"<sip:203@ast2t.ottawa.cadlink.com>;tag=as76c94cf8
Call-ID: NjEyYmM1Y2FkNmU2ZTk1YzNkMjRhNzBlNGEyMjc3YjU.
CSeq: 2 REGISTER
Server: Asterisk PBX SVN-branch-1.6.1-r233730M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Expires: 3600
Contact: <sip:203@192.168.16.158:54282;rinstance=4ed5c72adb5290dd;transport=TCP>;expires=3600
Date: Thu, 10 Dec 2009 21:44:00 GMT
Content-Length: 0


<------------>
By: Elazar Broad (ebroad) 2009-12-17 11:58:54.000-0600

"
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c: Sending to 192.168.16.158 : 15373 (NAT)
[Dec 10 16:44:00] VERBOSE[15565] chan_sip.c:
<--- Transmitting (no NAT) to 192.168.16.158:54282 --->"

Now that's interesting...

Do you have nat=yes under general in sip.conf and nat=no under the peer definition?


By: Dave Hawkes (hevad) 2009-12-17 12:44:59.000-0600

Yes, I do. I assumed that the general "nat=yes" would only be active for a specific peer if it did not have it's own "nat" entry?

However it still doesn't work if I remove the "nat=yes" from the general section...


By: Elazar Broad (ebroad) 2009-12-17 12:51:52.000-0600

That is correct, and that's probably why it logged like that. Basically, nat=yes, Asterisk will use the rport header, if rport is not equal to anything then Asterisk will use the port that the UA sent from. When nat=no, Asterisk uses whatever is in the Contact header. AFAIK, I believe this is correct operation per the RFC(s). Can you check to see if X-Lite is indeed listening on the port that is specifies in the Contact header when NAT is disabled(both is Asterisk and in the UA)? Thanks!
By: Dave Hawkes (hevad) 2009-12-17 14:43:38.000-0600

X-Lite is listening on that port, but asterisk never sends any data to it even though it logs that it is.
By: Elazar Broad (ebroad) 2009-12-17 16:33:11.000-0600

Tested X-Lite 3.0 build 56013 on 1.6.1 r233730 and it seems to work fine. Dumb question, are you running any sort of local(software) firewall?
By: Dave Hawkes (hevad) 2009-12-18 08:12:33.000-0600

I have no firewall between them. Did you use TCP and disable NAT ("Use local IP address" in "Topology") in X-Lite.


By: Elazar Broad (ebroad) 2009-12-18 09:23:29.000-0600

Yes, NAT was disabled on both sides. I'm wondering if its an X-Lite bug, can you try their latest build? Unfortunately I cannot get the build that you are working with. Thanks!
By: Dave Hawkes (hevad) 2009-12-18 10:08:20.000-0600

I've tried the latest X-Lite V3 build and also V4 beta 2 and still get the same results. I also occasionally get the issue with Snom 360 phones.
By: Leif Madsen (lmadsen) 2011-07-26 14:34:09.150-0500

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch. For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

If this is still an issue, please open a new issue so it can be re-triaged appropriately. Thanks!