FHEM spinnt plötzlich, keine Config-Änderung oder Host-Änderung

[RalfRog]

.....einzig seit dem Update bekomme ich haufenweise Warnings vom FRITZBOX-Modul.

Ein Hinweis zu den vielen Meldungen vom FRITZBOX-Modul -wenn das System wieder läuft, vielleicht mit Update und aktualisiertem FRITZBOX-Modul.
Aufgrund der Anpassungen am Modul musst Du vermutlich das define ändern und IP oder Host dazufügen.
   

define <name> FRITZBOX <host>
    Der Parameter host ist die Web-Adresse (Name oder IP) der FRITZ!BOX / Repeater.

und schau bitte hier die Infos aus der Version 07.50.10

INFO	The support for telnet and operation on a Fritz!Box has been discontinued. The functions are disabled.
INFO2	The following attributes are not longer supported:
	useGuiHack, ringWithIntern, defaultCallerName, allowTR064Command,
	forceTelnetConnection, telnetUser, telnetTimeOut
	Use deleteattr to delete from Attributes.
INFO3	The attribute fritzBoxIP is not longer supported!
	May be you have to use deleteattr to delete fritzBoxIP from Attributes.
	The definition of the device has been adjusted. Please use 'Save config'

Gruß

[TheTrumpeter]

.....einzig seit dem Update bekomme ich haufenweise Warnings vom FRITZBOX-Modul.

Ein Hinweis zu den vielen Meldungen vom FRITZBOX-Modul -wenn das System wieder läuft, vielleicht mit Update und aktualisiertem FRITZBOX-Modul.
Aufgrund der Anpassungen am Modul musst Du vermutlich das define ändern und IP oder Host dazufügen.
   

define <name> FRITZBOX <host>
    Der Parameter host ist die Web-Adresse (Name oder IP) der FRITZ!BOX / Repeater.

Danke für den Hinweis, genau das war's.

Was das Problem mit dem nicht reagierenden FHEM betrifft habe ich auch einen Verdacht wodurch es ausgelöst wird. Werde das morgen mal genauer untersuchen bzw. gezielt zu reproduzieren versuchen.
Wenn sich der Verdacht bestätigt, hat es genau 0,0 mit der SD-Karte zu tun.

[TheTrumpeter]

So, mal ein Update:

Mein Verdacht war, dass das FHEM-Problem durch einen Zugriff auf die Website von meinem Arbeits-Rechner getriggert wird.
Zwar hat das in der Vergangenheit noch nie Probleme verursacht & spontan könnte ich mir auch nicht erklären wie es zu dem Problem kommen sollte, aber tatsächlich habe ich die Probleme jedes Mal durch einen Zugriff vom Arbeitsrechner aus festgestellt & anhand der FHEM-Filelogs schien der Auftretenszeitpunkt auch immer zu dem Zugriffszeitpunkt zu passen.
Gestern konnte ich es dann nicht prüfen und heute Nacht gab es wohl einen kurzen Stromausfall bei uns. Seitdem konnte ich es nicht mehr reproduzieren, egal von welchem Rechner und mit welchem Browser ich es versuche, der Zugriff klappt problemlos.

[TheTrumpeter]

So, mal ein Update:

Mein Verdacht war, dass das FHEM-Problem durch einen Zugriff auf die Website von meinem Arbeits-Rechner getriggert wird.
Zwar hat das in der Vergangenheit noch nie Probleme verursacht & spontan könnte ich mir auch nicht erklären wie es zu dem Problem kommen sollte, aber tatsächlich habe ich die Probleme jedes Mal durch einen Zugriff vom Arbeitsrechner aus festgestellt & anhand der FHEM-Filelogs schien der Auftretenszeitpunkt auch immer zu dem Zugriffszeitpunkt zu passen.
Gestern konnte ich es dann nicht prüfen und heute Nacht gab es wohl einen kurzen Stromausfall bei uns. Seitdem konnte ich es nicht mehr reproduzieren, egal von welchem Rechner und mit welchem Browser ich es versuche, der Zugriff klappt problemlos.

Gerade ist es wieder aufgetreten, und bemerkt habe ich es zufälligerweise wieder durch einen Zugriff von meinem Arbeits-Rechner.
Habe mich dann gleich per SSH auf den RasPi verbunden, er sagte "FHEM is running" und die Prozessorlast war auch unauffällig.

Kurze Zeit später hat dann mein "Watchdog" FHEM neu gestartet.
Was mich wundert, ist, dass

• das Beenden von FHEM durch den Watchdog nicht im Logfile ersichtlich ist.
• der erste Neustart offenbar nicht erfolgreich war (wg. telnetPort-Fehler, den ich so noch nie gesehen habe)

Hier der Logfile-Auszug von dem Zeitpunkt, die letzte Zeile davor ist von 2023.04.27 02:02:14 vom PROPLATA-Modul, weil die Wetterdaten nicht abgerufen werden konnten.

Code Auswählen Erweitern

2023.04.27 08:01:01 1: PERL WARNING: given is experimental at ./FHEM/99_myLWZUtils.pm line 389.
2023.04.27 08:01:01 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 391.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 392.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 393.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 394.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 395.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 396.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 397.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 398.
2023.04.27 08:01:02 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 399.
2023.04.27 08:01:02 1: Including fhem.cfg
2023.04.27 08:01:02 1: telnetPort: Can't open server port at 7072: Address already in use. Exiting.
2023.04.27 08:01:09 0: Server shutdown
2023.04.27 08:02:20 1: PERL WARNING: given is experimental at ./FHEM/99_myLWZUtils.pm line 389.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 391.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 392.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 393.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 394.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 395.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 396.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 397.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 398.
2023.04.27 08:02:20 1: PERL WARNING: when is experimental at ./FHEM/99_myLWZUtils.pm line 399.
2023.04.27 08:02:20 1: Including fhem.cfg
2023.04.27 08:02:30 1: SmartMeterRestAPI: the attribute reading110Expr should no longer be used. Please use reading110OExpr instead
2023.04.27 08:02:30 1: SmartMeterRestAPI: For most old attributes you can specify enableControlSet and then set device upgradeAttributes to automatically modify the configuration
2023.04.27 08:02:30 1: SmartMeterRestAPI: the attribute reading111Expr should no longer be used. Please use reading111OExpr instead
2023.04.27 08:02:30 1: SmartMeterRestAPI: For most old attributes you can specify enableControlSet and then set device upgradeAttributes to automatically modify the configuration
2023.04.27 08:02:32 1: Including /opt/fhem/log/fhem.save
2023.04.27 08:02:33 0: Featurelevel: 6.2
2023.04.27 08:02:33 0: Server started with 314 defined entities (fhem.pl:27410/2023-04-07 perl:5.024001 os:linux user:fhem pid:11509)
Der letzte Eintrag in den FileLogs stammt von 07:59:36, was ziemlich genau der Zeitpunkt meines Zugriffs vom Arbeitsrechner sein müsste.
Dann gibt es welche von 08:01:05 bis 08:01:09, was dem Zeitpunkt des ersten (erfolglosen) Neustarts entspricht.
Seit 08:02:36 geht's wieder weiter.

Habe nun erneut den Zugriff vom Arbeits-Rechner versucht, geht natürlich wieder problemlos.

Was kann ich vorbereitend tun, damit ich das Problem beim nächsten Mal "einfangen" kann?
Loglevel von FHEMweb hochsetzen?
Globales Loglevel hochsetzen?

[TheTrumpeter]

Kurze Zeit später hat dann mein "Watchdog" FHEM neu gestartet.
Was mich wundert, ist, dass

• das Beenden von FHEM durch den Watchdog nicht im Logfile ersichtlich ist.
• der erste Neustart offenbar nicht erfolgreich war (wg. telnetPort-Fehler, den ich so noch nie gesehen habe)

So, DIESES Rätsel dürfte ich gelöst haben... der Watchdog hat nach dem Absetzen des "/etc/init.d/fhem stop" bisher 3 Sekunden gewartet, bevor "/etc/init.d/fhem start" abgesetzt wurde. Die 3 Sekunden Wartezeit habe ich irgendwann mal zu Friedenszeiten ausprobiert.
Im aktuellen Problemfall scheint es aber länger zu dauern bis FHEM tatsächlich beendet wird, weshalb der erneute "Start" in den laufenden Betrieb kommt. Daher fehlt der "Server shutdown" Logeintrag und es kommt beim erneuten Start zum Fehler mit dem Telnet-Port, weil der durch den laufenden Prozess noch blockiert ist.
Ich hab' die Wartezeit nun mal auf 15 Sekunden erhöht (10 waren auch zu wenig), damit der Neustart zumindest sauber funktioniert, wenn ich schon die Problemursache noch nicht finden konnte.

Einen wirklichen Plan wann es auftritt habe ich noch immer nicht.

[Beta-User]

Kann es sein, dass du unterschiedliche (FHEM-Detail-) Seiten aufrufst von den verschiedenen Rechnern aus?
Dann _könnte_ es sein, dass FHEM forkt (z.B. um svg's zu produzieren) und dann der PI (evtl. nur bei zusätzlichen anderen forks) anfängt zu swappen, und dann "zu langsam" ist, um alle Prozesse sauber/schnell genug abzuarbeiten. Grade wenn/weil du eine ramdisk eingebaut hast, ist der Speicher evtl. etwas knapp.

Je nachdem, von wo du (bei diversen Modulen) versionsmäßig kommst, gab es evtl. auch Änderungen in der Art und Weise, wann/wie geforkt wird und wie viele Events erzeugt werden.

[TheTrumpeter]

Kann es sein, dass du unterschiedliche (FHEM-Detail-) Seiten aufrufst von den verschiedenen Rechnern aus?

Kann Dir nicht ganz folgen, von den PCs gehe ich immer auf Port 8083 (FHEMweb), vom Smartphone auf 8084 (FHEMwebPhone).
Ich rufe immer wieder dieselben "rooms" auf, aber natürlich nicht immer nur einen.

Dann _könnte_ es sein, dass FHEM forkt (z.B. um svg's zu produzieren) und dann der PI (evtl. nur bei zusätzlichen anderen forks) anfängt zu swappen, und dann "zu langsam" ist, um alle Prozesse sauber/schnell genug abzuarbeiten. Grade wenn/weil du eine ramdisk eingebaut hast, ist der Speicher evtl. etwas knapp.

Heute um 8 habe ich ein Dashboard aufgerufen, von dem ich einfach meine Rollos/Raffstores aus steuern kann. Da ist praktisch nix zu laden.
Davor habe ich einige Minuten von keinem anderen Rechner aus zugegriffen. Zu dem Zeitpunkt waren ca. 800MB RAM frei (ist ein Pi3B mit 1GB, auf dem nur FHEM läuft, die RAM-Disk hat nur ein paar MB).

Je nachdem, von wo du (bei diversen Modulen) versionsmäßig kommst, gab es evtl. auch Änderungen in der Art und Weise, wann/wie geforkt wird und wie viele Events erzeugt werden.

Das Problem kam ja noch bevor ich ein "update" in FHEM gemacht habe, nach monatelangem problemlosen Betrieb. Das "update" habe ich nur gemacht, um das Problem dadurch ev. zufällig zu lösen, was leider nicht der Fall ist.

Ich habe im letzten Monat meine "große" PV-Anlage in Betrieb genommen und in dem Zuge erstmals ModbusAttrTCP konfiguriert bzw. in Betrieb genommen. Bis zum erstmaligen Problemauftritt ist es aber auch schon ca. 1 Monat gelaufen.
Eine Idee war grad, dass ev. die File-Logs dadurch deutlich größer sind als in der Vergangenheit, aber der Verdacht hat sich nicht bestätigt, die Files sind vergleichbar mit den ersten 3 Monaten in 2023. Dadurch sollte also auch keine höhere Last entstehen als früher.

Das Problem ist heute 2x so aufgetreten, dass der Browser (am Arbeitsrechner) gerade "connection lost, trying to reconnect every 5 seconds" oder so ähnlich geschrieben hat und ich dann einen anderen Raum angeklickt bzw. "aktualisieren" geklickt habe.
Und jetzt grad ist es wieder aufgetreten: ein Raum wurde noch vollständig geladen (ein paar SVG-Plots), ein paar Sekunden später habe ich einen anderen Raum angeklickt (Wettervorschau, d.h. keine SVGs zu produzieren). Als Status habe ich gerade noch den "TLS-Handshake" gesehen, danach wechselte es auf "Warten auf <IP-Adresse>" und da hängt's grad.
Der Watchdog ist dann wieder angesprungen und hat dem Treiben ein Ende gesetzt.

[Beta-User]

Kann es sein, dass du unterschiedliche (FHEM-Detail-) Seiten aufrufst von den verschiedenen Rechnern aus?

Kann Dir nicht ganz folgen, von den PCs gehe ich immer auf Port 8083 (FHEMweb), vom Smartphone auf 8084 (FHEMwebPhone).
Ich rufe immer wieder dieselben "rooms" auf, aber natürlich nicht immer nur einen.

Na ja, du hattest geschrieben, dass du beobachtet hattest, dass das Problem evtl. damit zusammenhing, dass du von deinem "Arbeitsrechner" aus zugreifst. Wenn das zutreffend wäre, müßte es am auszuliefernden Inhalt liegen, also entweder irgendwas "browserspezifisches", das FHEM "drumrum" ausliefert, oder eben am darzustellenden Inhalt. Die aufgerufene Web-Seite (html-Link) könnte ja (unabhängig vom Port) unterschiedlich sein, z.B. weil über entsprechende Favoriten oder anderweitig gespeicherte Detaillinks eben nicht zwangsläufig immer die "Startseite" augerufen werden muss.

Aber anscheinend hängt es doch nicht am Endgerät, auf dem FHEMWEB irgendwas darstellen soll.

_Vielleicht_ ist einfach die Hardware sonst irgendwie kaputt...

[TheTrumpeter]

Mal wieder ein Update:

Ende April trat das Problem immer mal wieder beim Zugriff von meinem Arbeitsrechner mit Firefox auf. Die genauen Abläufe wann es auftritt und wann nicht, konnte ich nicht herausfinden, aber es trat zuletzt 1-2x täglich auf.
Seitdem greife ich von diesem Rechner nur noch von Chrome aus zu, das Problem ist seither nicht mehr aufgetreten.

Ich bin daher nach wie vor der Meinung, dass es an irgendetwas liegen muss, was Firefox auf diesem Rechner "anders" macht.

Was könnte ich versuchen um das Problem "einzufangen"?
Würde es Sinn machen eine zusätzliche "FHEMweb"-Instanz mit anderem Port definieren, Loglevel dafür hochsetzen, und diesen Port nur vom Arbeitsrechner mit Firefox nutzen?