Solved: SPA112 Registration fails?

nvogelsang · ‎02-04-2015

Hi!

My SPA112(1.3.5 004p) fails to register in varying intervals. When restarting the device everything works fine and the registration works. After some time the Re-Registration starts to fail and sometime I get a registration failed even before the Re-Registration started. My SPA112 is behind a Netgear R7000 Router with SIP ALG deaktivated. I really tried everything including DMZ, Port Forwarding and deaktivating QOS and NAT Filter but it makes no difference. I also tried nearly all options with the SPA112. When registered Fax via T.38 works just fine!

I alredy made a detailed log file of the process via Slogsrv. This is what happens if registration Fails(XXX=personal Information):

SIP_tsClientEventProc(event: 4)
tryAltIp_delay() SIP_regTsEventProc(event: 4)
CC_eventProc(), event: CC_EV_SIG_REGISTER_FAILED(0x3B), lid: 0, par: 0, par2: (nil)
AUD_ccEventProc: event 59 vid 0 par 0x0 par2 0x0
SLIC_stopRing
SLIC_stopTone
[0]RegFail. Retry in 10
SIP_regTsEventProc(event: 32)
SIP_tsClientEventProc(event: 3)
[0]->XXX:5060(461)
NOTIFY sip:XXX SIP/2.0

Via: SIP/2.0/UDP 192.168.2.21:5060;branch=XXX

From: "XXX" <sip:XXX@XXX>;tag=XXX

To: <sip:XXX>

Call-ID: XXX@192.168.2.21

CSeq: 87 NOTIFY

Max-Forwards: 70

Contact: "XXX" <sip:XXX@XXX:5060;ref=XXX>

Event: keep-alive

User-Agent: Cisco/SPA112-1.3.5(004p)

Content-Length: 0

SIP_tsClientEventProc(event: 3)
[0]->XXX:5060(461)
NOTIFY sip:XXX SIP/2.0

Via: SIP/2.0/UDP 192.168.2.21:5060;branch=XXX

From: "XXX" <sip:XXX@XXX>;tag=XXX

To: <sip:XXX>

Call-ID: XXX@192.168.2.21

CSeq: 87 NOTIFY

Max-Forwards: 70

Contact: "XXX" <sip:XXX@XXX:5060;ref=XXX>

Event: keep-alive

User-Agent: Cisco/SPA112-1.3.5(004p)

Content-Length: 0

Dan Lukes · ‎02-05-2015

There is no password.

The log starts with REGISTER attempt (CSeq: 43236 REGISTER). Such request has not been responded by server. It has been retried several time until timeout. There is also unresponded NOTIFY at the same time (CSeq: 1 NOTIFY).

Same for REGISTER requests Cseqs 43238-43263.

It's not possible to decide at this level it's network issue (requests are lost on it's path to PBX / responses are lost on their path to you) or PBX issue (the server just not responds the requests).

Verify configuration of Register Expires and Reg Retry Intvl values. They should not be set to lower value than requested by your provider or an anti-DoS filter on the PBX may consider your IP blocked. If there is no requirement from your's provider, the 60 / 30 seconds should be considered minimum.

Well, lets go back to log analysis.

First succesful REGISTER is Cseq 43264/43265. NOTIFY Cseq 15 seems to be responded as well. At this time everything seems to work. Up to last succesful REGISTER Cseq 43273.

With Register Expires set to 60 it mean there has been about 10 minutes of succesful registration.

Starting at 43274 the REGISTER requests become unresponded again up to 43279. E.g. about 3 minutes of blackout.

Very important is REGISTER request 43286. It has been responded by "500 Server Error". It may reveal that there is an issue on PBX. If course, it may be an unimportant transient issue as well.

The rest of log reveal nothing important. periods of succesful registration are followed by periods of unresponded registration and so on.

So final conclusion is - either network issue or PBX issue.

I'm no Netgear expert, so I can't advice how to debug network issue. You should ask Netgear experts instead. Note that "network issue" may not mean "Netgear issue". The destination server may not be reachable because of isue anywhere on network path.

According PBX issue, there has been one "Server error" response only. We should not overestimate it. But you can ask your PBX administrator of help. Not only because of this error. He can verity the REGISTER packets are arriving from you to him. So he can help you to verify full network path from you to the server (unidirectional) is broken or not.

Unfortunately, just phone's log doesn't allow more precise conclusions ...

View solution in original post

Dan Lukes · ‎02-05-2015

Unfortunately, the fragment of log you supplied is so short. We need to see fragment starting before a successful registration and ending past unsuccessful attempt of registration. We need to see both (e.g. successful and unsuccessful) REGISTER request and the reply from server as well.

The log needs to be complete, e.g. both syslog and debug messages. Debug level needs to be set to highest level possible.

nvogelsang · ‎02-05-2015

Hi! Thanks for your reply. Just uploaded a longer version of the log. Please let me know if it is possible to retrieve the password from this log so that I know if I have to change it.

Dan Lukes · ‎02-05-2015

There is no password.

The log starts with REGISTER attempt (CSeq: 43236 REGISTER). Such request has not been responded by server. It has been retried several time until timeout. There is also unresponded NOTIFY at the same time (CSeq: 1 NOTIFY).

Same for REGISTER requests Cseqs 43238-43263.

It's not possible to decide at this level it's network issue (requests are lost on it's path to PBX / responses are lost on their path to you) or PBX issue (the server just not responds the requests).

Verify configuration of Register Expires and Reg Retry Intvl values. They should not be set to lower value than requested by your provider or an anti-DoS filter on the PBX may consider your IP blocked. If there is no requirement from your's provider, the 60 / 30 seconds should be considered minimum.

Well, lets go back to log analysis.

First succesful REGISTER is Cseq 43264/43265. NOTIFY Cseq 15 seems to be responded as well. At this time everything seems to work. Up to last succesful REGISTER Cseq 43273.

With Register Expires set to 60 it mean there has been about 10 minutes of succesful registration.

Starting at 43274 the REGISTER requests become unresponded again up to 43279. E.g. about 3 minutes of blackout.

Very important is REGISTER request 43286. It has been responded by "500 Server Error". It may reveal that there is an issue on PBX. If course, it may be an unimportant transient issue as well.

The rest of log reveal nothing important. periods of succesful registration are followed by periods of unresponded registration and so on.

So final conclusion is - either network issue or PBX issue.

I'm no Netgear expert, so I can't advice how to debug network issue. You should ask Netgear experts instead. Note that "network issue" may not mean "Netgear issue". The destination server may not be reachable because of isue anywhere on network path.

According PBX issue, there has been one "Server error" response only. We should not overestimate it. But you can ask your PBX administrator of help. Not only because of this error. He can verity the REGISTER packets are arriving from you to him. So he can help you to verify full network path from you to the server (unidirectional) is broken or not.

Unfortunately, just phone's log doesn't allow more precise conclusions ...

nvogelsang · ‎02-05-2015

Hi! Thanks for this detailed answer. Under Sip I have the following settings:

Reg Min Expires: 1 -> changed it to 60 now

Reg Retry Intvl: 10 -> changed it to 30 now

Reg Retry Random Delay: 0

Reg Retry Intvl Cap: 0

ReINVITE Expires: 30

Reg Max Expires: 600

Reg Retry Long Intvl: 1200

Reg Retry Long Radom Delay: 0

Under Line 1 my config is:

Proxy Fallback Intvl: 60 --> tried it with 300 ...didn't help

Register Expires: 60 --> tried it with 300 ...didn't help

nvogelsang · ‎02-05-2015

Found the issue but sadly not the solution. The SPA112 was not directly connected to the Router but over a WIFI Bridge Device. When I tried connecting it via ethernet cable everything works just fine and the registration is always OK.

Now I tried every possible WIFI setting for the Bridge and the Wifi Router but nothing seems to work. There are absolutely no packet losses between the the wired network and the SPA112 connected through the WIFI Bridge. Average Ping is 1ms.

As I wrote above Fax over T.38 with the SPA connected over WIFI was never a problem when registered.

Do you know any setting on the SPA112 or the providers Asterisk which can cause this issue when using WIFI. Maybe some kind of timeout variable which can be set?

Dan Lukes · ‎02-05-2015

Bridge, including the Wifi one, is L2 (Layer 2) device. It should be transparent to operations on upper layers, e.g. L3 (e.g. IP packet) or L4 (e.g. UDP datagram) used by SPA112 during SIP communication.

It should not be possible to detect it's presence of L2 device on the network even if you wish for it.

It seems that your bridge is not transparent and it affect the communication by unknown means incompatible with SPA112 operation.

Unfortunately, we have no packet dump on L2 level so we have nothing to analyze here. We can make some hypothesis only.

Casual communication, e.g. SIP is UDP IP packet. It's protocol suitable to reach remote destinations, even with satelite hop on path. SIP timing is matter of hundreds of milliseconds or seconds. The SIP T1, the most short timeout in SIP word, is 500ms by default. Few milliseconds of delay introduced by WiFi bridge need not to be taken into consideration.

In advance, the SPA112 use ARP protocol. No IP (thus UDP thus SIP) communication is possible with no ARP working here. But the behavior observed seems not to allow us to expect issue here. In advance, ARP timeouts are matter of seconds. Again, miliseconds embedded by bridge need not to be considered.

There are absolutely no packet losses between the the wired network and the SPA112 connected through the WIFI Bridge. Average Ping is 1ms.

Sure ? How you measured it ? Using ping ? It's unreliable method for such kind of analysis. Ping use ICMP protocol and packets are very short.

If you are affected by so called "hidden node issue" on WiFi, the short packets have high probability to pass with no problem, but longer packet may be lost in transit at the same time.

And it's not only aspect that's may affect SIP packets different way that ICMP ping. There may be QoS related issues as well.

Even with full L2 dump it may not be easy to analyze it.

nvogelsang · ‎02-05-2015

Hi! Yes I was using ping to measure the latency. Installed a 5GHZ Bridge instead of the 2.4 GHZ ~1 hour ago. So far no failed registration.

Signal is weaker and ping is roughly the same. There are not that many 2.4GHz APs round here so I am able to find a free Channel but still....

There is no other 5GHZ AP in reach.

Dan Lukes · ‎02-05-2015

Well, despite we are unable to identify in full what's wrong with 2.4GHz wireless, it seems we can be sure the issue has been caused by wireless part of the path.

Identification of exact cause is not possible with information available (and it's outside my field somewhat).

Glad to hear it worked with 5GHz bridge now.

Rate useful advices. It will help others to found solution.

nvogelsang · ‎02-07-2015

Hi! Registration is still very stable with the ATA connected to the 5GHZ Bridge(~50% Signal strength). When analyzing the latency with Pingplotter it seems that the 2.4GHZ Bridge has a way higher jitter and packet loss...still 0% but there is some. With the 5GHZ Bridge I don't have any lost packets. This is still ICMP - Ping.Thanks for the help!

Dan Lukes · ‎02-07-2015

Th behavior observer on 2.4G bridge can't be explained by higher jitter or just few packets lost. There has been long sequences of unresponded register attempts.

But glad to hear you found acceptable solution of your issue.