[reSIProcate] Issue with Registration failure

[John Jurrius]

Hi!

 

I am experiencing a SIP server problem with the handling of client
registration messages.  The problem is intermittent and random but happens
at least once an hour in our current configuration.  This current
configuration consists of 56 registered SIP endpoint with active sessions
between most of the clients.  The clients are set to register every 60s as
the registration state is used to determine when the client device is no
longer accessible.  The fundamental problem is that the registration timer
is expiring however it is not because the re-registration message was not
received but rather the server is not properly handling the re-registration
message.  The situation is evidenced and documented with Wireshark traces
and manifests itself as 3 different but recurring problems.

 

1)      The re-registration message is ignored.  The client then repeatedly
sends the re-registration message but eventually gives up.  One minute later
when the next re-registration is sent, it is replied to correctly and all is
okay again.

2)      The re-registration message is responded to but send to the wrong
user ID.  More specifically the OK message is sent to the correct IP and
port however if one looks at the User ID in the message it does not
correspond to the re-registration request.  The client then sends repeated
re-registration message all of which are responded to with the same
incorrect reply.  When the next re-registration message is received 1 minute
later the re-registration is responded to correctly.  It should be noted
that the incorrect User ID in the reply appears to always be the User ID of
another client on the same physical device (of the 56 endpoint 28 are paired
clients on 14 SIP devices).

3)      The re-registration message is responded to but the server requests
proxy authentication.  However the registration message clearly has the
correct authentication.  As noted in the previous item, the client sends
repeated re-registration messages all of which are responded to with a
request for proxy authentication and as before one minute later all is okay
again. 

 

I have worked around the problem by ignoring the first registration failure
however clearly this is a problem that is better understood and fixed rather
than ignored.  The problem was first observed using v1.7 and under the
assumption it might have been a known and corrected issue, the SIP engine
was updated to 1.8.5 however the problem remains.   

 

Following is a Wireshark summary excerpt for case 2:

 

47           2012-09-05 18:10:20.382696000  10.73.179.3
193.43.93.138     SIP          678         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

48           2012-09-05 18:10:20.408600000  193.43.93.138     10.73.179.3
SIP          332         Status: 200 OK    (1 bindings)
... User ID 1006

49           2012-09-05 18:10:22.373514000  10.73.179.3
193.43.93.138     SIP          686         Request: REGISTER
sip:193.43.93.138              ... User ID 1005

50           2012-09-05 18:10:22.405592000  193.43.93.138     10.73.179.3
SIP          340         Status: 200 OK    (1 bindings)
... User ID 1005

51           2012-09-05 18:11:18.035010000  10.73.179.3
193.43.93.138     SIP          672         Request: REGISTER
sip:193.43.93.138              ... User ID 1005

52           2012-09-05 18:11:18.046625000  10.73.179.3
193.43.93.138     SIP          671         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

53           2012-09-05 18:11:18.046970000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

 

... All good up until this point

 

54           2012-09-05 18:11:18.065177000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

 

... This should have been the reply for User ID 1006 but the same reply that
was sent to 1005 is resent to 1006.  

 

55           2012-09-05 18:11:18.532743000  10.73.179.3
193.43.93.138     SIP          671         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

56           2012-09-05 18:11:18.564685000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

 

... This process repeats until the clients give up waiting for the correct
response.

 

57           2012-09-05 18:11:19.532823000  10.73.179.3
193.43.93.138     SIP          671         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

58           2012-09-05 18:11:19.561102000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

59           2012-09-05 18:11:21.283209000  10.73.179.3
193.43.93.138     SIP          671         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

60           2012-09-05 18:11:21.310273000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

61           2012-09-05 18:11:25.273572000  10.73.179.3
193.43.93.138     SIP          671         Request: REGISTER
sip:193.43.93.138              ... User ID 1006

62           2012-09-05 18:11:25.304686000  193.43.93.138     10.73.179.3
SIP          326         Status: 200 OK    (1 bindings)
... User ID 1005

 

... One minute later the client registers again, it is successful, and all
continues normally.

 

Before I spend any more time on this I am interested to know if this problem
sounds familiar to anyone.   

 

Many thanks for your time and especially thanks to the authors for an
absolutely fabulous library.

 

John

 

 

 

 

 

 

 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://list.resiprocate.org/pipermail/resiprocate-devel/attachments/20120906/14b05f17/attachment.htm>