Losing WIFI Signal after a while

Help and Support Vero 4K / Vero 4K +
1

I upgraded to the May built this evening (was on December before).

One thing I noticed that I keep loosing a WIFI connection after a while on the Vero4K now. Any new settings I overlooked like some “power management” you might have added?

I just seeing this in the logs:

May 27 23:32:36 Vero kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DISASSOC_IND
May 27 23:32:36 Vero kernel: link down if wlan0 may call cfg80211_disconnected. event : 12, reason=33 from 44:4e:6d:7b:9d:38
May 27 23:32:36 Vero kernel: wl_iw_event: Link Down with BSSID=44:4E:6D:7B:9D:38
May 27 23:32:36 Vero kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_LINK

Well doesn’t help me to find a root cause what changed after the update. As said that behavior is new, happened right after the update, never had that problem before.

Full Logs: https://paste.osmc.tv/moweweladu

Please advice, no clue where too look.

2

Haven’t added any power management changes or any WiFi changes.

Can you power off the device for 5 mins and see if it persists?

Sam

3

Will unplug before I go to bed, check tomorrow after work and report back, finishing my movie first :stuck_out_tongue:

4

Seems to be stable right now. I’ll keep an eye on this how it behaves in the coming days. But leaving the unit some time without power might have done the trick.

5

Well, was only stable initially, now Wifi is constantly lost and even disabling/enabling the adapter doesn’t help and I have to actually fully reboot to get it back working.

Well, I play a bit more with it, if not back to December build on which I never had such issues.

6

Nothing has changed with regards to WiFi since December.
Are you certain that reverting to the December version resolves things?

7

I had this issue as well and it fixed itself after powering the Vero off and on after a good couple of minutes.

8

Well, if you didn’t include anything new / didn’t update anything in regards to WLAN, then it might come from the Debian side itself?

I never experienced that problem at all before, Wifi in general was stable since the day I bought the unit.

Only change yesterday was updating and within the first hour my SSH session was terminated (this is how I noticed). Rebooted, same thing happend. Then left the unit unplugged as suggested. Plugged in this afternoon, looked good for about two hours ,now came back and wanted to watch a movie and Wifi was gone and even disabling/enabling did nothing. It was just dead on the unit.

There have been no other changes yesterday beside apt-get update && apt-get distupgrade followed by a reboot and fixing the resolution (Kodi 18 issue) followed by another reboot. Nothing else changed. And problems began right away.

I’ll try to go back to the last known good for me and see if the problem is gone then. If so, it should be possible to find out what update, maybe from the Debian side, is causing the problem. This time around there was nothing in the log, so whatever happened it wasn’t even logged.

9

I can’t see anything from Debian that would be obvious (i.e. wpa-supplicant etc).
I can do some testing here. How long do I need to keep a connection up for to see a problem?

Can you try a static IP – I wonder if it’s dying with DHCP renewal?

Sam

13

Have not found out if there is a specific time interval, first times it happend within the first hour two times in a row, last time I don’t know (half a day passed before I noticed). I’ll do some more tests before I revert that unit at my mother’s place. Also put up some health checking if the Vero is still reachable to find out if there is some kind of time interval or if it is more random.

DHCP renewal doesn’t seem to play a role here. No DHCP requests received between the reboots. Lease time is set to 86400 here.

Plugging in when I came home:

May 28 06:15:39 pi dhcpd[603]: DHCPDISCOVER from 44:2c:05:9d:3d:92 via eth0
May 28 06:15:39 pi dhcpd[603]: DHCPOFFER on 192.168.100.50 to 44:2c:05:9d:3d:92 via eth0
May 28 06:15:39 pi dhcpd[603]: DHCPREQUEST for 192.168.100.50 (192.168.100.40) from 44:2c:05:9d:3d:92 via eth0
May 28 06:15:39 pi dhcpd[603]: DHCPACK on 192.168.100.50 to 44:2c:05:9d:3d:92 via eth0
May 28 06:15:39 pi dhcpd[603]: Added new forward map from Vero.cuttingroomfloor.net to 192.168.100.50
May 28 06:15:39 pi dhcpd[603]: Added reverse map from 50.100.168.192.100.168.192.in-addr.arpa to Vero.cuttingroomfloor.net

Nothing else in the dhcpd log in regards to the Vero until I just rebooted it after I noticed that the network was dead about an hour ago.

May 28 18:27:06 pi dhcpd[605]: DHCPREQUEST for 192.168.100.50 from 44:2c:05:9d:3d:92 via eth0
May 28 18:27:06 pi dhcpd[605]: DHCPACK on 192.168.100.50 to 44:2c:05:9d:3d:92 via eth0
May 28 18:27:06 pi dhcpd[605]: Added new forward map from Vero.cuttingroomfloor.net to 192.168.100.50
May 28 18:27:06 pi dhcpd[605]: Added reverse map from 50.100.168.192.100.168.192.in-addr.arpa to Vero.cuttingroomfloor.net

It’s also not about not having an IP address or something. Tried from the OSMC Kodi app (as I cannot SSH in without a network connection) to re-join wifi or so. Wifi was dead, after disable, re-enabling it was able to see all SSIDs here but refused to join any. Reboot fixed it. But don’t know what the app is actually doing behind the scene.

But sure, I’ll reconfigure it with a static IP just to rule DHCP out. No biggie.

Yesterday on the first loss of connection just going into the OSMC Kodi app helped to re-join the network right away.

It feels like the wlan driver is just crashing because I cannot really find a pattern so far. It just goes “poof” out of a sudden within the first few hours if being idle after a reboot. At least if feels like it.

As said, never had this problem since the day I bought the Vero

What is also strange, yesterday I saw the Vero on it’s own doing a fallback to 2.4GHz. Normally it only does that in case 5GHz is not available anymore (e.g. router reboot). I never have seen that doing it on its own. And naturally in the current configuration it never try to re-join 5GHz (different issue, I never bothered to address). Just another indicator that something behaves differently now…

Ah well, will monitor it a bit and do a fallback on December (where I had none of these issues) so see if it behaves any better then.

PS: If anything fails I’ll have to route a cable here as well, but need to test if the USB ethernet adapter I have lying around (to get a tad more than 100MBit/s) will work at all with the Vero.

14

If you do try that, I’d just use the built in ethernet. I use mine and never have problems playing UHD movies. And it simplifies troubleshooting; one less variable.

15

Ah well, I might give the dongle a shot at least if it works as it is just lying around.

In case anyone cares, it is this one: https://www.amazon.de/gp/product/B01N4LWHW0 (RTL8153).

But yeah, 100MBit/s good enough anyway. Though had some trouble with the built-in ethernet port when I setup that unit. But that could have been a bad cable to begin with…

Geting a + for a faster wired speed would be an overkill of course.

16

I wasn’t suggesting that you update to a +. I have the original 4K with 100M and as I said, UHD is no problem for me.

17

Sure, given the UHD BD specs it should be of no issue.

Anyway, the unit is at my mother’s place (she bought on shortly after me, to replac her Amazon Fire TV). She also uses an old NAS plus a Pi of of mine for some network services that suck on her AVM Router - and it’s 1080p content for her anyway. So 100 is more than enough.

Still feeling the itch to use the dongle I have lying around :stuck_out_tongue:

18

I understand that you want to try the dongle, but that will just complicate trying to solve your issue. Wait to try the dongle until we resolve your issue,. Then play around all you like :grinning:

19

Fair Enough.

20

Seems to happen almost exactly 30 Minutes after being idle in Kodi - so means no constant network activity. Last playback on Kodi was 30 minutes earlier (playback was done right after a reboot and movie ran for about 2h) and input was switched back to the TV shortly after playback ended.

May 28 20:59:39 Vero kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DISASSOC_IND
May 28 20:59:39 Vero kernel: link down if wlan0 may call cfg80211_disconnected. event : 12, reason=33 from 44:4e:6d:7b:9d:38
May 28 20:59:39 Vero kernel: wl_iw_event: Link Down with BSSID=44:4E:6D:7B:9D:38
May 28 20:59:39 Vero kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_LINK
May 28 20:59:39 Vero kernel: cfg80211: Calling CRDA for country: DE
May 28 20:59:39 Vero wpa_supplicant[486]: wlan0: CTRL-EVENT-DISCONNECTED bssid=44:4e:6d:7b:9d:38 reason=33
May 28 20:59:39 Vero connmand[406]: wlan0 {RX} 3968369 packets 1416475915 bytes
May 28 20:59:39 Vero kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
May 28 20:59:39 Vero connmand[406]: wlan0 {TX} 2089403 packets 151337585 bytes
May 28 20:59:39 Vero connmand[406]: wlan0 {update} flags 102403 <UP,LOWER_UP>
May 28 20:59:39 Vero connmand[406]: wlan0 {newlink} index 3 address 44:2C:05:9D:3D:92 mtu 1500
May 28 20:59:39 Vero connmand[406]: wlan0 {newlink} index 3 operstate 5
May 28 20:59:39 Vero avahi-daemon[408]: Withdrawing address record for 192.168.100.50 on wlan0.
May 28 20:59:39 Vero avahi-daemon[408]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.50.
May 28 20:59:39 Vero avahi-daemon[408]: Interface wlan0.IPv4 no longer relevant for mDNS.
May 28 20:59:39 Vero connmand[406]: wlan0 {del} address 192.168.100.50/24 label wlan0
May 28 20:59:39 Vero connmand[406]: wlan0 {del} route 192.168.100.0 gw 0.0.0.0 scope 253
May 28 20:59:39 Vero connmand[406]: ipconfig state 7 ipconfig method 1
May 28 20:59:39 Vero wpa_supplicant[486]: wlan0: Trying to associate with f0:b0:14:4f:86:d2 (SSID=‘moria’ freq=5180 MHz)
May 28 20:59:39 Vero connmand[406]: ipconfig state 2 ipconfig method 1
May 28 20:59:39 Vero kernel: Connectting with f0:b0:14:4f:86:d2 channel (36) ssid “moria”, len (5)
May 28 20:59:39 Vero wpa_supplicant[486]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=f0:b0:14:4f:86:d2 status_code=34
May 28 20:59:39 Vero kernel: connect failed event=0 e->status 1 e->reason 0
May 28 20:59:39 Vero kernel: CFG80211-ERROR) wl_bss_connect_done : Report connect result - connection failed
May 28 20:59:39 Vero connmand[406]: ipconfig state 7 ipconfig method 1
May 28 20:59:39 Vero connmand[406]: ipconfig state 7 ipconfig method 1
May 28 20:59:41 Vero ntpd[887]: Deleting interface #3 wlan0, 192.168.100.50#123, interface stats: received=737, sent=739, dropped=0, active_time=9153 secs
May 28 20:59:41 Vero ntpd[887]: 141.82.25.201 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 80.151.232.87 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 188.68.53.92 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 213.172.105.106 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 78.46.102.180 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 5.199.135.170 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 46.38.241.30 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 5.9.83.106 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 37.120.189.254 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 185.194.140.199 local addr 192.168.100.50 →
May 28 20:59:41 Vero ntpd[887]: 212.18.3.19 local addr 192.168.100.50 →

This time it reconnected. Only difference, I had an active SSH sessions open (journalctl -f) and even re-joined the 5GHz Network compared to loosing it completely.

But it should not get that “Link down” from CFG80211 in the first place. I couldn’t find any meaningful information what the “WLC_E_DISASSOC_IND” and “WLC_E_LINK” messages mean. Googling just leads to driver on GitHub basically.

No DHCP directly involved. That happend about 6 mins later…

Vero:

May 28 21:05:47 Vero connmand[406]: ipconfig state 2 ipconfig method 1
May 28 21:05:47 Vero wpa_supplicant[486]: wlan0: Trying to associate with 44:4e:6d:7b:9d:38 (SSID=‘moria’ freq=5180 MHz)
May 28 21:05:47 Vero kernel: Connectting with 44:4e:6d:7b:9d:38 channel (36) ssid “moria”, len (5)
May 28 21:05:47 Vero wpa_supplicant[486]: wlan0: Associated with 44:4e:6d:7b:9d:38
May 28 21:05:47 Vero kernel: wl_iw_event: Link UP with BSSID=44:4E:6D:7B:9D:38
May 28 21:05:47 Vero kernel: wl_bss_connect_done succeeded with 44:4e:6d:7b:9d:38
May 28 21:05:47 Vero kernel: wl_bss_connect_done succeeded with 44:4e:6d:7b:9d:38
May 28 21:05:47 Vero wpa_supplicant[486]: wlan0: WPA: Key negotiation completed with 44:4e:6d:7b:9d:38 [PTK=CCMP GTK=CCMP]
May 28 21:05:47 Vero wpa_supplicant[486]: wlan0: CTRL-EVENT-CONNECTED - Connection to 44:4e:6d:7b:9d:38 completed [id=0 id_str=]
May 28 21:05:47 Vero wpa_supplicant[486]: bgscan simple: Failed to enable signal strength monitoring
May 28 21:05:47 Vero connmand[406]: wlan0 {RX} 3968371 packets 1416476169 bytes
May 28 21:05:47 Vero connmand[406]: wlan0 {TX} 2089408 packets 151338531 bytes
May 28 21:05:47 Vero connmand[406]: wlan0 {update} flags 102467 <UP,RUNNING,LOWER_UP>
May 28 21:05:47 Vero connmand[406]: wlan0 {newlink} index 3 address 44:2C:05:9D:3D:92 mtu 1500
May 28 21:05:47 Vero connmand[406]: wlan0 {newlink} index 3 operstate 6
May 28 21:05:47 Vero connmand[406]: ipconfig state 3 ipconfig method 1
May 28 21:05:47 Vero avahi-daemon[408]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.50.
May 28 21:05:47 Vero avahi-daemon[408]: New relevant interface wlan0.IPv4 for mDNS.
May 28 21:05:47 Vero avahi-daemon[408]: Registering new address record for 192.168.100.50 on wlan0.IPv4.
May 28 21:05:47 Vero connmand[406]: Setting domainname to cuttingroomfloor.net
May 28 21:05:47 Vero connmand[406]: wlan0 {add} address 192.168.100.50/24 label wlan0 family 2
May 28 21:05:47 Vero connmand[406]: wlan0 {add} route 192.168.100.0 gw 0.0.0.0 scope 253
May 28 21:05:47 Vero connmand[406]: wlan0 {add} route 192.168.100.1 gw 0.0.0.0 scope 253
May 28 21:05:47 Vero connmand[406]: wlan0 {add} route 0.0.0.0 gw 192.168.100.1 scope 0
May 28 21:05:47 Vero connmand[406]: wlan0 {add} route 212.227.81.55 gw 192.168.100.1 scope 0
May 28 21:05:49 Vero ntpd[887]: Listen normally on 5 wlan0 192.168.100.50:123
May 28 21:05:54 Vero connmand[406]: wlan0 {del} route 212.227.81.55 gw 192.168.100.1 scope 0

DHCPD:

May 28 21:05:47 pi dhcpd[605]: DHCPREQUEST for 192.168.100.50 from 44:2c:05:9d:3d:92 via eth0
May 28 21:05:47 pi dhcpd[605]: DHCPACK on 192.168.100.50 to 44:2c:05:9d:3d:92 via eth0
May 28 21:05:47 pi dhcpd[605]: Added new forward map from Vero.cuttingroomfloor.net to 192.168.100.50
May 28 21:05:47 pi dhcpd[605]: Added reverse map from 50.100.168.192.100.168.192.in-addr.arpa to Vero.cuttingroomfloor.net

Then the Vero keeps going on with HDMITX stuff from the Kernel about a minute later. I assume my mother turned off the TV here, which would make sense for any HDMI stuff. Just remotely looking at the box right now, so don’t know exactly what happened over there.

Despite the error message from the driver (???), I could theorize why it may have lost the connection. This is a mesh setup and the Vero is not allowed to connect to all present APs (it is only allowed on the one that is closest to it and has the strongest 5 GHz signal an best throughput in general). And it might have tried to access a different one, couldn’t and just stopped (doesn’t explain why it couldn’t rejoin manually though). But again, this setup is there for a long time and was working out fine. It’s pretty much standard anyway. Nothing fancy here. No issues in the last 12 months.

So question would be what these CFG80211 Errors actually mean to find out what might not be working. Any ideas?

Will try to reproduce tomorrow. Play something at my mothers place, switch to TV and just having SSH open without doing anything (as it was the last time when it failed, this time I had the syslog open basically).

For now I leave the box as it is and wait what happens…

Vero Logs - in case you care: https://paste.osmc.tv/pufuzewire

21

The first question to ask in a situation like is “what has changed?” And the one thing that stands out is that wpasupplicant has recently been updated from version 2:2.4-1+deb9u3 to 2:2.4-1+deb9u4. (Though the version kicking around in Dec 2018 was probably 2:2.4-1+deb9u2.)

It’s your call, but I’d be inclined to revert to the a previous version and see what happens:

sudo apt-get install --reinstall wpasupplicant=2:2.4-1+deb9u3

then reboot.

22

Thanks, I’ll try some older version of wpasupplicant and see if it makes any difference. I have no problems trying out some different versions of packages compared to doing a full fallback of the system to the state of the December image.

Was under the impression from initial replyies that there were no relevant changes. Guess I misread that part. Stupid me.

Also I I took another look at the logs just a few minutes ago:

May 28 21:38:42 Vero kernel: CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DISASSOC_IND

So this happens roughly every 30 minutes after the last noteworthy network activity (last one was a DHCP request - at 21:38 there was none. So next error from CFG80211 should happen soonish. At least I have something to work on and to look for the in logs and a rough time frame to check for any different behavior.

This time it said goodbye to 5GHz, stayed on 2.4GHz instead of losing all connectivity. That never happened before that the Vero leaves the 5GHz by choice. So probably just a variation here of saying goodby to connectivity completly. On 2.4GHz so far no errors later on.

If I look at the wpa_supplicant error codes for the line:

May 28 21:38:42 Vero wpa_supplicant[486]: wlan0: CTRL-EVENT-DISCONNECTED bssid=44:4e:6d:7b:9d:38 reason=33

I’ll get “NOT_ENOUGH_BANDWIDTH - Disassociated because QoS AP lacks sufficient bandwidth for this QoS STA” - well that’s pretty much bullshit here. The Vero doesn’t even announce to the AP any WMM support. Yeah, could be some change in wpasupplicant here causing all the trouble I am experiencing.

Will rollback the wpasupplicant package version by version and look for any different behavior over the next couple of days and report back then with my findings.

23

The details: of the security update: Debian -- Security Information -- DSA-4450-1 wpa