[asterisk-bugs] [Asterisk 0018119]: Reregistration with small (20 sec) Expiry fails

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=18119 
====================================================================== 
Reported By:                fabled
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   18119
Category:                   Channels/chan_sip/Registration
Reproducibility:            always
Severity:                   major
Priority:                   normal
Status:                     new
Asterisk Version:           1.6.2.13 
JIRA:                        
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2010-10-12 03:36 CDT
Last Modified:              2010-10-12 05:18 CDT
====================================================================== 
Summary:                    Reregistration with small (20 sec) Expiry fails
Description: 
Apparently the following happens:

1. Asterisk register succesfully, 20s Expiry -> reregister in 15s
   - destruction of sip_pvt scheduled with timeout > 15s
2. When reregister triggers:
   - sip_registry->call is NULL, because of successful registration
   - transmit_register builds new sip_pvt with same call ID as
https://issues.asterisk.org/view.php?id=1
3. Server replies
4. Asterisk rejects registration reply because:
   - the sip_pvt from https://issues.asterisk.org/view.php?id=1 has not been yet
destroyed
   - and asterisk routes the reply to sip_pvt from
https://issues.asterisk.org/view.php?id=1 due to call-id
conflict
   - this is indicated by log messages such as:
[Oct 11 21:34:26] DEBUG[16751] chan_sip.c: Ignoring out of order
response 476 (expecting 475)
   - until we get timer_t1*64 ms later the message
[Oct 11 21:34:42] DEBUG[16751] chan_sip.c: Auto destroying SIP dialog
'768de833447ed7e558ee6dcc44f94821 at ...'
   - immediately after which the registration succeeds again

Olle suggested on mailing list:
I think it clearly has to do with the t1 timer for
https://issues.asterisk.org/view.php?id=1. It propably hangs
around for more than 20 secs. We should set max
T1 for registry transactions to be the expiry time minus some small unit.

And yes, with default global_t1 the timeout would be around 30 seconds.
====================================================================== 

---------------------------------------------------------------------- 
 (0127858) fabled (reporter) - 2010-10-12 05:18
 https://issues.asterisk.org/view.php?id=18119#c127858 
---------------------------------------------------------------------- 
Sorry for not mentioning: Asterisk is the client sending SIP registration
messages out here.

Since the server (non-Asterisk) replies with 200 OK and small "expires" in
Contact header, we cannot possibly respond to reply anymore. My quick read
of RFC would indicate that it's OK for the server to send this small 20s
expires. Minimum expires setting is server-only apparently.

Asterisk is doing the correct thing according to RFC. The problem becomes
in the fact that there exists multiple sip_pvt for same Call-ID which
confuses asterisk internal message passing code.

It seems that Call-ID must match for the reregister to update binding
properly, so we have some options to fix this:
 1. Force sip_pvt of REGISTER to expire faster for small expires intervals
as suggested
 2. Fix registration code to reuse sip_pvt if it has not been expired yet
 3. Fix registration code to not delete sip_pvt at all and reuse it always 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2010-10-12 05:18 fabled         Note Added: 0127858                          
======================================================================