Ausfall Freifunk-Knoten mit unklarer Ursache

https://wiki.freifunk.net/Konsole

Bei mir funktioniert das einwandfrei, mein Knoten geht aber auch nicht offline. Wenn fastd nicht terminiert dann würde ich sagen ist irgendwas gewaltig faul. Entweder defekte Hardware (z.B. Flashspeicher) oder Hardware am Ende (z.B. zu wenig Hauptspeicher).

Weder noch. Die Hardware ist ganz neu, und RAM hat der Zyxel NWA50AX im Überfluss. Linux-Programme lassen sich nicht killen, wenn sie in einem nicht unterbrechbaren Systemaufruf hängen, und das scheint hier auch der Fall zu sein. Bei unterbrochener Verbindung zum Gateway hängt auch ein Aufruf von batctl n und lässt sich nicht mehr einfach abbrechen.

1 „Gefällt mir“

Deshalb tippe ich ja auf Hardware. Fastd ist ein einfacher Daemon im Userspace - der macht höchstens indirekt entsprechende Systemaufrufe. Wenn die Hardware selbst in Ordnung ist bleibt eigentlich nur der Netzwerktreiber.

Momentan tippe ich darauf, dass fastd in SYS_pipe hängt:

root@Ladenburg-INTAKT-001:~# cat /proc/4493/syscall 
0 0x4 0x7faf8740 0x24 0x0 0x0 0x0 0x7faf7618 0x77dc82e4

Basierend auf der Tatsache, daß kein generelles Problem bekannt ist, würde ich der These von @TomH folgen, daß der Internetzugang(srouter) hier ursächlich für die Symptome ist.

Dagegen spricht, dass eine dauerhafte Verbindung und logread -f per IPv4 reverse ssh über diesen Router auf den Knoten ohne Probleme möglich ist, auch noch, wenn die Verbindung zum Gateway ausfällt.

Ich tippe momentan auf ein Problem im WLAN-Treiber, das hier wegen der starken WLAN-Nutzung (viele Clients plus Mesh per WLAN) besonders oft zuschlägt.

Guter Punkt; wobei WLAN nichts mit fastd zu tun hat. Kannst Du denn das Default-GW pingen?

Nein, wenn der Knoten ausgefallen ist, ist auch keines der Gateways über seine IPv6 anpingbar, wohl aber über IPv4.

Über logread ist rausfindbar, wohin fastd sich verbunden hatte, wichtig wäre nun zu wissen, ob, wenn die fastd-Verbindung wegbricht, diese per IP noch per ping und der UDP-Port von fastd erreichbar ist. Evtl. hat der Internetrouter mit der Menge an UDP-Paketen ein Problem, IIRC wurde sowas schon früher mal berichtet.

Abbruch der fastd-Verbindung deutet für mich wieder auf den Zugangsrouter, dafür braucht’s kein WLAN.

(IPv6 geht i. d. R. nur via Freifunk und damit nur mit fastd-Verbindung; was gibt denn ‘ip route show dev br-wan‘ zurück? wobei, eigentlich hat der Knoten ja IPv6 via LTE lt. Logfile.)

Das Gateway gw02.freifunk-rhein-neckar.de wird von fastd offenbar per IPv4 angesprochen:

root@Ladenburg-INTAKT-001:~# netstat -anp|grep fastd
udp        0      0 192.168.0.165:35185     94.130.243.232:10000    ESTABLISHED 4389/fastd
[...]
root@Ladenburg-INTAKT-001:~# ip route show dev br-wan
default via 192.168.0.1 dev br-wan  src 192.168.0.165 
192.168.0.0/24 dev br-wan scope link  src 192.168.0.165

Die Frage ist: ist UDP 10000 auf der IPv4-Adreesse über den Router weiterhin ansprechbar? Wenn die fastd-Verbindung abbricht, ist das der IMHO übliche Grund dafür. (Was kommt bei tcpdump -n -i br-wan host 94.130.243.232 (bzw. der IPv4 des genutzten GWs)?)

Momentan kommuniziert fastd mit gw02 per IPv6 (2a01:4f8:140:4093:0:5eff:fe82:f3e8), und tcpdump zeigt auch starke Aktivität. Seit ich das WLAN-Mesh abgeschaltet habe, gab es keinen Ausfall mehr. Der Knoten läuft jetzt seit 2 Tagen und 12 Stunden ohne Störung.

Übrigens würde die fastd-Verbindung auch abbrechen, wenn fastd in einem Systemcall hängt (wie oben beschrieben), weil der Prozess dann einfach nichts mehr tut.

Vor rund 2 Stunden ist der Knoten wieder ausgefallen, zumindest aus Sicht der Benutzer.
Meine SSH-Verbindung per reverse ssh funktioniert noch.
DNS funktioniert nur über den Telekom-Router.
tcpdump -n -i br-wan host 138.201.30.247 (gw3) zeigt regen Datenverkehr:

root@Ladenburg-INTAKT-001:~# tcpdump -n -i br-wan host 138.201.30.247
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on br-wan, link-type EN10MB (Ethernet), capture size 262144 bytes
22:17:49.325391 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 78
22:17:49.325469 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 78
22:17:49.325499 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 122
22:17:49.326004 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 122
22:17:49.326053 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 122
22:17:49.326084 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 510
22:17:49.341303 IP 192.168.0.165.38866 > 138.201.30.247.10000: UDP, length 354
22:17:49.341432 IP 192.168.0.165.38866 > 138.201.30.247.10000: UDP, length 522
22:17:49.361210 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 430
22:17:49.361329 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 78
22:17:49.432884 IP 138.201.30.247.10000 > 192.168.0.165.38866: UDP, length 70

gw3 ist über IPv4 anpingbar, aber nicht über IPv6:

root@Ladenburg-INTAKT-001:~# ping6 2a01:4f8:171:3242:0:8aff:fec9:1ef7
PING 2a01:4f8:171:3242:0:8aff:fec9:1ef7 (2a01:4f8:171:3242:0:8aff:fec9:1ef7): 56 data bytes
ping6: sendto: Network unreachable

Auffälligkeiten in den Logausgaben:

Wed Jan 25 20:00:47 2023 kern.err kernel: [46109.946964] mt7915e 0000:02:00.0: Message 00005aed (seq 12) timeout
[Meldung kommt wiederholt]
Wed Jan 25 20:03:30 2023 daemon.notice netifd: client (2215): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": true, "data": { }, "keep": false, "ip6addr": [ { "ipaddr": "fdc3:67ce:cc7e:9001:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14388, "valid": 86388, "offlink": true }, { "ipaddr": "2a01:4f8:140:7700:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14388, "valid": 86388, "offlink": true }, { "ipaddr": "2a01:4f8:160:9700:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14388, "valid": 86388, "offlink": true }, { "ipaddr": "2a01:4f8:171:fcff:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14394, "valid": 86394, "offlink": true } ], "routes6": [ { "target": "fdc3:67ce:cc7e:9001::", "netmask": "64", "metric": 256, "valid": 86388 }, { "target": "::", "netmask": "0", "gateway": "fe80::68ff:94ff:fe00:404", "metric": 512, "valid": 1788 }, { "target": "2a01:4f8:140:7700::", "netmask": "64", "metric": 256, "valid": 86388 }, { "target": "::", "netmask": "0", "gateway": "fe80::68ff:94ff:fe00:2
[Meldung kommt wiederholt, die dabei gestarteten Prozesse sind vermutlich für den Last- und Speicheranstieg verantwortlich]
Wed Jan 25 20:03:30 2023 daemon.notice netifd: wan6 (2872): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": true, "data": { }, "keep": false, "ip6addr": [ { "ipaddr": "2a01:598:c839:1e31:70a2:96ff:fecb:fe80", "mask": "64", "preferred": 119, "valid": 299, "offlink": true } ], "routes6": [ { "target": "::", "netmask": "0", "gateway": "fe80::70d8:caff:fe93:ea56", "metric": 512, "valid": 299 }, { "target": "2a01:598:c839:1e31:1:0:cc62:57f0", "netmask": "64", "metric": 256, "valid": 299 } ], "interface": "wan6" } (Request timed out)
[...]
Wed Jan 25 20:55:03 2023 daemon.notice netifd: client (2215): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": true, "data": { }, "keep": false, "ip6
addr": [ { "ipaddr": "fdc3:67ce:cc7e:9001:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14400, "valid": 86400, "offlink": true }, { "ipaddr": "2a01:4f8:140:7700:baec:a3ff:fee0:f050
", "mask": "64", "preferred": 14376, "valid": 86376, "offlink": true }, { "ipaddr": "2a01:4f8:160:9700:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14400, "valid": 86400, "offlink
": true }, { "ipaddr": "2a01:4f8:171:fcff:baec:a3ff:fee0:f050", "mask": "64", "preferred": 14400, "valid": 86400, "offlink": true } ], "routes6": [ { "target": "fdc3:67ce:cc7e:9001::"
, "netmask": "64", "metric": 256, "valid": 86400 }, { "target": "::", "netmask": "0", "gateway": "fe80::68ff:94ff:fe00:404", "metric": 512, "valid": 1782 }, { "target": "2a01:4f8:140:
7700::", "netmask": "64", "metric": 256, "valid": 86376 }, { "target": "::", "netmask": "0", "gateway": "fe80::68ff:94ff:fe00:2
Wed Jan 25 20:55:23 2023 kern.err kernel: [49386.722776] mt7915e 0000:02:00.0: Message 00005aed (seq 7) timeout
[...]
Wed Jan 25 22:14:29 2023 daemon.notice netifd: radio0 (26031): Command failed: ubus call hostapd config_add {"iface":"client0", "config":"/var/run/hostapd-phy0.conf"} (Invalid argument)
Wed Jan 25 22:14:29 2023 daemon.notice netifd: radio0 (26031): Usage: ubus [<options>] <command> [arguments...]
[...]

Zusammenfassung meiner bisherigen Erkenntnisse:

Seit einer Woche ist der Knoten zuverlässig per Reverse SSH über IPv4 erreichbar und lässt sich so bei Ausfall ohne Vor-Ort-Einsatz wieder starten, was die Ausfallzeiten deutlich reduziert. Auch die Ausgabe von logread -f läuft permanent über die gleiche Verbindung. Es sieht daher so aus, als ob die Mobilfunkverbindung per IPv4 stabil ist, also wohl keine Hardwarestörung beim Anbieter, in der Speedbox oder auf dem Knoten vorliegt.

Am längsten lief der Knoten bisher, wenn das WLAN-Mesh zum zweiten und dritten Knoten eine gute Verbindung hatte (ganz am Anfang 7 d 21 h, danach wurde Knoten in anderen Raum gestellt) oder manuell deaktiviert war (4 d 4 h). Da Mesh über 2,4 GHz deutlich stabiler als über 5 GHz ist, habe ich heute früh Mesh für 5 GHz deaktiviert in der Hoffnung, das damit Ausfälle weniger häufig vorkommen.

Bei den letzten Ausfällen zeigte tcpdump, dass nach wie vor Daten mit einem Gateway ausgetauscht wurden. Es fällt auf, dass ein Ausfall praktisch immer zeitgleich mit einem Wechsel des Mesh Links auftritt.

Vorhin gab es um 14:20 einen erneuten Ausfall, allerdings mit neuem Fehlerbild: der Knoten blieb weiterhin von außerhalb noch anpingbar, die Statusseite des Knoten war per HTTP erreichbar, und die Knoten 2 und 3 liefen durchgehend normal, also mit angemeldeten Clients und Statusmeldungen.

https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=a63430eac33ceb1dbf96d3667e2a0f2e04ba391f

Der Commit behebt wohl das Problem das Mesh Verbindungen mittels 802.11ax maximal 54 Mbit/s hatten.

Es wird wohl zeitnah ein neues Gluon geben wo dann auch der Fix drin ist. Mal schauen wie es dann damit alles aussieht.

1 „Gefällt mir“

Es gibt nun endlich Mal wieder eine aktuelle Nightly auf Basis des aktuellen Gluon Master Branch.
Ich werde die Tage aber wohl auch Experimental Firmware auf Basis des gestrigen Gluon Releases bauen.

OpenWRT müsste zwischen Release und master gleich sein. In master sind aber ein paar Gluon spezifische Neuerungen welche erst im nächsten Major Gluon Release landen werden weil sie nicht backported wurden.

Diese Firmware läuft inzwischen auf einem der Knoten ( Ladenburg-INTAKT-003), bisher ohne Auffälligkeiten.

1 „Gefällt mir“

Seit drei Tagen laufen auch die beiden Knoten Ladenburg-INTAKT-001 und Ladenburg-INTAKT-002 mit der Nightly Firmware.

Der nur per WLAN-Mesh angebundene Knoten Ladenburg-INTAKT-003, der zuerst diese Firmware bekam und zuvor 39 Tage durchgehalten hatte, ist seit gestern Abend genau um 20:00 nicht mehr erreichbar. Ohne Vor-Ort-Termin mit den Hausmeistern kann ich leider nichts machen.