In den letzten 3 Wochen kam es heute zum 2. Mal vor, dass FHEM irgendwann "hängen" geblieben ist. Der Prozess selbst lief noch, aber es wurde nichts geloggt und auch das Frontend war nicht mehr erreichbar.
Nach stoppen und starten des Prozesses läuft es nun erstmal wieder.
Im fhem-Logfile ist kein Eintrag zur Ursache zu finden. Einzig anhand der Device-Logfiles kann ich nachvollziehen, wann das "Aufängen" passiert sein muss.
Wie finde ich die Ursache dafür, um es abstellen zu können?
Woher weist Du das
Zitat
Im fhem-Logfile ist kein Eintrag zur Ursache zu finden
wenn Du die Ursache noch nicht einmal kennst.
Bitte gib uns die letzten 30 Zeilen vom Log bevor der Crash kommt.
"Aufgehängt" hat sich FHEM lt. der Device-Logfiles um ca. 18:15 gestern, gemerkt habe ich es um ca. 21:00. Der von mir ausgelöste Shutdown wurde interessanterweise sauber protokolliert.
Hier das Logfile:
2018.12.04 07:57:19 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 2a03:567:1::20)
2018.12.04 09:35:01 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 2a03:567:1::20)
2018.12.04 14:00:25 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (peer: 2a03:567:1::20)
2018.12.04 16:55:54 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.04 20:04:05 1: PERL WARNING: Use of uninitialized value $_ in numeric gt (>) at ./FHEM/99_Utils.pm line 63.
2018.12.04 20:37:42 1: PERL WARNING: Use of uninitialized value $_ in numeric gt (>) at ./FHEM/99_Utils.pm line 63.
2018.12.04 21:19:57 1: RMDIR: ./restoreDir/save/2018-11-29
2018.12.05 06:16:23 1: Timeout for PROPLANTA_Run reached, terminated process 9316
2018.12.05 06:25:19 1: PERL WARNING: Use of uninitialized value $_ in numeric gt (>) at ./FHEM/99_Utils.pm line 63.
2018.12.05 06:43:17 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 2a03:567:1::20)
2018.12.05 07:32:32 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 2a03:567:1::20)
2018.12.05 15:06:36 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 15:06:37 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 15:06:37 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 15:06:42 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 17:24:29 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 2a03:567:1::20)
2018.12.05 17:53:28 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 17:53:29 1: FHEMWEB SSL/HTTPS error: SSL accept attempt failed (peer: 2a03:567:1::20)
2018.12.05 21:16:42 0: Server shutdown
(Die Zeilen davor sind eine Fehlermeldung von einem Plot von der Plot-Erstellung.)
Eventuell beim nächsten nicht erreichbar sein einmal schauen was die Prozesstabelle sagt.
"top" zum Beispiel und dann nach einem Perlprozess schauen.
Der Prozess läuft weiterhin, das habe ich geschaut.
Komisch ist, dass der FHEM-Shutdown dann "ganz normal" geloggt wurde, die Device-Readings in den Device-Logs aber nicht.
Zitat von: TheTrumpeter am 06 Dezember 2018, 09:44:01
Der Prozess läuft weiterhin, das habe ich geschaut.
Komisch ist, dass der FHEM-Shutdown dann "ganz normal" geloggt wurde, die Device-Readings in den Device-Logs aber nicht.
Das würde erstmal lediglich auf fehlende Events hinweisen. Interessanter ist da schon eher das Du laut Deiner Aussage FHEMWEB auch nicht aufrufen konntest.
Richtig.
Selbst im Heimnetz konnte ich mit Angabe der IP-Adresse nicht hin, was sonst immer funktioniert. Zum Rechner konnte ich aber mit VNC sofort verbinden.
Auch beim letzten Mal war es so, dass der Shutdown sauber im Log protokolliert wurde, davor war fast 12h kein anderer Logeintrag mehr, auch nicht in den Device-Logs. (War über Nacht...)
Du hast SSL auf fhemweb installiert?
(Und DU betreibst ein Desktop-Server-System?)
Mich würde aktuell eher interessiren, wie der Speicherverbrauch aussah. Sagt die /var/log/kern.log in der Zeit etwas? z.B. wegen oem-Killer?
Irgendwie hatten wir irgendwo diese Woche doch schon mal das Thema?
Zitat von: Wernieman am 06 Dezember 2018, 10:31:34
Du hast SSL auf fhemweb installiert?
Ich habe SSL gemäss FHEM-Wiki aktiviert, ja.
Zitat von: Wernieman am 06 Dezember 2018, 10:31:34
(Und DU betreibst ein Desktop-Server-System?)
Was genau meinst Du? Ich habe FHEM auf einem RasPi installiert. Von Aussen greife ich über VNC-Cloud bzw. über die im Router freigegeben FHEM-Web-Ports zu.
Zitat von: Wernieman am 06 Dezember 2018, 10:31:34
Mich würde aktuell eher interessiren, wie der Speicherverbrauch aussah. Sagt die /var/log/kern.log in der Zeit etwas? z.B. wegen oem-Killer?
Speichernutzung war lt. FHEM-Modul "sysmon" beim letzten Eintrag unauffällig.
Im Kernel-Log ist ausser den Infos über Runter- und Rauftakten im fragwürdigen Zeitraum nichts enthalten.
naja VNC ist für die Dekstopübertragung zuständig. Also hast Du ein Grafisches-System auf dem PI ....
Zitat von: Wernieman am 06 Dezember 2018, 15:12:41
naja VNC ist für die Dekstopübertragung zuständig. Also hast Du ein Grafisches-System auf dem PI ....
OK, das meinst Du.
Ja, Jessi läuft drauf.
Mal ein paar Ideen in den Raum werfen (brainstorm)
- Ram voll (unwahrscheinlich)
- HDD voll / Speicherkarte mit Zugriffen überlastet (unwahrscheinlich)
- Spannungsprobleme bei USB-Geräten? zB Antenne? -> Systemlogs/dmesg
Für mich klingt es danach, dass ein Gerät sich weghängt und FHEMin einen Timeout rennt ...
- Telnet irgendwohin?
- WLAN oder Kabel?
Klingt nach einem blockierenden Aufruf von irgendwas (IP-basiert, aber nicht erreichbar). In allen anderen Fällen müßte m.E. sonst was im log stehen oder die Maschine würde gar nicht mehr reagieren; aber wenn sogar der Desktop noch erreichbar ist?!?
Vielleicht mal hier starten:
https://wiki.fhem.de/wiki/FHEM_startet_nicht_-_Tipps_zur_Fehlersuche
Und dann freezemon oä. anwerfen.
Generell aber: Ein Server ist ein Server. Da hat ein Desktop nix drauf verloren (nur meine Meinung, die allerdings ein paar andere hier teilen), auch wenn irgendeiner in einem seeeehr langweiligen Video was anderes behauptet. (Der Hinweis auf "jessie" deutet darauf hin, dass der Betreffende nicht zwischen einer Desktop- und einer lite-Version unterscheiden kann, vielleicht liest du dich da mal ein?).
Empfehlung: "Richtig" machen, nochmal eine SD-Karte für das aktuelle Raspbian (stretch) vorbereiten, und dann die lite-Variante installieren. Dann ssh statt VNC nutzen (und für den Fall, dass ungeschütztes Portforwarding vorliegt, auch das gleich ändern...) und dann an der Konsole arbeiten. Wie man eine FHEM-Installation umzieht, sollte sowieso geübt werden ;) .
Ist erst mal gewöhnungsbedürftig, aber langfristig deutlich zielführender.
Just my2ct.
Beta-User
Ich kann Betta-User nur Zustimmen!
Zitat von: Beta-User am 06 Dezember 2018, 16:20:24
Klingt nach einem blockierenden Aufruf von irgendwas (IP-basiert, aber nicht erreichbar). In allen anderen Fällen müßte m.E. sonst was im log stehen oder die Maschine würde gar nicht mehr reagieren; aber wenn sogar der Desktop noch erreichbar ist?!?
Vielleicht mal hier starten:
https://wiki.fhem.de/wiki/FHEM_startet_nicht_-_Tipps_zur_Fehlersuche
Was genau meinst Du mit dem ersten Satz?
Irgend etwas, das ich per FHEMWEB selbst verursache? Bei beiden "Ausfällen" war ich nicht per VNC verbunden, vielleicht aber kurz vorher per FHEMWEB.
Ich habe keinerlei neue Devices eingebunden. Ich meine, dass die Probleme erst mit dem Umstieg auf stretch (ja, vorhin habe ich jessie gesagt) aufgetreten sind.
Alles was in den "Tipps zur Fehlersuche" steht, habe ich ohnehin gemacht, erfolglos.
Der Prozess läuft und erzeugt keine auffällige CPU-Last, an den Berechtigungen habe ich ewig nix geändert, im fhem.log ist nix auffälliges drin.
An den USB-Ports hängt ein RS485-Dongle (seit 1,5 Jahren), ein nano-cul (seit dem Sommer) sowie natürlich ein (Sandisk-) Flashspeicher, der die Logfiles enthält.
Zitat von: Beta-User am 06 Dezember 2018, 16:20:24
Generell aber: Ein Server ist ein Server. Da hat ein Desktop nix drauf verloren (nur meine Meinung, die allerdings ein paar andere hier teilen), auch wenn irgendeiner in einem seeeehr langweiligen Video was anderes behauptet. (Der Hinweis auf "jessie" deutet darauf hin, dass der Betreffende nicht zwischen einer Desktop- und einer lite-Version unterscheiden kann, vielleicht liest du dich da mal ein?).
Empfehlung: "Richtig" machen, nochmal eine SD-Karte für das aktuelle Raspbian (stretch) vorbereiten, und dann die lite-Variante installieren. Dann ssh statt VNC nutzen (und für den Fall, dass ungeschütztes Portforwarding vorliegt, auch das gleich ändern...) und dann an der Konsole arbeiten. Wie man eine FHEM-Installation umzieht, sollte sowieso geübt werden ;) .
Ist erst mal gewöhnungsbedürftig, aber langfristig deutlich zielführender.
Meine Hardcore-Terminalzeiten sind lange vorbei, davor scheue ich mich einfach... abgesehen davon sehe ich nicht, welchen Vorteil das haben soll. Ja, das System ist schlanker und weniger belastet, aber eigentlich langweilt sich der Raspi jetzt auch schon.
Zitat von: erdo_king am 06 Dezember 2018, 16:03:34
Mal ein paar Ideen in den Raum werfen (brainstorm)
- Ram voll (unwahrscheinlich)
- HDD voll / Speicherkarte mit Zugriffen überlastet (unwahrscheinlich)
- Spannungsprobleme bei USB-Geräten? zB Antenne? -> Systemlogs/dmesg
Nein, nein, und dmesg leer. USB-Geräte siehe oben.
Raspi bekommt konstant 5,3V. Das könnte ich beliebig erhöhen, sehe aber nicht wofür.
Zitat von: erdo_king am 06 Dezember 2018, 16:03:34
Für mich klingt es danach, dass ein Gerät sich weghängt und FHEMin einen Timeout rennt ...
- Telnet irgendwohin?
- WLAN oder Kabel?
Telnet ist zwar aktiviert, aber niemand war verbunden.
WLAN.
Ich habe anhand der Device-Logs nun die genaue Ausfallzeit nachvollzogen, muss gestern kurz nach 18:16 gewesen sein.
Kernel-Log sagt dazu nur, dass der Raspi da grad mit niedrigem Takt lief.
Dec 5 18:10:22 raspberrypi kernel: [892669.158210] rpi_firmware_get_throttled: 16 callbacks suppressed
Dec 5 18:10:22 raspberrypi kernel: [892669.158217] Under-voltage detected! (0x00050005)
Dec 5 18:10:40 raspberrypi kernel: [892687.878297] Under-voltage detected! (0x00050005)
Dec 5 18:11:01 raspberrypi kernel: [892708.678454] Under-voltage detected! (0x00050005)
Dec 5 18:14:37 raspberrypi kernel: [892925.009827] rpi_firmware_get_throttled: 14 callbacks suppressed
Dec 5 18:14:37 raspberrypi kernel: [892925.009831] Voltage normalised (0x00000000)
Dec 5 18:14:46 raspberrypi kernel: [892933.319942] Voltage normalised (0x00000000)
Dec 5 18:15:11 raspberrypi kernel: [892958.280065] Voltage normalised (0x00000000)
Dec 5 18:15:40 raspberrypi kernel: [892987.400359] rpi_firmware_get_throttled: 15 callbacks suppressed
Dec 5 18:15:40 raspberrypi kernel: [892987.400367] Under-voltage detected! (0x00050005)
Dec 5 18:16:03 raspberrypi kernel: [893010.280429] Under-voltage detected! (0x00050005)
Dec 5 18:17:20 raspberrypi kernel: [893087.240940] Under-voltage detected! (0x00050005)
Dec 5 18:21:19 raspberrypi kernel: [893326.442531] rpi_firmware_get_throttled: 1 callbacks suppressed
Dec 5 18:21:19 raspberrypi kernel: [893326.442548] Under-voltage detected! (0x00050005)
Dec 5 18:21:25 raspberrypi kernel: [893332.682553] rpi_firmware_get_throttled: 5 callbacks suppressed
Dec 5 18:21:25 raspberrypi kernel: [893332.682560] Voltage normalised (0x00000000)Bin leider immer noch ratlos.
So, seit gestern 22:30 habe ich wieder das gleiche Fehlerbild.
Ich habe nun etwas genauer geschaut. Für mich wirkt es so, als ob der FHEM-Prozess zwar läuft, aber "nichts tut". Die CPU-Last ist permanent "0". Normalerweise verbraucht der Prozess immer mal wieder einzelne Prozent.
Kann ich jetzt noch irgend etwas tun, um dem Problem näher auf die Schliche zu kommen, bevor ich den Prozess wieder neu starte?
Zitat von: TheTrumpeter am 06 Dezember 2018, 21:41:36
Was genau meinst Du mit dem ersten Satz?
Irgend etwas, das ich per FHEMWEB selbst verursache?
Nicht mit FHEMWEB, sondern mit FHEM selbst. Typischerweise ist das eine blockierende Datenabfrage von einem entfernten Gerät, das eben gerade nicht erreichbar ist, da das allg. Netzwerk oder nur das entfernte Gerät nicht erreichbar ist. Kann auch ein falsch genutztes "sleep" sein...
Zitat von: TheTrumpeter am 07 Dezember 2018, 06:50:26
Kann ich jetzt noch irgend etwas tun, um dem Problem näher auf die Schliche zu kommen, bevor ich den Prozess wieder neu starte?
Und dann freezemon oä. anwerfen.+Lesen, Wiki+Forum nach den gegebenen Schlagworten durchsuchen und selbst aktiv mitdenken... (Niemand hat eigentlich Lust, dieselbe Frage mehrfach zu beantworten. Verständlich, oder?)
Freezemon habe ich gestern noch angeworfen, aber vorerst ohne Log. Das hilft mir wohl jetzt nix mehr.
Zitat von: Beta-User am 07 Dezember 2018, 07:20:06
Typischerweise ist das eine blockierende Datenabfrage von einem entfernten Gerät, das eben gerade nicht erreichbar ist, da das allg. Netzwerk oder nur das entfernte Gerät nicht erreichbar ist. Kann auch ein falsch genutztes "sleep" sein...
Da fällt mir nur der Wasserzähler über WMBus ein. Beim "Hänger" vorgestern war dieses Device das Letzte, was geloggt wurde. Mal sehen wie es diesmal war...
Wäre aber dennoch komisch, weil ich von dem Gerät noch nie Verbindungsabbrüche hatte.
"Sleep" habe ich nur in einem benutzerdefinierten Modul im Einsatz, das zum fragwürdigen Zeitpunkt sicher nicht getriggert wurde. Das Modul habe ich aber getestet und hat damals nicht diesen Effekt verursacht. Werde trotzdem nochmal danach schauen.
Kann ich irgendwie herausfinden, ob FHEM grundsätzlich noch reagieren würde, aber eben nur nicht mehr loggt und nicht mehr per FHEMWEB erreichbar ist?
Wenn die logs ausbleiben, wartet FHEM auf irgendwas, das kannst du noch 10x fragen...
FHEM ist eigentlich nur ein linear arbeitender single thread. Wartet der, dann werden nur noch geforkte Prozesse abgearbeitet. Aber sonst geht afaik nichts. Ob es möglich ist, FHEMWEB alleine abzuschießen, habe ich ehrlich gesagt noch nie intensiv geprüft, glaube aber wegen des Wesens von FHEM als single thread eigentlich nicht, dass das geht. Würde die Frage also als zwecklos bewerten.
FHEM ist, abgesehen von "nonblocking-Modulen" Single-Threaded, d.h. wenn es hängt, dann hängt es komplett.
Du könntst natürlich schauen, ob FHEM z.B. über die telnet-Schnittstelle erreichbar ist ....
ZitatMeine Hardcore-Terminalzeiten sind lange vorbei, davor scheue ich mich einfach... abgesehen davon sehe ich nicht, welchen Vorteil das haben soll. Ja, das System ist schlanker und weniger belastet, aber eigentlich langweilt sich der Raspi jetzt auch schon.
Das Problem ist nicht nur die grafische Oberfläche, sondern auch die dazugehörigen Biblioteken, die in Summe ein Sicherheitsrisiko darstellen. Nicht ohne Grund gehen auch die großen Server-Programm-Hersteller (Sogar Microsoft) wieder zur "Terminal" Konfiguration über.
Ich persöhlich finde Terminal sogar einfacher als "Grafische Oberfläche", die meistens sowieso nur ein Überbau über die terminal-Programme ist und damit deren Entwicklerzeit hinterherhängt. In einer Grafischen Oberfläche suche ich mich meistens "zu Tode", bevor ich das Finde, was ich ändern möchte. Gibt allerdings auch Außnahmen (wie FHEM) ....
Gut, nach dem Neustart ist der letzte Eintrag im Freezemon vor dem Neustart:
1 - 2018-12-06: s:22:30:39 e:22:30:40 f:1.465 d:tmr-CustomReadings_OnTimer(mySlowReadings) tmr-TPLinkHS110_Get(LBE250.Steckdose) tmr-FW_closeInactiveClients(N/A)
D.h. eines der 3 genannten Dinge war für eine Freeze-Zeit von 1.5 Sekunden zuständig. Danach sollte FHEM aber wieder "aktiv" gewesen sein.
Ich habe jetzt mal "autocreate" deaktiviert, weil vor ein paar Tagen mal ein unbekanntes WMBus-Device aufgetaucht ist, vermutlich vom Nachbar oder so. Ev. verursacht das Probleme, wenn es kurz erreichbar, dann aber doch nicht, ist?