[Spce-user] registration problems after upgrade to 2.6
Joan Cifre (ibred)
jcifre at ib-red.com
Fri Jan 4 15:14:25 EST 2013
Hi all,
definitively there is a problem between Cisco SPA112 and Cisco PAP2 ATAs
and the 2.6 version of Sipwise. Before the upgrade there were no
problems of registration. Now we have many devices (just these Cisco
devices) that fail to register. After many trials, registration is done,
but it can be after 5 or 50 minuts. The same ocurs with registration or
with reinvite.
I don't know if this is a problem with ATAs or with Sipwise, but sure
that before upgrade the problem didn't exist. In the last log I send,
you can see how a ATA tries to register during many times and after
about 10 minutes, it register (se below this mail). Many messages with
"Authentication failed - no credentials" and after 10 minutes register
is done. Also the same occurs with re-invites after register expires.
We have a big problem so many of our phones are these ATAs. In the graph
I sent you can see the problem starts the day of the update (many
registrations failed so there is not a fixed number of registered
devices). I could reboot the sipwise server but I'm afraid many ATAs try
then to register and they can't.
Any help would be appreciated. I can send you the logs you need. We are
considering to downgrade to 2.5 but I don't know if this is easy to do.
Jan 4 14:04:02 sipwise /usr/sbin/kamailio[1996]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:04:02 sipwise /usr/sbin/kamailio[1996]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:04:32 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:04:32 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:02 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:02 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:33 sipwise /usr/sbin/kamailio[2004]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:33 sipwise /usr/sbin/kamailio[2004]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:33 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:05:33 sipwise /usr/sbin/kamailio[1995]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:06:03 sipwise /usr/sbin/kamailio[2006]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:06:03 sipwise /usr/sbin/kamailio[2006]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:06:34 sipwise /usr/sbin/kamailio[2006]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:06:34 sipwise /usr/sbin/kamailio[2006]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:05 sipwise /usr/sbin/kamailio[2004]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:05 sipwise /usr/sbin/kamailio[2004]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Authentication failed, stale nonce - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1995]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[1996]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[2006]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:35 sipwise /usr/sbin/kamailio[2006]: INFO: <script>:
Authentication failed, no credentials - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1998]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1998]: INFO: <script>: Load
prefs for uuid 'a1ceef67-5b37-4c36-99f5-5441c31a3b5e' -
R=sip:voip.ibreddigital.net ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1998]: INFO: <script>: IP
authorization not provisioned, allow registration -
R=sip:voip.ibreddigital.net ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=REGISTER R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net
T=sip:n971944148 at voip.ibreddigital.net IP=141.105.104.20:1026
(127.0.0.1:5060) ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: Load
prefs for uuid 'a1ceef67-5b37-4c36-99f5-5441c31a3b5e' -
R=sip:voip.ibreddigital.net ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: IP
authorization not provisioned, allow registration -
R=sip:voip.ibreddigital.net ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1998]: INFO: <script>:
Registration ok - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Registration ok - R=sip:voip.ibreddigital.net
ID=1103f5bc-e8cd5b0a at 192.168.10.59
Jan 4 14:07:50 sipwise /usr/sbin/kamailio[2004]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:50 sipwise /usr/sbin/kamailio[2004]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:07:50 sipwise /usr/sbin/kamailio[2004]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:05 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:05 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:05 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:20 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:20 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:20 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:36 sipwise /usr/sbin/kamailio[1997]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:36 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:51 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:51 sipwise /usr/sbin/kamailio[1995]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:08:51 sipwise /usr/sbin/kamailio[1995]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:06 sipwise /usr/sbin/kamailio[1998]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:06 sipwise /usr/sbin/kamailio[1998]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:06 sipwise /usr/sbin/kamailio[1998]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:21 sipwise /usr/sbin/kamailio[1996]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:21 sipwise /usr/sbin/kamailio[1996]: INFO: <script>:
Handling RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:21 sipwise /usr/sbin/kamailio[1996]: INFO: <script>: Failed
to handle RLS notification - R=sip:voip.ibreddigital.net
ID=7cf9c13d-5051a5b5 at 192.168.10.59
Jan 4 14:09:21 sipwise /usr/sbin/kamailio[2004]: INFO: <script>: New
request - M=NOTIFY R=sip:voip.ibreddigital.net
F=sip:n971944148 at voip.ibreddigital.net T=sip:voip.ibreddigital.net
IP=141.105.104.20:1026 (127.0.0.1:5060) ID=7cf9c13d-5051a5b5 at 192.168.10.59
El 04/01/2013 14:28, Joan Cifre (ibred) escribió:
> Hi Lorenzo,
> the problem is that this does not happens always. Now I've configured
> a registration expiry time of 60 seconds, and ir does the reinvite
> with no problem. It's annoying!
>
>
> El 04/01/2013 14:13, Lorenzo Mangani escribió:
>> Joan,
>> Apparently so. Is there any chance you could get us an actual SIP
>> trace? The log will once again only provide the tail, not the head of
>> this issue.
>> Seeing the re-invite should clarify the condition you're suffering.
>> You can possibly set one of the affected ATAs with a short
>> registration span to simulate and replicate/capture it faster.
>> Best,
>> Lorenzo
>>
>> On Fri, Jan 4, 2013 at 2:06 PM, Joan Cifre (ibred) <jcifre at ib-red.com
>> <mailto:jcifre at ib-red.com>> wrote:
>>
>> Hello,
>> now I have located a SPA112 that doesn't register( it tries every
>> 30 secs), with this log messages. It tells "no credentials" but
>> does it means that ATa does not send the password????
>>
>> Jan 4 14:03:02 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
>> New request - M=REGISTER R=sip:voip.ibreddigital.net
>> <http://voip.ibreddigital.net>
>> F=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> T=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> IP=141.105.104.20:1026 <http://141.105.104.20:1026>
>> (127.0.0.1:5060 <http://127.0.0.1:5060>)
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>> Jan 4 14:03:02 sipwise /usr/sbin/kamailio[1997]: INFO: <script>:
>> Authentication failed, no credentials -
>> R=sip:voip.ibreddigital.net <http://voip.ibreddigital.net>
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>> Jan 4 14:03:32 sipwise /usr/sbin/kamailio[1998]: INFO: <script>:
>> New request - M=REGISTER R=sip:voip.ibreddigital.net
>> <http://voip.ibreddigital.net>
>> F=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> T=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> IP=141.105.104.20:1026 <http://141.105.104.20:1026>
>> (127.0.0.1:5060 <http://127.0.0.1:5060>)
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>> Jan 4 14:03:32 sipwise /usr/sbin/kamailio[1998]: INFO: <script>:
>> Authentication failed, no credentials -
>> R=sip:voip.ibreddigital.net <http://voip.ibreddigital.net>
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>> Jan 4 14:04:02 sipwise /usr/sbin/kamailio[1996]: INFO: <script>:
>> New request - M=REGISTER R=sip:voip.ibreddigital.net
>> <http://voip.ibreddigital.net>
>> F=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> T=sip:n971944148 at voip.ibreddigital.net
>> <mailto:sip%3An971944148 at voip.ibreddigital.net>
>> IP=141.105.104.20:1026 <http://141.105.104.20:1026>
>> (127.0.0.1:5060 <http://127.0.0.1:5060>)
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>> Jan 4 14:04:02 sipwise /usr/sbin/kamailio[1996]: INFO: <script>:
>> Authentication failed, no credentials -
>> R=sip:voip.ibreddigital.net <http://voip.ibreddigital.net>
>> ID=1103f5bc-e8cd5b0a at 192.168.10.59
>> <mailto:1103f5bc-e8cd5b0a at 192.168.10.59>
>>
>>
>> El 04/01/2013 10:19, Andrew Pogrebennyk escribió:
>>
>> Hi Joan,
>>
>> this is not related to the registration problem. You should fine
>> fragment of the log where ATA sends a re-register.
>>
>> On 01/04/2013 09:57 AM, Joan Cifre (ibred) wrote:
>>
>> I don't know if this can help, but I'm getting many
>> messages about RLS
>> notification failures in the log, like this. Maybe it's
>> not important,
>> really I don't know, but I don't remember I was getting
>> these messages
>> before upgrade.
>>
>> Jan 3 23:59:14 sipwise /usr/sbin/kamailio[2006]: INFO:
>> <script>:
>> Handling RLS notification - R=sip:voip.ibreddigital.net
>> <http://voip.ibreddigital.net>
>> ID=f7a35131-c72a2c49 at 192.168.1.200
>> <mailto:f7a35131-c72a2c49 at 192.168.1.200>
>> Jan 3 23:59:14 sipwise /usr/sbin/kamailio[2006]: ERROR: rls
>> [resource_notify.c:572]: to tag value not parsed
>>
>>
>>
>>
>>
>> --
>>
>>
>> Lorenzo Mangani
>>
>> HOMER DEV TEAM
>> QXIP - Network Engineering
>>
>
>
>
> _______________________________________________
> Spce-user mailing list
> Spce-user at lists.sipwise.com
> http://lists.sipwise.com/listinfo/spce-user
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/mailman/private/spce-user_lists.sipwise.com/attachments/20130104/6a4d0dba/attachment.html>
More information about the Spce-user
mailing list