Ausfall Freifunk-Knoten mit unklarer Ursache

Technik
21

Auf der Seite des Knoten bin ich mit der Problemanalyse auch etwas weiter gekommen. Der praktisch bei jedem Ausfall beobachtete Anstieg des Speicherverbrauchs scheint real zu sein. Ich habe mit ps und top gesehen, dass es gleichzeitig eine wachsende Anzahl von ubus Prozessen gab, vermutlich die gleichen, die auch in einigen Logdateien aufgezeichnet sind:

ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan" }

Ich interpretiere das so, dass das Interface wan eine Aktion triggert, obwohl eine gleichartige Aktion noch ausgeführt wird. Das erscheint mir nicht sinnvoll zu sein. Und zu klären wäre auch, warum diese Aktionen scheinbar nicht weiterkommen.

22

Wie kann ich auf dem Knoten die Verbindung zum Gateway trennen und neu aufbauen lassen? Das wäre vielleicht eine gute Alternative zu reboot und könnte auch zeitgesteuert z. B. alle 4 Stunden automatisch gemacht werden.

23

/etc/init.d/fastd restart && exit 0

1 „Gefällt mir“
24

Das funktioniert leider nicht als Abhilfe, wenn der Knoten offline geht, zunächst weil der Prozess fastd nicht terminiert. Erst mit kill -KILL beendet er sich nach etlichen Minuten. Danach lässt sich fastd neu starten, was aber die Verbindung zum Gateway nicht repariert. DNS funktioniert darüber nach wie vor nicht. Über den angeschlossenen Mobilfunkrouter funktioniert glücklicherweise mein Zugang über Reverse SSH mit IPv4, und darüber funktioniert auch DNS problemlos.

Bei den letzten Ausfällen wie gerade um 18:30 musste ich letzten Endes den Knoten neu starten, damit er wieder normal läuft.

25

Nach einem schon älteren ähnlichen Fehlerbericht von 2016 könnte es sich bei den Ausfällen meines Freifunk-Knotens um ein generelles Problem von Freifunk-Meshs, die sich per WLAN verbinden, handeln.

Das könnte ich am einfachsten überprüfen, indem ich am ersten Knoten das Mesh ausschalte. Geht das von der Kommandozeile aus? Update: iw dev mesh0 mesh leave hat das WLAN-Mesh erfolgreich stillgelegt.

Umgekehrt wären Meshs per WLAN, die trotz starker Nutzung sehr lange ohne Störung laufen, ein Indiz gegen obige Vermutung.

26

https://wiki.freifunk.net/Konsole

27

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).

28

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“
29

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.

30

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
31

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.

32

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.

33

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

34

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

35

Ü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.)

36

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
37

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)?)

38

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.

39

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
40

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...]
[...]