IP Phone not staying registered

General Help
1

We have an issue with one of our IP Phones becoming unregistered and it has to be rebooted to get back onto the PBX.

Our PBX is running in our office and this user is connecting from his home. This has worked fine up until recently. The only thing that has changed is that we moved our PBX into a Virtual Machine on our server. It’s a small company and we only have three active users, so we haven’t run into any issues so far with it running in a VM.

Two of us use softphones when working from home with no problems. The user that’s having problems uses a Nortel 2001 model IP phone. What will happen is that when we call him it goes straight to voice mail. I logged into the PBX console to check the status and his phone is unregistered. Once he reboots it’s fine. It happened once and he rebooted and we thought everything was fine, but it did it again today so there is an issue.

One thing he mentioned to me is that he has a timer on his cable modem to turn off for 2 min during the night and reboot. I would suspect that this is the culprit, but he’s been doing this for a long time and it’s only recently become an issue.

We’re running Trixbox CE 2.6.2.2, Asterisk 1.4.20

Any suggestions on where to look for the issue?

Thanks!

Here’s what was in the log this morning:

[Mar 5 04:02:02] VERBOSE[16384] logger.c: Asterisk Event Logger restarted
[Mar 5 04:02:02] VERBOSE[16384] logger.c: Asterisk Queue Logger restarted
[Mar 5 04:02:02] VERBOSE[16384] logger.c: – Remote UNIX connection disconnected
[Mar 5 07:16:32] VERBOSE[2399] logger.c: – Registered SIP ‘903’ at 71.76.220.163 port 5060 expires 3600
[Mar 5 07:16:32] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (70ms / 2000ms)
[Mar 5 07:32:36] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3055ms / 2000ms)
[Mar 5 07:32:47] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1054ms / 2000ms)
[Mar 5 07:43:53] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3058ms / 2000ms)
[Mar 5 07:44:04] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1050ms / 2000ms)
[Mar 5 07:48:07] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (2046ms / 2000ms)
[Mar 5 07:48:17] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (53ms / 2000ms)
[Mar 5 07:53:22] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (2052ms / 2000ms)
[Mar 5 07:53:32] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (67ms / 2000ms)
[Mar 5 07:57:36] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (2048ms / 2000ms)
[Mar 5 07:57:50] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 2048
[Mar 5 07:58:00] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (57ms / 2000ms)
[Mar 5 08:02:05] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3052ms / 2000ms)
[Mar 5 08:02:15] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (56ms / 2000ms)
[Mar 5 08:04:18] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3048ms / 2000ms)
[Mar 5 08:04:44] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 2044
[Mar 5 08:04:55] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (53ms / 2000ms)
[Mar 5 08:06:58] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (2045ms / 2000ms)
[Mar 5 08:07:08] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (53ms / 2000ms)
[Mar 5 08:08:11] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3046ms / 2000ms)
[Mar 5 08:08:22] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1047ms / 2000ms)
[Mar 5 08:09:26] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1047
[Mar 5 08:09:36] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (53ms / 2000ms)
[Mar 5 08:10:40] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 53
[Mar 5 08:10:50] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (58ms / 2000ms)
[Mar 5 08:13:54] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3050ms / 2000ms)
[Mar 5 08:14:04] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (56ms / 2000ms)
[Mar 5 08:16:08] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 62
[Mar 5 08:16:18] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (55ms / 2000ms)
[Mar 5 08:17:22] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 55
[Mar 5 08:18:11] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (52ms / 2000ms)
[Mar 5 08:19:14] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3044ms / 2000ms)
[Mar 5 08:19:25] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (54ms / 2000ms)
[Mar 5 08:20:28] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3050ms / 2000ms)
[Mar 5 08:20:38] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (56ms / 2000ms)
[Mar 5 08:21:42] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 56
[Mar 5 08:21:52] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (58ms / 2000ms)
[Mar 5 08:23:57] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1049
[Mar 5 08:24:23] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 2046
[Mar 5 08:24:33] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (54ms / 2000ms)
[Mar 5 08:25:37] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 54
[Mar 5 08:26:25] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (55ms / 2000ms)
[Mar 5 08:28:28] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (3047ms / 2000ms)
[Mar 5 08:28:42] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 3047
[Mar 5 08:28:52] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (55ms / 2000ms)
[Mar 5 08:32:56] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 57
[Mar 5 08:33:20] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1046ms / 2000ms)
[Mar 5 08:34:24] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1046
[Mar 5 08:35:40] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (54ms / 2000ms)
[Mar 5 08:37:45] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1053
[Mar 5 08:38:11] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 2049
[Mar 5 08:38:21] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (51ms / 2000ms)
[Mar 5 08:39:23] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Lagged. (2047ms / 2000ms)
[Mar 5 08:39:34] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1043ms / 2000ms)
[Mar 5 08:40:38] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1043
[Mar 5 08:40:49] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1045ms / 2000ms)
[Mar 5 08:41:53] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1045
[Mar 5 08:42:46] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1046ms / 2000ms)
[Mar 5 08:43:50] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1046
[Mar 5 08:44:43] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1057ms / 2000ms)
[Mar 5 08:45:47] NOTICE[2399] chan_sip.c: Peer ‘903’ is now UNREACHABLE! Last qualify: 1057
[Mar 5 08:48:04] NOTICE[2399] chan_sip.c: Peer ‘903’ is now Reachable. (1046ms / 2000ms)

2

Phone systems virtualized don’t really work, they do for simple testing and very light loads but the most common issues are timing relaited. Audio not playing at the right speed (to fast or slow), registration windows being missed, recording issues.

The latency shown above is very poor. you need to take a look at some traceroutes between both locations (check both ways as data might not return using the same path it arrived on). Do it several times and check if there is either a huge change in numbers between times or different routes showing up.

If you have access to a linux box on each side try and use MTR instead as it’s a combo of traceroute and ping so will show issues better. It could be a third party backbone provider is having issues that just happened to show up at the same time.

But virtualizing the phone server is probably not helping. When you are local it’s not as noticeable as when it is remote.

If the phone has support for changing the time to start re-renewing to a bit sooner then the default it might help. On a Aastra phone it’s called sip registration renewal timer and it defaults to 15 seconds. So when there is only 15 second left in the renewal window it starts to re-renew. For far away phones we changed it to 25 seconds and that stopped phones from not renewing properly.

1 Like
3

Does anyone know how to make a similar adjustment on Linksys phones? I have multiple remote phones suffering from this same problem. All local phones maintain registrations without problem, all remote phones cycle through the “is now Lagged”, “is now UNREACHABLE”, “is now Reachable” problem. I’m having problems with dropped calls on these remote phones as well, and I suspect this is a related issue. Thanks in advance for any advice!