Hello all, This may be a little long winded as i have already tried numerous things to fix this and will detail all.
Firstly, FreePBX version is 3.211.63-8 running Asterisk 11 at setup.
I have the same problem on 2 systems setup the same using same hardware.
What i am seeing is that every so often a phone will not ring for an incoming call. If i look into the CLI at this time i see
[2013-05-18 03:47:21] NOTICE[1821] chan_sip.c: Peer ‘106’ is now UNREACHABLE! Last qualify: 18
Followed (normally 10 seconds later by
[2013-05-18 03:47:31] NOTICE[1821] chan_sip.c: Peer ‘106’ is now Reachable. (20ms / 2000ms)
There are 6 SNOM 370 handset attached to the system and at some point most hours at some time they go offline and people cannot answer their phones and they don’t ring.
The phones are all plugged into a DLink DGS1210-10P switch and are running on VLAN 512. The phones then have a PC plugged into their PC port running in VLAN 1.
DHCP is running on the system and handed out on VLAN 512 successfully and phones provision on that VLAN.
Topology is:
VLAN 1 - 10.10.10.0 network (data and PC internet)
VLAN 512 - 192.168.2.0 network (phones only)
Eth0 is 10.10.10.1
Eth0.512 is 192.168.2.1
Eth1 is 192.168.1.1 (PBX traffic to internet on this connection - 1 x IAX trunk setup)
Gateway is only setup for 192.168.1.250 (modem attached directly to Eth1) tested by removing cable from Eth0 and still getting internet whereas if i remove cable from Eth1 i cannot get internet.
In /etc/resolve.conf i have:
nameserver=127.0.0.1
nameserver=192.168.1.250
QoS applied to give VLAN 512 higher priority
Firstly, it appears the add VLAN section of networking in sysadmin module only does half the job as it does not add the value vlan=yes to the setup and try as i might i cannot get a phone to autoprovision straight out of the box on that VLAN. i have to set VLAN 512 on the phone handset and tell settings server to be 192.168.2.1 then all works happily. When i use physical network cards on systems i don’t have this problem. (but that is a problem for another thread).
Troubleshooting already done:
Switch - replaced with newer version (still same model) all power saving turned off and negotiation manually set to 100Mbps on each port (as handsets only have 100Mb switch in them).
QoS settings turned on and off. Voice VLAN prioritization turned on and off.
FreePBX - check nat settings to Never
I am testing same setup on same system now using physical nics instead of VLANs to try and woork out if this is a FreePBX, Asterisk, VLAN or hardware error.
So far the problem has not recurred.
Below is from asterisk log full file from a couple days ago.
[2013-05-18 03:47:21] NOTICE[1821] chan_sip.c: Peer '106' is now UNREACHABLE! Last qualify: 18
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:47:21] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:47:31] NOTICE[1821] chan_sip.c: Peer '106' is now Reachable. (20ms / 2000ms)
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 106
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 102
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 105
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 101
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 103
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 104
[2013-05-18 03:47:31] NOTICE[1821] chan_sip.c: Peer '105' is now Lagged. (3692ms / 2000ms)
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:47:31] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:47:41] NOTICE[1821] chan_sip.c: Peer '105' is now Reachable. (18ms / 2000ms)
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 106
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 102
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 105
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 101
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 103
[2013-05-18 03:47:41] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Idle for Notify User 104
[2013-05-18 03:49:04] NOTICE[1821] chan_sip.c: Peer '102' is now UNREACHABLE! Last qualify: 18
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:49:04] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:49:13] NOTICE[1821] chan_sip.c: Peer '106' is now UNREACHABLE! Last qualify: 198
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 103 (queued)
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:49:13] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:49:15] NOTICE[1821] chan_sip.c: Peer '102' is now Reachable. (125ms / 2000ms)
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 102
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 105
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 101
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 104
[2013-05-18 03:49:15] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 106 (queued)
[2013-05-18 03:50:29] VERBOSE[1821] chan_sip.c: -- Registered SIP '106' at 192.168.2.169:5060
[2013-05-18 03:50:29] NOTICE[1821] chan_sip.c: Peer '106' is now Reachable. (54ms / 2000ms)
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 106 (queued)
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 105
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 101
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 103
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 104
[2013-05-18 03:50:29] VERBOSE[1698] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 102
[2013-05-18 03:50:51] NOTICE[1821] chan_sip.c: Peer '102' is now UNREACHABLE! Last qualify: 704
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103 (queued)
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 106 (queued)
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:50:51] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:51:03] NOTICE[1821] chan_sip.c: Peer '102' is now Reachable. (1734ms / 2000ms)
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 105
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 101
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 104
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 106 (queued)
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 102
[2013-05-18 03:51:03] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 106
[2013-05-18 03:52:07] NOTICE[1821] chan_sip.c: Peer '102' is now UNREACHABLE! Last qualify: 1734
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103 (queued)
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 106 (queued)
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:52:07] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:53:48] NOTICE[1821] chan_sip.c: Peer '101' is now Lagged. (2813ms / 2000ms)
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 105
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 101
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 103
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 104
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 102
[2013-05-18 03:53:48] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Unavailable for Notify User 106
[2013-05-18 03:53:58] NOTICE[1821] chan_sip.c: Peer '101' is now Reachable. (18ms / 2000ms)
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 105
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 101
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 103
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 104
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 106 (queued)
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 102 (queued)
[2013-05-18 03:53:58] VERBOSE[1698] chan_sip.c: == Extension Changed 101[ext-local] new state Idle for Notify User 106
[2013-05-18 03:54:14] NOTICE[1821] chan_sip.c: Peer '102' is now Reachable. (63ms / 2000ms)
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 105
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 101
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103 (queued)
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 103
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 104
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 106 (queued)
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 102 (queued)
[2013-05-18 03:54:14] VERBOSE[1698] chan_sip.c: == Extension Changed 102[ext-local] new state Idle for Notify User 106
[2013-05-18 04:08:46] NOTICE[1821] chan_sip.c: Peer '105' is now UNREACHABLE! Last qualify: 18
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 105
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 101
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 103 (queued)
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 103
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 104
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 106
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 102
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 106
[2013-05-18 04:08:46] VERBOSE[1698] chan_sip.c: == Extension Changed 105[ext-local] new state Unavailable for Notify User 102
[2013-05-18 04:08:57] NOTICE[1821] chan_sip.c: Peer '105' is now Reachable. (505ms / 2000ms)