Mehrminütiger Ausfall im 60 Minuten-Takt

Sie wurden von hinten erschossen :roll_eyes:

Ich glaube ich habe den Fehler!

root@33378-a42bb0f43a87:~# /usr/sbin/autoupdater-wifi-fallback
autoupdater-wifi-fallback: connectivity check failed
autoupdater-wifi-fallback: going to fallback mode
autoupdater-wifi-fallback: connecting to radio0 KreisGT.freifunk.net 7E:8A:20:28:73:CB
autoupdater-wifi-fallback: executing the autoupdater…
Retrieving manifest from http://firmware.ipv6.4830.org/experimental/sysupgrade/experimental.manifest
autoupdater: warning: error downloading manifest: Connection failed
autoupdater: error: no usable mirror found
autoupdater-wifi-fallback: connecting to radio1 test-KreisGT.freifunk.net 1E:00:53:42:06:48
autoupdater-wifi-fallback: executing the autoupdater…
Retrieving manifest from http://firmware.ipv6.4830.org/experimental/sysupgrade/experimental.manifest
autoupdater: warning: error downloading manifest: Connection failed
autoupdater: error: no usable mirror found
autoupdater-wifi-fallback: connecting to radio1 owe.KreisGT.freifunk.net 1E:00:53:42:06:4A
autoupdater-wifi-fallback: executing the autoupdater…
Retrieving manifest from http://firmware.ipv6.4830.org/experimental/sysupgrade/experimental.manifest
autoupdater: warning: error downloading manifest: Connection failed
autoupdater: error: no usable mirror found
autoupdater-wifi-fallback: going back to standard mode
root@33378-a42bb0f43a87:~#

Nachdem ich den Fehler hier in Wiedenbrück auch immer wieder um ca. Minute 40 hatte und ich heute einen Tag frei hatte bin ich der sache etwas auf die Schliche gekommen.

Die Firmware Seite ist per IPv6 aktuell nicht erreichbar. Das habe ich schon länger gesehen. Aber bisher nicht als problematisch angesehen.

Die Fallback Option ist besonders brsinat im Offloader Einsatz mit VLAN, da zumindestens auf meinem Archer C7 die br-client Bridge zerlegt wird und nachher nicht wieder richtig zusammen gebaut wird. Auf allen anderen Systemen scheint das der Fall zu sein. (Was ich aber noch nicht getestet habe).

Warum passiert jetzt der Fehler überall zu ein anderen Zeit, … Ich habe mir gerade vier Knoten angeschaut. Dort steht überall eine andere Minute drin.

@wusel bitte die Firmware Seite wieder sauber zuänglich aus dem Netz machen. Ich gehe dann davon aus das alles wieder läuft.

Hallo Zusammen,

die letzten zwei Wochen habe ich diverse Tests durchgeführt, um die Probleme etwas genauer einzugrenzen.

Disclaimer
Ich bin in dem Thema Freifunk erst neu dabei. Es mag also vorkommen, dass ich aufgrund fehlender Erfahrung falsche Annahmen treffe.
Macht mich dann einfach darauf aufmerksam. :slight_smile:

Ergebnisse meiner Test:

Es ist für mich nachgewiesen, dass diese langfristigen Ausfällen von zwischen 10-45 Minuten des Routers zum Freifunk-Netz nicht auftreten, wenn ich die dahinter geschaltete Umgebung (PCs im VLAN & WLAN-Umgebung) abschalte.
Ich also das Patchkabel aus den LAN-Anschlüssen der Fritzbox entferne.

Nutze ich Freifunk als nur an der Fritzbox, dann scheint es keine Langfristigen Ausfälle zu geben.
Es mag aber sein, dass es kurzfristigere Ausfälle (2-3 Minuten) gibt, die sich meinem Fokus und meinen Prüfmitteln entziehen.

Somit ging ich erst davon aus, dass ich für die Probleme selbst verantwortlich bin.
Ich habe jetzt aber ein paar Stunden in die Prüfung des Ganzen gesetzt und finde keine konkreten Fehler in meiner Umgebung hinter der Fritzbox.

Ich konnte zusätzlich nachvollziehen, dass die Fehler auch nicht auftreten, wenn ich mein geplantes Konzept (WLAN-APS und Clients hinter Fritzbox) ausführe, aber das Freifunk-WLAN mit einem Kennwort versehe.
Damit wollte ich nachvollziehen, ob die Fehler auch auftreten, wenn nur wenige Geräte über den Kabel-Anschluss der Fritzbox kommen.
Ich kann das verneinen und auch bestätigen.
Manchmal kam der Fehler nicht mehr vor (8 angeschlossene Endgeräte per externem AP also per VLAN hinter Fritzbox) und dann aber manchmal doch (Nur vier verbundene Clients am externen AP).

Fazit meiner Tests

Die Ergebnisse ermöglichen mir nicht den Fehler genau zu orten.
Somit habe ich mich auch nochmal mit @Thomas Aussage beschäftigt, was mir auch recht schlüssig vorkommt.

Referenz auf @Thomas Aussage

Ich kann seine Vermutung total unterstützen.
Das deckt sich ziemlich gut mit meiner Umgebung.

Einmal vorweg
Ich habe bislang keinen SSH-Zugang zu den Freifunk-Fritzboxen gehabt, weshalb ich noch keine Tests direkt auf diesen durchführen konnte. Müsste ich mich nochmal dransetzen.

Er sagt ja, dass die URL für das automatische Prüfen der Firmware nicht erreichbar ist und ihm das die „BR-Client Bridge“ zerlegt.

Könnte das dann nicht auch erklären, warum die Fritzbox bei mir dann versucht das Freifunk-LAN Gateway „10.234.160.74“ dann über seinen eigenen WAN-Anschluss zu erreichen, was natürlich nicht geht.

Zitat von @Thomas
Die Fallback Option ist besonders brsinat im Offloader Einsatz mit VLAN, da zumindestens auf meinem Archer C7 die br-client Bridge zerlegt wird und nachher nicht wieder richtig zusammen gebaut wird.

Ich kann mit meinen Tests z.B. bestätigen, dass der Fehler auch nur bei der Nutzung der Frizbox als Offloader stattfindet.
Das passt also auch ins Bild.

Meine Theorie (Achtung gefährliches Halbwissen)

Ich glaube, dass diese Regelmäßigkeit (Ausfall alle 60 Minuten) daher kommt, dass die Frizbox allen 60 Minuten (nach Systemstart??) prüft ob eine neue Firmware verfügbar ist.
Das schlägt dann aber fehl, da die Firmware-Webseite nicht aufrufbar ist.

Das sollte dann ja eigentlich kein Problem sein, doch irgendwie bricht dann dabei die „BR-Client Bridge“ weg und somit besteht keine Verbindung mehr von der FF-Fritzbox zum Freifunk-Netz.

Irgendwann fängt sich der Freifunk-Router dann wieder und zu den nächsten vollendeten 60 Minuten passierts dann wieder.

Ich habe das Gefühl, dass die Intensität des Ausfalls auch irgendwas mit der Anzahl hinterm Offloader angeschlossener Endgeräte zu tun hat.
Als ich eben nur 5 WLAN-Endgeräte hinter meiner Umgebung, also per Kabel an der Fritzbox verwendet habe, konnte ich einen 1-3 Minütigen (Mini-Ausfall) zum üblichen Zeitpunkt feststellen.
Dieser war aber nicht massiv genug, dass der Router in der Freifunk-Oberfläche als Offline angezeigt wurde.
Offensichtlich hat der Router sich dann schnell genug gefangen.

Dass dieses Problem nicht bei allen Teilnehmern des Freifunk-GT-Netzes auffällt, könnte ja an genau diese Kombination liegen.
Nutzung des Routers als Offloader && Notwendigkeit von mehren Geräten hinter diesem.

Erreichbarkeit von firmware.ipv6.4830.org && firmware.4830.org

Wichtige Rückfrage
Habt Ihr heute Vormittag daran gearbeitet?

Eben konnte ich keine Verbindung auf Diensten (443, 80 und PING) per IPV4 wie auch IPV6 auf die beiden URLs hinbekommen.
Mittlerweile ist die Adresse „firmware.4830.org“ wieder ganz normal per IPv4 erreichbar.

Test von heute morgen

Fazit

Ich könnte mir jedenfalls auch vorstellen, dass es etwas mit der Erreichbarkeit des Update-Services zu tun hat.
Ich denke, dass es auf jeden Fall einen Versuch wert wäre, dies wieder in Betreib zu nehmen.

Moin.

Heute habe ich den Fehler bzw. er mich „life“ erwischt.
Der Router hängt direkt hinter einer FritzBox(DSL)
Nach dem Fehler braucht er eine Ewigkeit, bis er wieder erreichbar und Freifunk für die Clients nutzbar ist.
Hilf da den Autoupdate zu deaktivieren? :thinking:

17209-Sietow-Hafen
17209-Sietow-Hafen - StatusPage
Das Gateway war gerade … 02:ca:ff:ee:05:81

Die letzten Zeilen im Logfile waren …

Sun May 19 16:52:00 2024 user.notice ssid-changer: autoupdater is running, aborting.
Sun May 19 16:52:05 2024 user.info : autoupdater-wifi-fallback: connectivity check failed
Sun May 19 16:52:05 2024 user.info : autoupdater-wifi-fallback: going to fallback mode
Sun May 19 16:52:05 2024 kern.info kernel: [24382.503847] IPv6: ADDRCONF(NETDEV_UP): tmp.mesh0: link is not ready
Sun May 19 16:52:12 2024 kern.info kernel: [24389.247681] IPv6: ADDRCONF(NETDEV_UP): tmp.mesh1: link is not ready
Sun May 19 16:52:14 2024 user.info : autoupdater-wifi-fallback: connecting to radio0 mueritz.freifunk.net_EXT A8:42:A1:36:99:55
Sun May 19 16:52:14 2024 daemon.notice netifd: Interface 'mesh_radio0' is disabled
Sun May 19 16:52:14 2024 daemon.notice netifd: Interface 'mesh_radio0' has link connectivity loss
Sun May 19 16:52:14 2024 kern.info kernel: [24391.222973] device client0 left promiscuous mode
Sun May 19 16:52:14 2024 kern.info kernel: [24391.228012] br-client: port 3(client0) entered disabled state
Sun May 19 16:52:14 2024 kern.info kernel: [24391.267371] device owe0 left promiscuous mode
Sun May 19 16:52:14 2024 kern.info kernel: [24391.272266] br-client: port 4(owe0) entered disabled state
Sun May 19 16:52:14 2024 daemon.notice netifd: Interface 'mesh_radio1' is disabled
Sun May 19 16:52:14 2024 daemon.notice netifd: Interface 'mesh_radio1' has link connectivity loss
Sun May 19 16:52:14 2024 kern.info kernel: [24391.361390] device client1 left promiscuous mode
Sun May 19 16:52:14 2024 kern.info kernel: [24391.367620] br-client: port 5(client1) entered disabled state
Sun May 19 16:52:14 2024 kern.info kernel: [24391.444211] device owe1 left promiscuous mode
Sun May 19 16:52:14 2024 kern.info kernel: [24391.450221] br-client: port 6(owe1) entered disabled state
Sun May 19 16:52:14 2024 kern.info kernel: [24391.719535] batman_adv: bat0: Interface deactivated: mesh0
Sun May 19 16:52:14 2024 kern.info kernel: [24391.725897] batman_adv: bat0: Removing interface: mesh0
Sun May 19 16:52:15 2024 daemon.notice netifd: Interface 'mesh_radio0' is now down
Sun May 19 16:52:15 2024 kern.info kernel: [24391.914904] batman_adv: bat0: Interface deactivated: mesh1
Sun May 19 16:52:15 2024 kern.info kernel: [24391.920616] batman_adv: bat0: Removing interface: mesh1
Sun May 19 16:52:15 2024 daemon.notice netifd: Interface 'mesh_radio1' is now down
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: interface state ENABLED->DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: owe0: AP-DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: owe0: CTRL-EVENT-TERMINATING
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: Failed to remove interface owe0 from bridge br-client: No such device
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: AP-STA-DISCONNECTED 9a:4b:78:40:da:72
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: AP-STA-DISCONNECTED aa:69:d6:51:19:b2
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: AP-STA-DISCONNECTED ae:42:a1:36:99:55
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: AP-DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: client0: CTRL-EVENT-TERMINATING
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: deinit ifname=client0 disabled_11b_rates=0
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: Failed to remove interface client0 from bridge br-client: Invalid argument
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: interface state ENABLED->DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: owe1: AP-DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: owe1: CTRL-EVENT-TERMINATING
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: Failed to remove interface owe1 from bridge br-client: No such device
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: AP-STA-DISCONNECTED 12:64:22:25:0d:08
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: AP-STA-DISCONNECTED aa:69:d6:51:19:b2
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: AP-STA-DISCONNECTED f2:14:0b:37:a9:99
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: AP-STA-DISCONNECTED aa:42:a1:06:99:54
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: AP-DISABLED
Sun May 19 16:52:15 2024 daemon.notice hostapd: client1: CTRL-EVENT-TERMINATING
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: deinit ifname=client1 disabled_11b_rates=0
Sun May 19 16:52:15 2024 daemon.notice hostapd: nl80211: Failed to remove interface client1 from bridge br-client: Invalid argument
Sun May 19 16:52:19 2024 kern.warn kernel: [24396.576048] ath10k_pci 0000:01:00.0: pdev param 0 not supported by firmware
Sun May 19 16:52:19 2024 kern.info kernel: [24396.603816] IPv6: ADDRCONF(NETDEV_UP): fallback: link is not ready
Sun May 19 16:52:19 2024 kern.info kernel: [24396.743924] fallback: authenticate with a8:42:a1:36:99:55
Sun May 19 16:52:19 2024 kern.info kernel: [24396.758474] fallback: send auth to a8:42:a1:36:99:55 (try 1/3)
Sun May 19 16:52:19 2024 kern.info kernel: [24396.765737] fallback: authenticated
Sun May 19 16:52:20 2024 kern.info kernel: [24396.776517] fallback: associate with a8:42:a1:36:99:55 (try 1/3)
Sun May 19 16:52:20 2024 kern.info kernel: [24396.784641] fallback: RX AssocResp from a8:42:a1:36:99:55 (capab=0x1901 status=0 aid=1)
Sun May 19 16:52:20 2024 kern.info kernel: [24396.796628] fallback: associated
Sun May 19 16:52:20 2024 kern.info kernel: [24396.800197] IPv6: ADDRCONF(NETDEV_CHANGE): fallback: link becomes ready
Sun May 19 16:52:20 2024 daemon.notice netifd: radio0 (8643): fallback (phy #0): unknown event 46
Sun May 19 16:52:20 2024 daemon.notice netifd: radio0 (8643): cat: can't open '/var/run/wpa_supplicant-fallback.pid': No such file or directory
Sun May 19 16:52:20 2024 daemon.notice netifd: radio0 (8643): WARNING (wireless_add_process): executable path /usr/sbin/wpa_supplicant does not match process  path (/proc/exe)
Sun May 19 16:52:20 2024 kern.debug kernel: [24396.893249] fallback: Limiting TX power to 35 (35 - 0) dBm as advertised by a8:42:a1:36:99:55
Sun May 19 16:52:20 2024 daemon.notice netifd: radio0 (8643): Command failed: Invalid argument
Sun May 19 16:52:20 2024 daemon.notice netifd: Network device 'fallback' link is up
Sun May 19 16:52:20 2024 daemon.notice netifd: Interface 'fallback' is enabled
Sun May 19 16:52:20 2024 daemon.notice netifd: Interface 'fallback' has link connectivity
Sun May 19 16:52:20 2024 daemon.notice netifd: Interface 'fallback' is setting up now
Sun May 19 16:52:20 2024 daemon.notice netifd: fallback (8955): udhcpc: started, v1.30.1
Sun May 19 16:52:20 2024 daemon.notice netifd: fallback (8955): udhcpc: sending discover
Sun May 19 16:52:21 2024 daemon.notice netifd: fallback (8955): udhcpc: sending select for 10.234.194.101
Sun May 19 16:52:21 2024 daemon.notice netifd: fallback (8955): udhcpc: lease of 10.234.194.101 obtained, lease time 300

Danke für die Logzeilen; ich fasse die Threads mal zusammen, da vermutlich gleiches Problem …

Autoupdater deaktivieren hilft. Ich habe den cron Job auf alle 24h gesetzt.

Ich hab’s auch gerade live erleben dürfen, nachdem ich im Smokeping der VM hinter der Mesh04-Gluon-VM das Muster gefunden und das Remotelogging gefixt hatte:


(Zeiten in UTC)

MTRs vom Knoten zum Gateway und vom Clieent (durch das GW) zu 1.1.1.1:

33378-test-20240502 (192.168.177.14)                   2024-05-20T01:30:05+0200
Keys:  Help   Display mode   Restart statistics   Order of fields   quit
                                       Packets               Pings
 Host                                Loss%   Snt   Last   Avg  Best  Wrst StDev
 1. 192.168.177.1                     0.0%  1370    1.2   0.7   0.6  12.3   0.4
 2. p3e9bf2e7.dip0.t-ipconnect.de     0.0%  1370    7.5  10.1   7.4  74.6   7.5
 3. b-eh2-i.B.DE.NET.DTAG.DE          0.0%  1370   13.8  14.0  13.0  65.6   3.7
 4. bgp-ber01.4830.org               10.9%  1370   14.0  14.2  13.6  62.6   3.2
 5. ngw-ber01.4830.org                0.5%  1370   13.7  14.1  13.6  41.0   2.8

­

                              My traceroute  [v0.95]
 test-mesh02 (10.234.147.250) -> 1.1.1.1 (1.1.1.1)               2024-05-19T23:31:06+0000
 Keys:  Help   Display mode   Restart statistics   Order of fields   quit
                                        Packets               Pings
  Host                                Loss%   Snt   Last   Avg  Best  Wrst StDev
  1. 10.234.144.70                     2.0%  1436   22.2  23.3  22.0  48.5   3.3
  2. 194.113.54.65                    86.7%  1436   43.2  24.0  22.0  44.4   2.9
  3. wobcom.n15.community-ix.de        2.6%  1436   24.4  24.6  22.7  71.1   4.2
  4. et-0-0-2-0.cbrc1101.as9136.net    1.5%  1436   24.2  25.3  22.9 107.8   5.5
  5. cloudflare.bcix.de                3.1%  1436   31.9  29.6  22.9 117.1  11.3
  6. one.one.one.one                   2.9%  1436   23.7  24.7  22.7  72.9   4.2

Logs via remote logging:

May 20 00:57:10 33378-test-20240502 netifd: wan (2926): udhcpc: lease of 192.168.177.14 obtained, lease time 600
May 20 00:57:45 33378-test-20240502 netifd: client (2940): cat: write error: Broken pipe
May 20 00:59:59 33378-test-20240502 netifd: client (2940): cat: write error: Broken pipe
May 20 01:00:23 33378-test-20240502 netifd: client (2940): cat: write error: Broken pipe
May 20 01:01:01 33378-test-20240502 netifd: client (2940): cat: write error: Broken pipe
May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: connectivity check failed
May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: going to fallback mode
May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: going back to standard mode
May 20 01:02:10 33378-test-20240502 netifd: Interface 'bat0' is now down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'loopback' is now down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'loopback' is disabled
May 20 01:02:10 33378-test-20240502 netifd: Network device 'lo' link is down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'loopback' has link connectivity loss
May 20 01:02:10 33378-test-20240502 dnsmasq[1767]: no servers found in /tmp/resolv.conf.auto, will retry
May 20 01:02:10 33378-test-20240502 kernel: [1477775.080263] batman_adv: bat0: Interface deactivated: primary0
May 20 01:02:10 33378-test-20240502 kernel: [1477775.082326] batman_adv: bat0: Removing interface: primary0
May 20 01:02:10 33378-test-20240502 kernel: [1477775.084741] batman_adv: bat0: Interface deactivated: mesh-vpn
May 20 01:02:10 33378-test-20240502 kernel: [1477775.086576] batman_adv: bat0: Removing interface: mesh-vpn
May 20 01:02:10 33378-test-20240502 kernel: [1477775.089627] br-client: port 2(bat0) entered disabled state
May 20 01:02:10 33378-test-20240502 netifd: Network device 'bat0' link is down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'bat0' has link connectivity loss
May 20 01:02:10 33378-test-20240502 netifd: Interface 'client' is now down
May 20 01:02:10 33378-test-20240502 kernel: [1477775.137227] device bat0 left promiscuous mode
May 20 01:02:10 33378-test-20240502 kernel: [1477775.138743] br-client: port 2(bat0) entered disabled state
May 20 01:02:10 33378-test-20240502 kernel: [1477775.142172] br-client: port 1(eth0) entered disabled state
May 20 01:02:10 33378-test-20240502 netifd: Interface 'bat0' is disabled
May 20 01:02:10 33378-test-20240502 kernel: [1477775.205729] device eth0 left promiscuous mode
May 20 01:02:10 33378-test-20240502 kernel: [1477775.207360] br-client: port 1(eth0) entered disabled state
May 20 01:02:10 33378-test-20240502 kernel: [1477775.214720] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
May 20 01:02:10 33378-test-20240502 netifd: Interface 'client' is disabled
May 20 01:02:10 33378-test-20240502 netifd: Interface 'gluon_bat0' is now down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'mesh_vpn' is now down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'mesh_vpn' is disabled
May 20 01:02:10 33378-test-20240502 netifd: Network device 'eth0' link is down
May 20 01:02:10 33378-test-20240502 netifd: bridge 'br-client' link is down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'client' has link connectivity loss
May 20 01:02:10 33378-test-20240502 netifd: Network device 'mesh-vpn' link is down
May 20 01:02:10 33378-test-20240502 netifd: Interface 'mesh_vpn' has link connectivity loss
May 20 01:02:10 33378-test-20240502 netifd: wan (2926): udhcpc: sending renew to 192.168.177.9
May 20 01:02:10 33378-test-20240502 netifd: wan (2926): udhcpc: received SIGTERM
May 20 01:02:10 33378-test-20240502 netifd: Interface 'wan' is now down
May 20 01:02:12 33378-test-20240502 logread[1715]: Logread connected to 192.168.177.9:514
May 20 01:02:13 33378-test-20240502 odhcp6c[15979]: Failed to send DHCPV6 message to ff02::1:2 (Address not available)
May 20 01:02:13 33378-test-20240502 odhcp6c[15981]: Failed to send DHCPV6 message to ff02::1:2 (Address not available)
May 20 01:02:13 33378-test-20240502 odhcp6c[15981]: Failed to send DHCPV6 message to ff02::1:2 (Address not available)
May 20 01:02:15 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:16 33378-test-20240502 netifd: Interface 'wan6' is now up
May 20 01:02:16 33378-test-20240502 firewall: Reloading firewall due to ifup of wan6 (br-wan)
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: reading /var/gluon/wan-dnsmasq/resolv.conf
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: using nameserver fd00::9a9b:cbff:feb1:1397#53
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: using nameserver 2003:ef:9f17:8900:9a9b:cbff:feb1:1397#53
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: using nameserver 192.168.177.9#53
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: using nameserver 192.168.177.1#53
May 20 01:02:16 33378-test-20240502 dnsmasq[2613]: using nameserver 8.8.8.8#53
May 20 01:02:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:22 33378-test-20240502 kernel: [1477786.797900] batman_adv: bat0: IGMP Querier appeared
May 20 01:02:22 33378-test-20240502 kernel: [1477786.799860] batman_adv: bat0: MLD Querier appeared
May 20 01:02:27 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:33 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:39 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:45 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:51 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:02:57 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:03:03 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:03:09 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=5)!
May 20 01:03:10 33378-test-20240502 td-client: [g02m04.4830.org:10004] Tunnel has timed out, closing down interface.
May 20 01:03:10 33378-test-20240502 td-client: [g02m04.4830.org:10004] Failed to send() control packet (errno=19, type=3)!
May 20 01:03:10 33378-test-20240502 netifd: Network device 'mesh-vpn' link is down
May 20 01:03:10 33378-test-20240502 netifd: Interface 'mesh_vpn' has link connectivity loss
May 20 01:03:10 33378-test-20240502 kernel: [1477834.469730] batman_adv: bat0: Interface deactivated: mesh-vpn
May 20 01:03:10 33378-test-20240502 kernel: [1477834.485739] batman_adv: bat0: Removing interface: mesh-vpn
May 20 01:03:10 33378-test-20240502 td-client: [g02m04.4830.org:10004] Connection lost.
May 20 01:03:10 33378-test-20240502 td-client: for(;;) -- context_reinitialize() for all brokers.
May 20 01:03:10 33378-test-20240502 netifd: Interface 'mesh_vpn' is now down
May 20 01:03:10 33378-test-20240502 netifd: Interface 'mesh_vpn' is disabled
May 20 01:03:10 33378-test-20240502 td-client: Performing broker selection...
May 20 01:03:10 33378-test-20240502 td-client: Brokers deemed working: 6
May 20 01:03:10 33378-test-20240502 td-client: main loop -- Reset availability information and standby setting.
May 20 01:03:10 33378-test-20240502 td-client: [g01m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: [g02m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: [g03m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: [g04m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: [g05m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: [g06m04.4830.org:10004] is not flagged as broken, that's good.
May 20 01:03:10 33378-test-20240502 td-client: main loop -- Perform broker processing for 10 seconds or until all brokers are ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] Broker's FQDN has been resolved to 194.113.55.67.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_GET_USAGE, sending initial request.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] Broker's FQDN has been resolved to 194.113.54.80.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_GET_USAGE, sending initial request.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] Broker usage: 384
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] Broker usage: 448
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] Broker's FQDN has been resolved to 194.113.54.81.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_GET_USAGE, sending initial request.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] Broker's FQDN has been resolved to 194.113.55.71.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_GET_USAGE, sending initial request.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] Broker usage: 384
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] Broker usage: 384
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:11 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g04m04.4830.org:10004] is ready.
May 20 01:03:11 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:11 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
[…]
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_REINIT.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] reinitializing tunnel context.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] Failed to resolve hostname.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] Failed to resolve hostname.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_REINIT.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] reinitializing tunnel context.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is in STATE_STANDBY
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_REINIT.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] reinitializing tunnel context.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] Broker's FQDN hasn't been resolved to an IP yet.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is in STATE_RESOLVING
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] Failed to resolve hostname.
May 20 01:03:21 33378-test-20240502 td-client: [g01m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g03m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g04m04.4830.org:10004] is ready.
May 20 01:03:21 33378-test-20240502 td-client: [g05m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: [g06m04.4830.org:10004] is NOT ready.
May 20 01:03:21 33378-test-20240502 td-client: main loop -- select_broker()
May 20 01:03:21 33378-test-20240502 td-client: Selected g02m04.4830.org:10004 as the best broker.
May 20 01:03:21 33378-test-20240502 td-client: main loop -- activate selected broker
May 20 01:03:21 33378-test-20240502 td-client: main loop -- Perform processing on the main context ...
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_GET_COOKIE
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] sending request for a tasty cookie ...
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] is in STATE_GET_TUNNEL
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] sending tunnel setup request ...
May 20 01:03:21 33378-test-20240502 netifd: Interface 'mesh_vpn' is enabled
May 20 01:03:21 33378-test-20240502 netifd: Network device 'mesh-vpn' link is up
May 20 01:03:21 33378-test-20240502 netifd: Interface 'mesh_vpn' has link connectivity
May 20 01:03:21 33378-test-20240502 netifd: Interface 'mesh_vpn' is setting up now
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] Tunnel successfully established.
May 20 01:03:21 33378-test-20240502 td-client: [g02m04.4830.org:10004] Setting MTU to 1364
May 20 01:03:21 33378-test-20240502 netifd: Interface 'mesh_vpn' is now up
May 20 01:03:21 33378-test-20240502 kernel: [1477845.462835] batman_adv: bat0: Adding interface: mesh-vpn
May 20 01:03:21 33378-test-20240502 kernel: [1477845.465202] batman_adv: bat0: The MTU of interface mesh-vpn is too small (1364) to handle the transport of batman-adv packets. Packets going over this interface will be fragmented on layer2 which could impact the performance. Setting the MTU to 1532 would solve the problem.
May 20 01:03:21 33378-test-20240502 kernel: [1477845.477372] batman_adv: bat0: Interface activated: mesh-vpn
May 20 01:03:21 33378-test-20240502 firewall: Reloading firewall due to ifup of mesh_vpn (mesh-vpn)
May 20 01:03:22 33378-test-20240502 gluon-radv-filterd[16072]: Switching to f2:be:ef:00:04:71 (TQ=0)
May 20 01:03:29 33378-test-20240502 netifd: Interface 'client' is now up
May 20 01:03:29 33378-test-20240502 dnsmasq[1767]: reading /tmp/resolv.conf.auto
May 20 01:03:29 33378-test-20240502 dnsmasq[1767]: using local addresses only for domain lan
May 20 01:03:29 33378-test-20240502 dnsmasq[1767]: using nameserver 2620:fe::9#53
May 20 01:03:29 33378-test-20240502 dnsmasq[1767]: using nameserver 2606:4700:4700::1112#53
May 20 01:03:29 33378-test-20240502 firewall: Reloading firewall due to ifup of client (br-client)
May 20 01:03:37 33378-test-20240502 td-client: main loop -- connection established, broker [g02m04.4830.org:10004] is fine.
May 20 01:04:13 33378-test-20240502 netifd: client (15981): cat: write error: Broken pipe
May 20 01:06:19 33378-test-20240502 netifd: client (15981): cat: write error: Broken pipe
May 20 01:07:11 33378-test-20240502 netifd: wan (15971): udhcpc: sending renew to 192.168.177.9
May 20 01:07:11 33378-test-20240502 netifd: wan (15971): udhcpc: lease of 192.168.177.14 obtained, lease time 600
May 20 01:07:11 33378-test-20240502 firewall: Reloading firewall due to ifupdate of wan (br-wan)
May 20 01:07:48 33378-test-20240502 netifd: client (15981): cat: write error: Broken pipe
May 20 01:08:29 33378-test-20240502 netifd: client (15981): cat: write error: Broken pipe

Problem 1:

May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: connectivity check failed
May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: going to fallback mode
May 20 01:02:10 33378-test-20240502 : autoupdater-wifi-fallback: going back to standard mode

Das dürfte nicht passieren, a) nicht der »connectivity check failed«, b) nicht »going to fallback mode« & »going back to standard mode« direkt nacheinander.

Problem 2:

May 20 01:03:10 33378-test-20240502 td-client: main loop -- Perform broker processing for 10 seconds or until all brokers are ready.

In den meisten Meshes haben wir 2 GWs mehr in der Firmware hinterlegt als tatsächlich vorbereitet/genutzt. Hier in Mesh 4 sind z. B. g05m04.4830.org und g06m04.4830.org nicht im DNS eingetragen. Heißt bei Problemen mit dem Tunnel gibt es ggf. immer <= 10 Strafsekunden :frowning:

Zu Problem 1: das lua-Skript /usr/sbin/autoupdater-wifi-fallback testet erst, ob eines der Batman-Gateways via batman-ping (»nur ein Ping«) erreichbar ist. Falls nicht(!), wird versucht, den/die eingetragenen Updateserver per ICMP-Ping (»nur ein einziges Ping!«) zu erreichen — schlägt das auch(!) fehl, wird der Katastrophenfall ausgerufen.

Insofern kann …

… tatsächlich effektiv zur Problemlösung beitragen. Reallocating resources …

Problem sollte nun behoben sein, firmware.ipv6.4830.org ist AFAICS aus allen Meshes wieder erreichbar. Und eine neue rawhide-Firmware mit erweitertem Logging im autoupdater-wifi-fallback-Package – was spannenderweise schon am Sonntag, testweise auf meinem Knoten installiert, die Aussetzer verschwinden lies – wurde auch schon von zwei Knoten gezogen:

Screenshot 2024-05-21 at 23-59-05 4830.org e. V

Ohne neue Firmware scheint es auch wieder gut zu sein.

root@33378-TH-Test300e:~# /usr/sbin/autoupdater-wifi-fallback

root@33378-TH-Test300e:~#


root@33378-a42bb0f43a87:~# /usr/sbin/autoupdater-wifi-fallback

root@33378-a42bb0f43a87:~#

Es gibt zwar keine Ausgabe, aber auch kein Versuch die Firmware abzurufen, da der Autoupdater es vorher scheinbar schon geschafft hat. (Der Testknoten ist nur per Wifi Mesh angebunden)

1 „Gefällt mir“

Hallo Zusammen,

also bislang sieht bei mir auch alles wieder gut aus. :blush:

In beiden Standorten ist in den letzten Zwei Tagen kein Ausfall mehr aufgetreten.

Ich behalte es im Auge, doch denke ich, dass es sich somit erledigt hat.
Danke @wusel und @Thomas

2 „Gefällt mir“

Moin.

gerade hat der o.g. Knoten 17194-Joy-IT-126f wieder die Connection verloren. :sob:
Zusätzlich ist mir letztens aufgefallen, dass nach jedem Connection-Verlust die Traffic-Statistik auf der Geräteseite auf „0“ gesetzt wird. So kann man die „fehlerhaften Knoten“ auch identifizieren, auch wenn sie scheinbar funktionieren.

Die tng-Firmware dagegen läuft klaglos.

Log von 17194-Joy-IT-126f mit Firmware 1.4.0~121

Sat May 25 19:11:26 2024 daemon.debug td-client: [g01m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.err td-client: [g01m05.4830.org:10005] Hostname resolution timed out.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g02m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.err td-client: [g02m05.4830.org:10005] Hostname resolution timed out.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g03m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.err td-client: [g03m05.4830.org:10005] Hostname resolution timed out.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g04m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.err td-client: [g04m05.4830.org:10005] Hostname resolution timed out.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g05m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.err td-client: [g05m05.4830.org:10005] Hostname resolution timed out.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g06m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:26 2024 daemon.debug td-client: [g01m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g02m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g03m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g04m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g05m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:26 2024 daemon.debug td-client: [g06m05.4830.org:10005] is NOT ready.
Sat May 25 19:11:27 2024 daemon.debug td-client: [g01m05.4830.org:10005] is in STATE_REINIT.
Sat May 25 19:11:27 2024 daemon.debug td-client: [g01m05.4830.org:10005] reinitializing tunnel context.
Sat May 25 19:11:27 2024 daemon.debug td-client: [g01m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:27 2024 daemon.debug td-client: [g01m05.4830.org:10005] Broker's FQDN hasn't been resolved to an IP yet.
Sat May 25 19:11:27 2024 daemon.debug td-client: [g02m05.4830.org:10005] is in STATE_REINIT.
Sat May 25 19:11:27 2024 daemon.debug td-client: [g02m05.4830.org:10005] reinitializing tunnel context.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g02m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:28 2024 daemon.debug td-client: [g02m05.4830.org:10005] Broker's FQDN hasn't been resolved to an IP yet.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g03m05.4830.org:10005] is in STATE_REINIT.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g03m05.4830.org:10005] reinitializing tunnel context.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g03m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:28 2024 daemon.debug td-client: [g03m05.4830.org:10005] Broker's FQDN hasn't been resolved to an IP yet.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g04m05.4830.org:10005] is in STATE_REINIT.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g04m05.4830.org:10005] reinitializing tunnel context.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g04m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:28 2024 daemon.debug td-client: [g04m05.4830.org:10005] Broker's FQDN hasn't been resolved to an IP yet.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g05m05.4830.org:10005] is in STATE_REINIT.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g05m05.4830.org:10005] reinitializing tunnel context.
Sat May 25 19:11:28 2024 daemon.debug td-client: [g05m05.4830.org:10005] is in STATE_RESOLVING
Sat May 25 19:11:28 2024 daemon.debug td-client: [g05m05.4830.org:10005] Broker's FQDN hasn't been resolved to an IP yet.
Sat May 25 19:12:23 2024 daemon.notice netifd: client (16572): cat: write error: Broken pipe
Sat May 25 19:13:01 2024 user.notice ssid-changer: autoupdater is running, aborting.
Sat May 25 19:13:06 2024 user.info : autoupdater-wifi-fallback: connectivity check failed
Sat May 25 19:13:06 2024 user.info : autoupdater-wifi-fallback: going to fallback mode
Sat May 25 19:13:06 2024 kern.info kernel: [70011.590073] IPv6: ADDRCONF(NETDEV_UP): tmp.mesh0: link is not ready
Sat May 25 19:13:12 2024 kern.info kernel: [70018.336391] IPv6: ADDRCONF(NETDEV_UP): tmp.mesh1: link is not ready
Sat May 25 19:13:14 2024 user.info : autoupdater-wifi-fallback: connecting to radio0 mueritz.freifunk.net 86:BD:A3:A9:19:B8
Sat May 25 19:13:14 2024 daemon.notice netifd: Interface 'mesh_radio0' is disabled
Sat May 25 19:13:14 2024 daemon.notice netifd: Interface 'mesh_radio0' has link connectivity loss
Sat May 25 19:13:14 2024 kern.info kernel: [70020.346127] device client0 left promiscuous mode
Sat May 25 19:13:14 2024 kern.info kernel: [70020.351092] br-client: port 4(client0) entered disabled state
Sat May 25 19:13:15 2024 kern.info kernel: [70020.427014] device owe0 left promiscuous mode
Sat May 25 19:13:15 2024 kern.info kernel: [70020.431679] br-client: port 6(owe0) entered disabled state
Sat May 25 19:13:15 2024 daemon.notice netifd: Interface 'mesh_radio1' is disabled
Sat May 25 19:13:15 2024 daemon.notice netifd: Interface 'mesh_radio1' has link connectivity loss
Sat May 25 19:13:15 2024 kern.info kernel: [70020.569240] device client1 left promiscuous mode
Sat May 25 19:13:15 2024 kern.info kernel: [70020.574328] br-client: port 5(client1) entered disabled state
Sat May 25 19:13:15 2024 kern.info kernel: [70020.688445] device owe1 left promiscuous mode
Sat May 25 19:13:15 2024 kern.info kernel: [70020.693141] br-client: port 7(owe1) entered disabled state
Sat May 25 19:13:15 2024 kern.info kernel: [70020.781884] batman_adv: bat0: Interface deactivated: mesh0
Sat May 25 19:13:15 2024 kern.info kernel: [70020.787720] batman_adv: bat0: Removing interface: mesh0

Der Firmware-Server ist von diesem Knoten zurzeit auch nicht erreichbar. :thinking:

  OS: 19.07-SNAPSHOT, r11430+27-ecbbb3    FW: 1.4.0~121
  HW: Joy-IT JT-OR750i
root@17194-Joy-IT-126f:~# autoupdater
Retrieving manifest from http://firmware.ipv6.4830.org/rawhide/sysupgrade/rawhide.manifest ...
autoupdater: warning: error downloading manifest: Connection failed
autoupdater: error: no usable mirror found
root@17194-Joy-IT-126f:~#

Hier leider auch mit neuer Firmware nicht … :crazy_face:

root@17194-Joy-IT-126f:~# /usr/sbin/autoupdater-wifi-fallback
autoupdater-wifi-fallback: connectivity check failed
autoupdater-wifi-fallback: going to fallback mode
autoupdater-wifi-fallback: connecting to radio0 mueritz.freifunk.net 86:BD:A3:A9:19:B8
autoupdater-wifi-fallback: executing the autoupdater...

… und weg isser :zap:

Eine Gluon v2023.2-basierte FW steht für Juni/Juli auf dem Plan …

Was das ist wüßte ich auch gerne …

Nächstes Mal bitte einen traceroute firmware.ipv6.4830.org machen — Smokeping sagt was anderes, siehe g01, g02, g03, g04. EDIT: Rückweg tut auch:

 root@web01 ~ # traceroute -6 -s 2a06:e881:1709:1111:0:57ff:fefd:bc94 2001:bf7:170:192:46d1:faff:fe5a:126f
 traceroute to 2001:bf7:170:192:46d1:faff:fe5a:126f (2001:bf7:170:192:46d1:faff:fe5a:126f), 30 hops max, 80 byte packets
  1  2a06:e881:1709:1111::2 (2a06:e881:1709:1111::2)  0.729 ms  0.652 ms  0.577 ms
  2  2a06:e881:1709:1111::1 (2a06:e881:1709:1111::1)  0.526 ms  0.476 ms  0.437 ms
  3  2a06:e881:1705:1391::2 (2a06:e881:1705:1391::2)  19.806 ms  19.776 ms  19.729 ms
  4  2a06:e881:1709:1::1 (2a06:e881:1709:1::1)  20.089 ms  19.866 ms  20.491 ms
  5  bgp-ber01.4830.org (2a06:e881:1706:1::1)  25.363 ms  25.285 ms  25.208 ms
  6  2a06:e881:1706:11:0:c2ff:fe71:3656 (2a06:e881:1706:11:0:c2ff:fe71:3656)  25.513 ms  29.780 ms  29.674 ms
  7  2001:bf7:170:192:46d1:faff:fe5a:126f (2001:bf7:170:192:46d1:faff:fe5a:126f)  54.008 ms  55.275 ms  55.247 ms

Was heißt »weg isser«? Für mich heißt das »aufgehängt und tut nix mehr«, wogegen https://map03.4830.org/map/#!v:m;n:44d1fa5a126f (»21 Stunden up, online, letzte Nachricht vor 2 Minuten (26.05.2024, 23:22:23)«) spricht …

Moin.

  OS: 19.07-SNAPSHOT, r11430+27-ecbbb3    FW: 1.4.0~121
  HW: Joy-IT JT-OR750i
root@17194-Joy-IT-126f:~# autoupdater
Retrieving manifest from http://firmware.ipv6.4830.org/rawhide/sysupgrade/rawhide.manifest ...
autoupdater: warning: error downloading manifest: Connection failed
autoupdater: error: no usable mirror found
root@17194-Joy-IT-126f:~# traceroute -6 firmware.ipv6.4830.org

traceroute: bad address 'firmware.ipv6.4830.org'
root@17194-Joy-IT-126f:~#
root@17194-Joy-IT-126f:~# host firmware.ipv6.4830.org
-ash: host: not found
root@17194-Joy-IT-126f:~# ping firmware.ipv6.4830.org
ping: bad address 'firmware.ipv6.4830.org'
root@17194-Joy-IT-126f:~#

Es sieht so aus, als ob der Knoten den DNS-Namen nicht auflösen kann.

Naja. OK… Ich war per SSH drauf und nach " /usr/sbin/autoupdater-wifi-fallback" war auch die Verbindung weg und es dauerte auch eine Weile, bis der Knoten wieder per SSH/HTTP/ping ansprechbar war.

Moin.
DNS ist etwas instabil.
Ich habe mehrere Knoten verteilt auf alle Gateway in Mesh5 getestet … im Moment kann ‚firmware.ipv6.4830.org‘ nicht mehr aufgelöst werden.

root@17194-Joy-IT-126f:~#
root@17194-Joy-IT-126f:~# ping firmware.ipv6.4830.org
PING firmware.ipv6.4830.org (2a06:e881:1709:1111:0:57ff:fefd:bc94): 56 data bytes
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=0 ttl=58 time=48.720 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=1 ttl=58 time=49.290 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=2 ttl=58 time=50.212 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=3 ttl=58 time=50.511 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=4 ttl=58 time=50.528 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=5 ttl=58 time=50.638 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=6 ttl=58 time=47.507 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=7 ttl=58 time=46.422 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=8 ttl=58 time=51.187 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=9 ttl=58 time=51.703 ms
64 bytes from 2a06:e881:1709:1111:0:57ff:fefd:bc94: seq=10 ttl=58 time=48.630 ms
^C
--- firmware.ipv6.4830.org ping statistics ---
11 packets transmitted, 11 packets received, 0% packet loss
round-trip min/avg/max = 46.422/49.577/51.703 ms
root@17194-Joy-IT-126f:~# ping firmware.ipv6.4830.org
ping: bad address 'firmware.ipv6.4830.org'
root@17194-Joy-IT-126f:~# ping firmware.ipv6.4830.org
ping: bad address 'firmware.ipv6.4830.org'
root@17194-Joy-IT-126f:~# ping firmware.ipv6.4830.org
ping: bad address 'firmware.ipv6.4830.org'
root@17194-Joy-IT-126f:~# 

Danke für den Hinweis; ich guck’ mal, welche Resolver Knoten nutzen.

Zonemaster meldet für 4830.org, dass 2 der Nameserver per IPv6 weder per UDP noch TCP erreichbar sind. Ist aber nur ein Nebenproblem, nicht das Hauptproblem?

https://zonemaster.net/en/result/098a55d0642385c1

DNSViz spuckt auch noch einen Fehler aus zu firmware.ipv6.4830.org:

https://dnsviz.net/d/firmware.ipv6.4830.org/dnssec/
image

Hrmpft, vergessen, den auch in der Zone auszutragen, danke.

firmware.ipv6.4830.org | DNSViz moniert nun „nur“ noch

4830.org zone: The server(s) were not responsive to queries over UDP. (2a01:4f9:3b:5822:0:41ff:fe15:598a)

Das ist Hetzner Helsinki (dns-fks.uu.org), muß ich mal morgen in Ruhe gucken.

Dieses Thema wurde automatisch 10 Tage nach der letzten Antwort geschlossen. Es sind keine neuen Antworten mehr erlaubt.