[Home]

Summary:ASTERISK-14870: Asterisk does not use the “expires=” from the SIP contact header during registration
Reporter:tpsast (tpsast)Labels:
Date Opened:2009-09-22 20:36:53Date Closed:2013-02-23 22:26:34.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Registration
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 1.6.1.7-rc1_SIP_debug.txt
( 1) 1.6.1.7-rc1_SIP_debug_console.txt
Description:When registering against a SIP provider, the reply from the registrar (SIP 200 OK message) includes an “expires =” in the SIP contact header, but Asterisk always use the “defaultexpiry” value instead.

Example:
------------
Asterisk sends “Expires: 3600” when register, but if the registrar replies with “expires=3170” in the contact header, then Asterisk always scheduling for a reregistration in 3585 s. anyway, and therefore the registration expires before Asterisk sends a reregister.

I have tested with Asterisk versions: 1.6.0.5, 1.6.0.3-rc1, 1.6.0.9, 1.6.1-beta4, 1.6.1.0, 1.6.1.1, 1.6.0.13, 1.6.1.4, 1.6.1.5, 1.6.1.6, 1.6.1.7-rc1 and SVN revision: 219891 (Asterisk SVN-branch-1.6.1-r219820).
The problem seems to exist in all above versions.

With Asterisk 1.6.2.0-beta3, beta4, rc1 and rc2 the registration doesn’t work at all.
SIP/2.0 403 Forbidden
(WARNING[3584]: chan_sip.c:17273 handle_response_register: Forbidden - wrong password on authentication for REGISTER …)
;I will attach the debug output for the 1.6.2.0 registration problem in a new issue!

Asterisk sip settings:
---------------------------
Global Signalling Settings:
----------------------------------
Reg. min duration: 60 secs
Reg. max duration: 4000 secs
Reg. default duration: 3600 secs

Register in sip.conf:
-------------------------
[sip-trunk]
type=peer
callbackextension=extension
defaultuser=xxxxxxxxxx
fromuser= xxxxxxxxxx
secret=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Comments:By: Elazar Broad (ebroad) 2009-10-15 11:27:10

Regarding failed registrations in 1.6.2x, take a look at https://issues.asterisk.org/view.php?id=15943
By: tpsast (tpsast) 2009-10-19 10:29:42

The registration issue in 1.6.2.0 that I mention above has already been resolved!

The registration against a SIP-provider works in 1.6.2.0 with the option “secret” after the issue: 15943 were resolved.

When using the option “remotesecret” for registration in 1.6.2.0, the option “secret” is also needed for outgoing calls.

ebroad, I’m the one who reported the issue: 15943.


By: Elazar Broad (ebroad) 2009-10-19 10:51:07

<snip>ebroad, I’m the one who reported the issue: 15943.</snip>
Doh, my bad :)
By: Chris Walton (crjw) 2010-04-25 21:21:45

I have the same "expiry" problem with 1.6.0.1 and the latest trunk.

I can pass a recommended expiration time to my SIP provider when registering.
This can be done by setting "defaultexpiry" or appending an expiry to the end of a registration declaration.
e.g.
defaultexpiry=90
OR
register => xxxxxxxxxxx:xxxxxxxx:xxxx@xxxx.xxxxxx.com/xxxxxxxxxxxx~90

Using either method, if I specify a value of 90 seconds or over, my SIP provider insists on using an expiry of 89 seconds.  That's OK.
If I specify a value of less than 90, my SIP provider insists on using an expiry of 1 second less than what I have requested.  That's OK too.

This would be fine, except that my SIP provider specifies the expiry in the "Contact" and "Contact Binding" fields which Asterisk appears to ignore.
Asterisk always wants to register exactly 15 seconds prior to the value of "defaultexpiry"

"defaultexpiry" has a default of 120.
Thus if I append a value of 90 to the registration string but do not explicitly define defaultexpiry, the following happens.
1. Asterisk sends a register request with a requested expiry time of 90 seconds.
2. SIP provider sends back a value of 89 in the "Contact" and "Contact Binding" fields.
3. Calls placed within 89 seconds will succeed.
3. Calls placed after 89 seconds will fail.
4. At 105 seconds after the initial registration (120-15), Asterisk will re-register.
5. Cycle repeats.
By: tpsast (tpsast) 2010-08-25 08:36:02

This issue that probably exists in all previous releases, also exists in Asterisk 1.8.0-beta3 and -beta4.

SIP/2.0 200 OK
…………
Contact:sip:uxxxxxxxx@ax.xx.xxx.xxx:5061;expires=3283

NOTICE[3608]: chan_sip.c:19396 handle_response_register: Outbound Registration: Expiry for bxx.xxx.xx.xx is 3600 sec (Scheduling reregistration in 3585 s)
By: Matt Jordan (mjordan) 2013-02-23 22:25:48.824-0600

So, this issue is rather old, but - there actually isn't a bug here.

First, {{chan_sip}} does not support multiple contacts. When it sends a register request to an external registrar, it appends a Contact header with the contact corresponding to its registration. So a registration of:

{noformat}
register => asterisk@registrar.com
{noformat}

will have a contact header of {{ <sip:s@[local_ip]:5060> }}.

If you specify a specific extension to contact, then the contact header will use that:

{noformat}
register => asterisk@registrar.com/1234
{noformat}

will have a contact header of {{ <sip:1234@[local_ip]:5060> }}.

So how does this map to the response?

RFC 3261 states that the 200 OK response to a REGISTER request MUST contain the Contact headers from the request with the expiry that the registrar decided upon. Since we only support a single Contact header, we search through the Contact headers in the response for our Contact header. If we find it, we parse out the expiry; if not, we use what our default was.

The key here is that we take our Contact header that we sent out and look for a Contact header that contains *at least* that value (that is, a substring match). If it differs, we won't use it.

The following log from SVN 1.8 shows this working:

{noformat}
[Feb 23 22:14:55] VERBOSE[522] chan_sip.c: Retransmitting #1 (NAT) to 127.0.0.1:5062:
REGISTER sip:127.0.0.1:5062 SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK3e26585c;rport
Max-Forwards: 70
From: <sip:asterisk@127.0.0.1>;tag=as40b4a36d
To: <sip:asterisk@127.0.0.1>
Call-ID: 5f707f217a4b90300a384fd735187226@10.24.251.166
CSeq: 102 REGISTER
User-Agent: Asterisk PBX SVN-branch-1.8-r381847
Expires: 120
Contact: <sip:1234@127.0.0.1:5060>
Content-Length: 0


---
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 127.0.0.1:5062
[Feb 23 22:14:55] VERBOSE[522] chan_sip.c:
<--- SIP read from UDP:127.0.0.1:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK3e26585c;rport
From: <sip:asterisk@127.0.0.1>;tag=as40b4a36d
To: <sip:asterisk@127.0.0.1>;tag=542SIPpTag011
Call-ID: 5f707f217a4b90300a384fd735187226@10.24.251.166
CSeq: 102 REGISTER
Contact: <sip:1234@127.0.0.1:5060>;expires=90
Content-Type: application/sdp
Content-Length: 0

<------------->
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  0 [ 14]: SIP/2.0 200 OK
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  1 [ 60]: Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK3e26585c;rport
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  2 [ 45]: From: <sip:asterisk@127.0.0.1>;tag=as40b4a36d
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  3 [ 46]: To: <sip:asterisk@127.0.0.1>;tag=542SIPpTag011
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  4 [ 55]: Call-ID: 5f707f217a4b90300a384fd735187226@10.24.251.166
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  5 [ 18]: CSeq: 102 REGISTER
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  6 [ 45]: Contact: <sip:1234@127.0.0.1:5060>;expires=90
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  7 [ 29]: Content-Type: application/sdp
[Feb 23 22:14:55] DEBUG[522] chan_sip.c:  Header  8 [ 17]: Content-Length: 0
[Feb 23 22:14:55] VERBOSE[522] chan_sip.c: --- (9 headers 0 lines) ---
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: = Looking for  Call ID: 5f707f217a4b90300a384fd735187226@10.24.251.166 (Checking To) --From tag as40b4a36d --To-tag 542SIPpTag011  
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: Stopping retransmission on '5f707f217a4b90300a384fd735187226@10.24.251.166' of Request 102: Match Found
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: Registration successful
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: Cancelling timeout 2
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: SIP Registry 127.0.0.1: refcount now 2
[Feb 23 22:14:55] DEBUG[522] chan_sip.c: SIP Registry 127.0.0.1: refcount now 1
[Feb 23 22:14:55] VERBOSE[522] chan_sip.c: Scheduling destruction of SIP dialog '5f707f217a4b90300a384fd735187226@10.24.251.166' in 32000 ms (Method: REGISTER)
[Feb 23 22:14:55] NOTICE[522] chan_sip.c: Outbound Registration: Expiry for 127.0.0.1 is 90 sec (Scheduling reregistration in 75 s)
{noformat}

This code is pretty ancient. As in, r5841 by kpfleming :-)  So it's actually been working for quite some time.

So what happened in the log attached to this issue?

Well, compare the request and response contact headers:

*Our Request*:
{noformat}
[Sep 22 22:33:11] DEBUG[3602] chan_sip.c:  Header 10 [ 40]: Contact: <sip:uxxxxxxxxx@ax.xx.xxx.xxx>
{noformat}

*Registrar Response*:
{noformat}
[Sep 22 22:33:11] DEBUG[3602] chan_sip.c:  Header  1 [ 50]: Contact:sip:uxxxxxxxxx@ax.xx.xxx.xxx;expires=3170
{noformat}

The registrar response is missing {{<}} and {{>}}. We care about those. (The lack of a space after the header's {{:}} may or may not be problematic as well).

Closing this out, but hopefully this will be helpful to anyone else who runs into this problem.