Cannot connect to router (Linksys WERT160NL) running OpenWRT

[kovadam69]

Hi!

I have a strange issue, the wifi driver works everywhere I tried, except one OpenWRT driven router. I don't really get why.

First it did not even wanted to connect, then I turned off WMM on the router, and suddenly my notebook managed to connect. However the traffic is very-very-very slow. I experience huge delay in ping respone (like 6-8 seconds!) and there are sometimes also strange messages in the journal.

Now I connected to my phone's hotspot, which is connected to the same Wifi router, and the ping response went down to 100ms or even lower. So it is not the wifi or the router, but it is something with the openwrt wifi and this notebooks wifi driver/hardware. I have another router, which runs also openwrt, but with that it is working properly.

The router which is not working is a Linksys WRT160NL (only 2.4G wifi) router, with openwrt 17.01.4, and the working openwrt router is a TP-Link Archer C7 v4 running openwrt 19.07.7 (also supports 5G wifi)

This is the connection part from journal log:

dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: SME: Trying to authenticate with c8:d7:19:db:ca:fc (SSID='Z_NW' freq=2447 MHz) dec 01 14:05:38 zola-npc kernel: wlp1s0: disconnect from AP 90:9a:4a:bd:ab:5e for new auth to c8:d7:19:db:ca:fc dec 01 14:05:38 zola-npc kernel: wlp1s0: authenticate with c8:d7:19:db:ca:fc dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6031] device (wlp1s0): supplicant interface state: completed -> authenticating dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6031] device (p2p-dev-wlp1s0): supplicant management interface state: completed -> authenticating dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6031] device (wlp1s0): ip:dhcp4: restarting dec 01 14:05:38 zola-npc kernel: wlp1s0: send auth to c8:d7:19:db:ca:fc (try 1/3) dec 01 14:05:38 zola-npc kernel: wlp1s0: authenticated dec 01 14:05:38 zola-npc kernel: rtw89_8852be 0000:01:00.0 wlp1s0: disabling HT/VHT/HE as WMM/QoS is not supported by the AP dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: Trying to associate with c8:d7:19:db:ca:fc (SSID='Z_NW' freq=2447 MHz) dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6303] dhcp4 (wlp1s0): canceled DHCP transaction dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6304] dhcp4 (wlp1s0): activation: beginning transaction (timeout in 45 seconds) dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6304] dhcp4 (wlp1s0): state changed no lease dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6305] dhcp4 (wlp1s0): activation: beginning transaction (timeout in 45 seconds) dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6326] device (wlp1s0): supplicant interface state: authenticating -> associating dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.6326] device (p2p-dev-wlp1s0): supplicant management interface state: authenticating -> associating dec 01 14:05:38 zola-npc kernel: wlp1s0: associate with c8:d7:19:db:ca:fc (try 1/3) dec 01 14:05:38 zola-npc kernel: wlp1s0: RX ReassocResp from c8:d7:19:db:ca:fc (capab=0x31 status=0 aid=7) dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: Associated with c8:d7:19:db:ca:fc dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=HU dec 01 14:05:38 zola-npc kernel: wlp1s0: associated dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.7582] device (wlp1s0): supplicant interface state: associating -> 4way_handshake dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.7582] device (p2p-dev-wlp1s0): supplicant management interface state: associating -> 4way_handshake dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: WPA: Key negotiation completed with c8:d7:19:db:ca:fc [PTK=CCMP GTK=CCMP] dec 01 14:05:38 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-CONNECTED - Connection to c8:d7:19:db:ca:fc completed [id=0 id_str=] dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.9033] device (wlp1s0): supplicant interface state: 4way_handshake -> completed dec 01 14:05:38 zola-npc NetworkManager[879]: <info> [1669899938.9035] device (p2p-dev-wlp1s0): supplicant management interface state: 4way_handshake -> completed dec 01 14:05:39 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-66 noise=9999 txrate=48000 dec 01 14:05:43 zola-npc NetworkManager[879]: <info> [1669899943.0699] manager: NetworkManager state is now CONNECTED_SITE dec 01 14:05:43 zola-npc dbus-daemon[877]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 pid=879 com> dec 01 14:05:43 zola-npc systemd[1]: Starting Network Manager Script Dispatcher Service...

this is the strange error:

dec 01 14:07:12 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:13 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:13 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:14 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:14 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:14 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:15 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:15 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:15 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:16 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:16 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:16 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:17 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:36 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-51 noise=9999 txrate=6000 dec 01 14:07:38 zola-npc wpa_supplicant[902]: wlp1s0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-73 noise=9999 txrate=6000 dec 01 14:07:39 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:39 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 14:07:39 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues

And there are the ping times before connecting to my phone's hotspot:

64 bytes from 10.1.1.3: icmp_seq=330 ttl=64 time=8612 ms 64 bytes from 10.1.1.3: icmp_seq=331 ttl=64 time=8569 ms 64 bytes from 10.1.1.3: icmp_seq=332 ttl=64 time=9110 ms 64 bytes from 10.1.1.3: icmp_seq=333 ttl=64 time=10606 ms 64 bytes from 10.1.1.3: icmp_seq=334 ttl=64 time=9972 ms 64 bytes from 10.1.1.3: icmp_seq=335 ttl=64 time=9733 ms 64 bytes from 10.1.1.3: icmp_seq=336 ttl=64 time=9803 ms 64 bytes from 10.1.1.3: icmp_seq=337 ttl=64 time=9356 ms 64 bytes from 10.1.1.3: icmp_seq=338 ttl=64 time=9303 ms 64 bytes from 10.1.1.3: icmp_seq=356 ttl=63 time=12.1 ms 64 bytes from 10.1.1.3: icmp_seq=357 ttl=63 time=14.3 ms 64 bytes from 10.1.1.3: icmp_seq=358 ttl=63 time=15.2 ms 64 bytes from 10.1.1.3: icmp_seq=359 ttl=63 time=13.3 ms 64 bytes from 10.1.1.3: icmp_seq=360 ttl=63 time=6.02 ms 64 bytes from 10.1.1.3: icmp_seq=361 ttl=63 time=5.83 ms 64 bytes from 10.1.1.3: icmp_seq=362 ttl=63 time=10.4 ms 64 bytes from 10.1.1.3: icmp_seq=363 ttl=63 time=6.77 ms 64 bytes from 10.1.1.3: icmp_seq=364 ttl=63 time=12.2 ms

As you can see after connecting to my phone's hotspot, everything became normal.

What can be the issue? I think I use the latest codebase.

Thanks!

[kovadam69]

updated openwrt to latest 19.07 (what is available for linksys wrt160nl), now it seems to go a bit better, ping times are now around 100ms, still higher than with wifi hotspot, but OK

edit: no, not ok, still experience really high response times (over 10 sec), it is basically useless. And there are a lot of

dec 01 15:20:15 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush queues dec 01 15:20:15 zola-npc kernel: rtw89_8852be 0000:01:00.0: timed out to flush pci txch: 0

lines in the log, whatever they mean...

So seems the upgrade to openwrt 19.07 did not help on this issue...

[lwfinger]

After firmware update, do you still see "0000:01:00.0 wlp1s0: disabling HT/VHT/HE as WMM/QoS is not supported by the AP"? That will certainly cripple the connection.

I have seen those "timed out to flush queues" messages in the past, but not recently. I did have some updates on my version that had not been pushed, but I fixed that now. Do a 'git pull' and remake the drivers.

[kovadam69]

Yes, it's still there, however I turned off WMM on the router,.because with WMM turned on it did not even connect. Now it.connects, but useless slow.

I tired git pull, and compiled a new.module, bit the message is still there

lwfinger @.***> ezt írta (időpont: 2022. dec. 1., Csü 19:41):

After firmware update, do you still see "0000:01:00.0 wlp1s0: disabling HT/VHT/HE as WMM/QoS is not supported by the AP"? That will certainly cripple the connection.

I have seen those "timed out to flush queues" messages in the past, but not recently. I did have some updates on my version that had not been pushed, but I fixed that now. Do a 'git pull' and remake the drivers.

— Reply to this email directly, view it on GitHub https://github.com/lwfinger/rtw89/issues/199#issuecomment-1334191465, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACL35DI27D5KAB2HJY7CAUDWLDWPJANCNFSM6AAAAAASQZAIXI . You are receiving this because you modified the open/close state.Message ID: @.***>

[lwfinger]

The Web tells me that the Linksys router is 802.11b/g/n, i.e. wifi4 (I think). My closest AP is a Netgear WNDR 3300. Although, the router is dual-band, I connected to the 2.4 G band. Testing with a local LibreSpeed server, I get about 90 Mbps up and down. Using speedtest.net, I get 46/76 Mbps D/U. My base connection is 500 Mbps.

Next, I connected to the router used by most of my network. It is a Netgear WNDR4500 - an N900 router. On the 2.4 G band, speedtest.net got 97/86 Mbps D/U. LibreSpeed got about the same.

Next, I switched to an ac1900 (wifi 5) router. Using its 2.4 GHz band, performance is disappointing (57/101 D?U), but in the 5 G band, speedtest.net gets 457/287 D/U. LibreSpeed gets 542/310 D/U.

Using mt ax1500 (wifi 6) router, LibreSpeed gets 542/642 in the 2.4 G band, while speedtest.net gets about 465 U/D, which is about what I get when I connect with a wire. Changing to the 5 G band gave about the same results as 2.4.

All of my routers are running vendor firmware. I have dabbled with openWRT in the past, but not at the moment.

I would be interested in the over-the-air packets for the configuration that will not connect. Do you have experience with Wireshark?

[kovadam69]

I have wireshark installed, I can play with it tomorrow... Something is definetly wrong, sometimes (after connecting) it seems OK, and the ping is also low, then after a while it slows down and the ping goes above 10 sec! Then after a while I think it reconnects in the background... but overall it is superslow. I did not measure speed using speedtest, since it is challenging to open any web page in the browser. On the router side I see 6/11Mbps for the connection.

lwfinger @.***> ezt írta (időpont: 2022. dec. 1., Csü 20:36):

The Web tells me that the Linksys router is 802.11b/g/n, i.e. wifi4 (I think). My closest AP is a Netgear WNDR 3300. Although, the router is dual-band, I connected to the 2.4 G band. Testing with a local LibreSpeed server, I get about 90 Mbps up and down. Using speedtest.net, I get 46/76 Mbps D/U. My base connection is 500 Mbps.

Next, I connected to the router used by most of my network. It is a Netgear WNDR4500 - an N900 router. On the 2.4 G band, speedtest.net got 97/86 Mbps D/U. LibreSpeed got about the same.

Next, I switched to an ac1900 (wifi 5) router. Using its 2.4 GHz band, performance is disappointing (57/101 D?U), but in the 5 G band, speedtest.net gets 457/287 D/U. LibreSpeed gets 542/310 D/U.

Using mt ax1500 (wifi 6) router, LibreSpeed gets 542/642 in the 2.4 G band, while speedtest.net gets about 465 U/D, which is about what I get when I connect with a wire. Changing to the 5 G band gave about the same results as 2.4.

All of my routers are running vendor firmware. I have dabbled with openWRT in the past, but not at the moment.

I would be interested in the over-the-air packets for the configuration that will not connect. Do you have experience with Wireshark?

— Reply to this email directly, view it on GitHub https://github.com/lwfinger/rtw89/issues/199#issuecomment-1334272624, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACL35DMT6QJHRKRHGGJCFDDWLD45XANCNFSM6AAAAAASQZAIXI . You are receiving this because you modified the open/close state.Message ID: @.***>

[kovadam69]

I checked with wireshark. I could not capture for limited knowledge packets for Wifi connection, but it seems for some reason the DHCP requests do not work or get through. Which is strange since my phone is connecting without any issue. So it seems the auth to the Wifi AP is OK, but then it cannot get a DHCP packet. I tried with fixed IP, then it connected, not for the first time, but 2nd or 3rd time it managed to get a connection. I also tested PING from my phone, which is usually 5-10ms, on my notebook rather 50-100ms in best case and >10sec worst case. When there are multiple connections going on (like opening a website) it goes above 20sec and at the end "Destination host unreachable". In wireshark I saw a lot of following "errors?":

TCP Retransmission TCP Dup ACK TCP Out-Of-Order TCP Spurious Retransmission

and a lot above those "errors". Also ping gets sometime DUP response.

If you can tell me what to set up in wireshark, I can try to capture the wifi connection initiation.

Now I installed a TP-Link AC1200 wifi range extender (connected to the wired network using cable and in AP mode), try to use that one, it runs stock TP-Link firmware

[kovadam69]

Now with TP-Link it's working propely, speedtest 78/23mbit (23mbit is my cable connection upper limit). I disabled the linksys wifi and using now the tp-link AP...

[lwfinger]

The best way to capture the traffic is with a 3rd computer running Wireshark and capturing everything on the air. With that data, you can then isolate the packets involved in initiating and establishing a connection.

I do not know if the openWRT firmware for the Linksys has a bug, or if implements some protocol that we do not.

If you are happy with the TP-Link AP, you might try to restore the Linksys to vendor firmware and see if it still has a problem, or you can put it on the shelf, or in the trash.

[kovadam69]

Yeah, I used this Linksys anyway as an AP, so it does not make a different. Now with the TP-Link, it works without any problems. Also on TP-Link Archer c7 I have openWRT, but it also works with my notebook, just this Linksys not. Now I ordered another TP-Link AP (since this one I'm using now I removed elsewhere) which has 1000mbps LAN interface (this one has only 100mbps, this is why on 5G Wifi I got only 92mbps speed). I won't restore stock Linksys firmware, it's fine now this way. Thanks!

[lwfinger]

That is a very old TP link router. I have some 15 year old ones. but they all have Gigabit Lans.