[GELÖST] RaspMatic startet jede Nacht zur gleichen Zeit neu

[mazta]

Hallo zusammen,

seit ca. 2 Wochen startet meine RM nahezu jede Nacht gegen 02:10 Uhr neu. Das ärgerliche daran ist, dass meist die Verbindung zum LAN-Gateway (alte CCU2) danach nicht mehr läuft, das ich aber benötige, um das gesamte Haus abzudecken.

Ich hänge mal einen Log (CUxD an) an:

Code: Alles auswählen

Jun  6 02:06:46 homematic-ccu2 user.err setlgwkey: Cannot determine IP address of gateway with serial CCU2GW0001
Jun  6 02:06:46 homematic-ccu2 user.info kernel: [   78.630534] eq3loop: created slave mmd_hmip
Jun  6 02:06:46 homematic-ccu2 user.info kernel: [   78.630824] eq3loop: created slave mmd_bidcos
Jun  6 02:06:48 homematic-ccu2 user.info kernel: [   80.775061] eq3loop: eq3loop_open_slave() mmd_bidcos
Jun  6 02:06:51 homematic-ccu2 user.err rfd: UnifiedLanCommController::connect(): Could not connect.
Jun  6 02:06:51 homematic-ccu2 user.crit rfd: CCU2LGWCommController::init(): Cannot connect to HomeMatic Lan Gateway with serial number CCU2GW0001.
Jun  6 02:07:04 homematic-ccu2 user.info kernel: [   96.292669] eq3loop: eq3loop_open_slave() mmd_hmip
Jun  6 02:07:04 homematic-ccu2 user.info kernel: [   96.292882] eq3loop: eq3loop_close_slave() mmd_hmip
Jun  6 02:07:04 homematic-ccu2 user.info kernel: [   96.295734] eq3loop: eq3loop_open_slave() mmd_hmip
Jun  6 02:07:04 homematic-ccu2 user.info kernel: [   96.295875] eq3loop: eq3loop_close_slave() mmd_hmip
Jun  6 02:07:04 homematic-ccu2 user.info kernel: [   96.304438] eq3loop: eq3loop_open_slave() mmd_hmip
Jun  6 02:07:13 homematic-ccu2 daemon.warn cuxd[743]: process_rpc_request(127.0.0.1) - illegal XMLRPC(listDevices) request
Jun  6 02:07:15 homematic-ccu2 daemon.warn cuxd[743]: process_rpc_request(127.0.0.1) - illegal XMLRPC(init) request
Jun  6 00:07:19 homematic-ccu2 daemon.info : starting pid 1132, tty '/dev/null': '/usr/bin/monit -Ic /etc/monitrc'
Jun  6 02:07:19 homematic-ccu2 user.info monit[1132]: Starting Monit 5.26.0 daemon with http interface at /var/run/monit.sock
Jun  6 02:07:19 homematic-ccu2 user.info monit[1132]: 'homematic-ccu2' Monit 5.26.0 started
Jun  6 02:07:23 homematic-ccu2 daemon.info chronyd[630]: Selected source 129.70.132.32
Jun  6 02:07:36 homematic-ccu2 daemon.info cuxd[743]: INIT 'xmlrpc_bin://127.0.0.1:31999' '1722'
Jun  6 02:07:40 homematic-ccu2 user.err monit[1132]: 'hs485dEnabled' status failed (1) -- no output
Jun  6 02:07:40 homematic-ccu2 user.err monit[1132]: 'hmlangwEnabled' status failed (1) -- no output
Jun  6 02:07:58 homematic-ccu2 user.err monit[1132]: 'wlan0CheckEnabled' status failed (1) -- no output
Jun  6 02:09:31 homematic-ccu2 daemon.info chronyd[630]: Selected source 129.70.132.35

Hat jemand eine Idee? Das hing nicht mit einem Update zusammen, das fing auf einmal an...

[jmaus]

Hat jemand eine Idee? Das hing nicht mit einem Update zusammen, das fing auf einmal an...

Ja, das habe ich. Jede Nacht um 2:00 Uhr startet der sogenannte "BadBlocksCheck" der überprüft ob die genutzt SD karte auch keine schlechten Blöcke aufweist die darauf deuten lassen das die SD Karte ggf. bald ihren Dienst einstellen wird. Und wenn das jede Nacht bei dir ab 2:00 Uhr passiert würde ich einfach stark darauf tippen das du davon betroffen bist. D.h. schnellstmöglichst eine neue/frische SD Karte nehmen, neues RaspberryMatic drauf und aktuelles Backup einspielen und dann sollte das in der nächsten Nacht nicht mehr passieren.

[ProfDrYoMan]

Hallo Jens,

kann ich irgendwie verifizieren, dass es die SD-Karte ist? Gibt es einen Logeintrag, außer den neuen Boot?

Das ist ne "Markenkarte" bei mir und gerade mal 1 Jahr alt.

[LibertyX]

Wenn du dein LOG an einen Syslog-Server schickst ggf. ja sonst hast du halt das Problem, dass das Log nach einem Boot weg ist.

[jmaus]

Du bist doch nicht der Themenersteller?!?

Aber nein, man kann nicht zweifelsfrei feststellen ob eine SD Karte defekt ist bis sie defekt ist. Deshalb: Tägliches Backup durchführen und bei Auffälligkeiten (wie die hier beschriebenen) die SD Karte vorsorglich wechseln und aktuelles Backup einspielen, fertig.

Oder auf Nummer sicher gehen und auf eine Lösung ohne SD Karten umsteigen (TinkerboardS, OVA, etc.)

[ProfDrYoMan]

Nein, ich bin nicht der Themenstarter, aber ich habe genau das gleiche Problem.

Also gut. Kommt ne neue SD rein in Kürze und ich werde wohl am besten alles auf mein Syn218+ ziehen. Getestet habe ich da schonmal, soweit tat alles was ich einsetze, sogar RedMatic in der 686 version.

Aber bevor ich eine "neue" SD einsetze teste ich die mal mit "badblocks". Und die alte nach dem austausch ebenso um sicherzustellen, dass dies das Problem war.

Eine Frage habe ich aber noch. Triggert der nächtliche check mit Absicht einen reboot oder ist das ein Nebeneffekt?

[jmaus]

Eine Frage habe ich aber noch. Triggert der nächtliche check mit Absicht einen reboot oder ist das ein Nebeneffekt?

Natürlich wird da kein reboot getriggert. Das wird wohl ein Nebeneffekt sein das die SD karte dann einfach während des bad block checks ihren geist aufgibt und das System in den Reboot zwingt. Aber bestimmt kann man das nur sagen wenn man solch ein betroffenen system mal in der hand hat und einfach den bad blocks check von hand mal aufruft und dann beobachtet was konkret passiert.

[ProfDrYoMan]

Ok, dann wäre es nett, wenn du sagst wie im detail der check aufgerufen wird, dann würde ich das nämlich bei mir mal machen.

EDIT: Ich hab mal im cron gestöbert.

Ergebnis:

Code: Alles auswählen

root@homematic:/tmp# /sbin/badblocks -b 4096 -sv /dev/mmcblk0
Checking blocks 0 to 1945599
Checking for bad blocks (read-only test):  43.70% done, 2:45 elapsed. (0/0/0 errors)      

Dann hängt das Teil und raspimatic rebooted nach einer Weile.

Zweiter nochmaliger Test bestätigt das.

dmesg -w zeigt:

Code: Alles auswählen

[  284.130894] mmc0: timeout waiting for hardware interrupt.
...
[  284.133113] mmc0: data blocks 200 blksz 200 - err 0
[  284.133125] mmc0: stop op 12 arg 0x0 flags 0x95 - resp 00000000 00000000 00000000 00000000, err 0

Also gut. Andere SD Karte. ...

[jmaus]

Zweiter nochmaliger Test bestätigt das.

dmesg -w zeigt:

Code: Alles auswählen

[  284.130894] mmc0: timeout waiting for hardware interrupt.
...
[  284.133113] mmc0: data blocks 200 blksz 200 - err 0
[  284.133125] mmc0: stop op 12 arg 0x0 flags 0x95 - resp 00000000 00000000 00000000 00000000, err 0

Also gut. Andere SD Karte. ...

Gut das du das verifiziert hast. Das ist genau der Grund/Fall für den ich den badblocks-Check eingeführt habe. Denn wenn solche Probleme früh erkannt werden hat man bessere Chancen noch Daten zu retten bzw. frühzeitig einzugreifen bevor die gesamte SD Karte den Geist aufgibt. Leider gibt es allerdings nicht wirklich eine Möglichkeit solche Abstürze zu vermeiden bzw. den Grund dafür herauszufinden. Das einzige was ich vielleicht noch einbauen könnte wäre, zu erkennen das die Zentrale unerwartet neugestartet hatte und nicht ordnungsgemäß heruntergefahren wurde/ist. Und dann könnte ich das beim nächsten Booten via triggerAlarm automatisch als WebUI Alarmmeldung anzeigen lassen. Wäre vielleicht eine Überlegung wert.

[ProfDrYoMan]

Ja, es wäre gut, wenn man es mitbekommt. Ich habe es mitbekommen, da ein Programm nach dem Neustart läuft und mir ein Telegram schickt. Das passiert aber egal ob guter oder schlechter reboot.

Eine Sys-Var, welche im Falle eines schlechten Reboots gesetzt wäre, wäre nett.