Heartbeat missed - disconnect

[InfTF]

Good afternoon, I have problems with Unifi Ap the controller sees all Ap, adopts and connects but at a certain time they appear as heartbeat missed, reconnect themselves and are disconnected again with the label heartbeat missed.

I do not know what to do I tried it on different platforms but the same thing happens.

Any ideas?

The driver version is:

UI5.4.14.0
Backend5.4.14
Buildatag_5.4.14_9202

Regards!

[mlskrypka · Accepted solution]

Check this out:

https://help.ubnt.com/hc/en-us/articles/205144590-UniFi-What-is-Zero-Handoff-

I have never configured this

[mlskrypka]

Your controller marks your AP as "disconnected" because it stops receiving an inform messages from them. Do you know why this could be? Check the AP uptime, are they getting rebooted? How to you host your controller?

[InfTF]

I have a network with POE Switches and are connected to them the only thing I see in the SWITCHS is flappin and I do not understand why the APs produce them

[mlskrypka]

So your APs are getting rebooted because they are losing the power, correct?

[InfTF]

No, the APs do not restart appear as Heartbeat missed

and then appear disconnected. Then another AP is disconnected and does the same.

[bw1]

Can you explain what you meant by "the only thing I see in the SWITCHS is flappin and I do not understand why the APs produce them"?

[dvdwulp]

Which brand switch are you using?

Flapping can be MAC flapping which is in a wireless world normal behaviour when the client is roaming from one AP to another...... and back..... It might be that the switch disconnects an interface for 5 minutes if the amount of flaps happen more often then the threshold allows. The old cisco switches had that behaviour....

Can you share the log entries of your switch?

Cheers,

Dennis  

[InfTF]

In the different Switches PoE of my network appears the same MAC of an AP by different mouths and in different Switches this produces the flapping in the switchwes

[InfTF]

CISCO Switches, the logs I can not share.

In the different Switches PoE of my network appears the same MAC of an AP by different mouths and in different Switches this produces the flapping in the switchwes

[InfTF]

First:

Second:

Finally:

This happens randomly with all ap

[mlskrypka]

Check the controller logs for this particular AP . What can you see there:

cat /var/log/unifi/* | grep (MAC address of the affected AP)

For Windows please see below:

https://help.ubnt.com/hc/en-us/articles/204959834-UniFi-What-log-files-exist-and-where-can-I-view-th...

[InfTF]

[2017-04-24 10:48:55,046] <devmgr> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] HEARTBEAT_MISSED->UNKNOWN, state_expire=0
[2017-04-24 10:48:55,046] <stamgr> INFO  event  - [event] User[68:xxxxxxxxxxx:ff] disconnected from "IC" (29m 22s connected, 133,13K bytes, last AP[04:xxxxxxxxxxx:34])
[2017-04-24 10:48:57,874] <In-111> INFO  In - from 04::xxxxxxxxxxx:59](P, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.3, dev_ip=192.168.0.3, up=1122856
[2017-04-24 10:49:01,905] <discover> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] UNKNOWN->ADOPTING, state_expire=1493027371
[2017-04-24 10:49:01,905] <discover> INFO  dev    -    [Try Adopt] dev[04:xxxxxxxxxxx:34], dev_ip=192.168.0.6, url=http://192.168.0.150:8080/In
[2017-04-24 10:49:04,905] <ssh> INFO  dev    -    [Adopt Failed] ip 192.168.0.6 unreachable
[2017-04-24 10:49:04,905] <ssh> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPTING->ADOPT_FAILED, state_expire=0
[2017-04-24 10:49:06,812] <In-133> INFO  In - from [44:xxxxxxxxxxxc7](P1, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.5, dev_ip=192.168.0.5, up=1125411
[2017-04-24 10:49:11,812] <In-178> INFO  In - from [04:xxxxxxxxxxx:bc](Frut, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.4, dev_ip=192.168.0.4, up=332781
[2017-04-24 10:49:11,905] <discover> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPT_FAILED->ADOPTING, state_expire=1493027381
[2017-04-24 10:49:11,905] <discover> INFO  dev    -    [Try Adopt] dev[04:xxxxxxxxxxx:34], dev_ip=192.168.0.6, url=http://192.168.0.150:8080/In
[2017-04-24 10:49:14,905] <ssh> INFO  dev    -    [Adopt Failed] ip 192.168.0.6 unreachable
[2017-04-24 10:49:14,905] <ssh> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPTING->ADOPT_FAILED, state_expire=0
[2017-04-24 10:49:17,952] <In-183> INFO  In - from [44:xxxxxxxxxxx:d5](B, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.8, dev_ip=192.168.0.8, up=514875
[2017-04-24 10:49:17,968] <In_stat-7> INFO  event  - [event] User[a4:xxxxxxxxxxx:76] roams from "channel 1(ng)" to "channel 36(na)" at AP[44:xxxxxxxxxxx:d5]
[2017-04-24 10:49:21,905] <discover> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPT_FAILED->ADOPTING, state_expire=1493027391
[2017-04-24 10:49:21,905] <discover> INFO  dev    -    [Try Adopt] dev[04:xxxxxxxxxxx:34], dev_ip=192.168.0.6, url=http://192.168.0.150:8080/In
[2017-04-24 10:49:24,921] <ssh> INFO  dev    -    [Adopt Failed] ip 192.168.0.6 unreachable
[2017-04-24 10:49:24,921] <ssh> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPTING->ADOPT_FAILED, state_expire=0
[2017-04-24 10:49:24,937] <In-114> INFO  In - from 04::xxxxxxxxxxx:59](P, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.3, dev_ip=192.168.0.3, up=1122883
[2017-04-24 10:49:30,921] <In-99> INFO  In - from [44:xxxxxxxxxxxc7](P1, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.5, dev_ip=192.168.0.5, up=1125436
[2017-04-24 10:49:32,249] <In-19> INFO  In - from [04:xxxxxxxxxxx:34](I, U7P, 3.7.51.6230): state=ADOPT_FAILED, ext/stun_ip=192.168.0.6, dev_ip=192.168.0.6, up=613416
[2017-04-24 10:49:32,249] <In-19> INFO  dev    -    [state] dev[04:xxxxxxxxxxx:34] ADOPT_FAILED->CONNECTED, state_expire=0
[2017-04-24 10:49:32,265] <In-19> INFO  event  - [event] AP[04:xxxxxxxxxxx:34] was connected
[2017-04-24 10:49:32,280] <In-19> INFO  In - <<< [setparam] dev[04:xxxxxxxxxxx:34]: [_type, blocked_sta, server_time_in_utc]
[2017-04-24 10:49:34,156] <In-126> INFO  In - from [04:xxxxxxxxxxx:34](I, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.6, dev_ip=192.168.0.6, up=613418
[2017-04-24 10:49:34,234] <In-191> INFO  In - from [04:xxxxxxxxxxx:34](I, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.6, dev_ip=192.168.0.6, up=613418
[2017-04-24 10:49:39,921] <In-106> INFO  In - from [04:xxxxxxxxxxx:bc](Frut, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.4, dev_ip=192.168.0.4, up=332809
[2017-04-24 10:49:55,999] <In-164> INFO  In - from 04::xxxxxxxxxxx:59](P, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.3, dev_ip=192.168.0.3, up=1122914
[2017-04-24 10:50:03,984] <In-90> INFO  In - from [44:xxxxxxxxxxxc7](P1, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.5, dev_ip=192.168.0.5, up=1125469
[2017-04-24 10:50:08,343] <In-83> INFO  In - from [04:xxxxxxxxxxx:34](I, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.6, dev_ip=192.168.0.6, up=613452
[2017-04-24 10:50:13,984] <In-26> INFO  In - from [04:xxxxxxxxxxx:bc](Frut, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.4, dev_ip=192.168.0.4, up=332843
[2017-04-24 10:50:19,140] <In-131> INFO  In - from 04::xxxxxxxxxxx:59](P, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.3, dev_ip=192.168.0.3, up=1122937
[2017-04-24 10:50:24,062] <In-70> INFO  In - from [44:xxxxxxxxxxxc7](P1, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.5, dev_ip=192.168.0.5, up=1125489
[2017-04-24 10:50:32,453] <In-197> INFO  In - from [04:xxxxxxxxxxx:34](I, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.6, dev_ip=192.168.0.6, up=613476
[2017-04-24 10:50:40,062] <In-88> INFO  In - from [04:xxxxxxxxxxx:bc](Frut, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.4, dev_ip=192.168.0.4, up=332869
[2017-04-24 10:50:46,281] <In-94> INFO  In - from 04::xxxxxxxxxxx:59](P, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.3, dev_ip=192.168.0.3, up=1122964
[2017-04-24 10:50:49,171] <In-155> INFO  In - from [44:xxxxxxxxxxx:d5](B, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.8, dev_ip=192.168.0.8, up=514966
[2017-04-24 10:50:54,124] <In-118> INFO  In - from [44:xxxxxxxxxxxc7](P1, U7P, 3.7.51.6230): state=CONNECTED, ext/stun_ip=192.168.0.5, dev_ip=192.168.0.5, up=1125519

[mlskrypka]

Ok can you please send logs from the recent affected AP, please:

# dmesg | grep link
# uptime

[InfTF]

Occurs with all APS, disconnects and connects at random.

Thank you

[mlskrypka]

Cool. Logs?

[InfTF]

What log do you need? Because I put up what I get in the server log

[mlskrypka]

SSH into the AP and use the above commands to get those logs. We want to check AP uptime and link up/down entries

[InfTF]

Ok sorry, I had not understood

BZ.v3.7.51# tail -f /var/log/messages
Apr 24 13:09:21  user.warn kernel: [621747.312000] eth0: received packet with own address as source address
Apr 24 13:09:21  user.warn kernel: [621747.313000] eth0: received packet with own address as source address
Apr 24 13:09:25  user.err syslog: ace_reporter.reporter_fail(): Unreachable (http://192.168.0.150:8080/i)
Apr 24 13:09:25  user.err syslog: ace_reporter.reporter_fail(): i failed #3 (last i: 116 seconds ago), rc=3
Apr 24 13:09:25  user.err syslog: ace_reporter.reporter_fail(): [STATE] entering SELFRUN!!!!
Apr 24 13:09:40  user.info syslog: ace_reporter.reporter_set_managed(): [STATE] enter MANAGED
Apr 24 13:10:01  cron.err crond[5677]: USER i pid 22067 cmd syswrapper.sh refresh-walled-garden 1
Apr 24 13:20:01  cron.err crond[5677]: USER i pid 22080 cmd syswrapper.sh refresh-walled-garden 1
Apr 24 13:23:07  authpriv.info dropbear[22093]: Child connection from 192.168.0.201:12524
Apr 24 13:23:23  authpriv.notice dropbear[22093]: Password auth succeeded for



uptime: 13:30:22 up 7 days,  5:03, load average: 0.00, 0.00, 0.00

[mlskrypka]

Thanks,

I think is the an answer:

Apr 24 13:09:25 user.err syslog: ace_reporter.reporter_fail(): Unreachable (http://192.168.0.150:8080/i)

Now you need to understand why your APs sometimes unable to reach your controller. Your uptime is good so it is not due to reboot or port flapping.

[InfTF]

The CISCO POE switches detect that the same MAC address is on more than one different switch at the same time and produces the flapping.

Thanks