[gelöst] Fhem startet zwischen 0 und 1 Uhr Nachts immer neu

[kask]

Hallo,
ich habe mein System von einem Raspberry (Buster) auf einen anderen Raspberry mit Bullseye umgezogen.
Das funktionierte auch fast reibungslos. Allerdings habe ich jetzt das Problem das der FHEM service zwischen 0 und 1 Uhr nachts immer neustartet.
Ich vermute es liegt an irgend welchen Zeitfunktionen innerhalb von den Perlmodulen.
Hat einer eine Idee wie ich das rausbekomme (außer global verbose)? Am liebsten mit einer auflistung was perl alles haben will für fhem bzw. deren eingebundenen module. Und nicht erst zur Laufzeit wenn das benötigt wird. Gibt es da Möglichkeiten?
Syslog, journal etc. bringen mir nicht wirklich den Grund warum das passiert.

hier geht es los:

Code Auswählen Erweitern

Sep  8 00:00:08 RPiAutoHome systemd[1]: fhem.service: Main process exited, code=killed, status=11/SEGV
Sep  8 00:00:15 RPiAutoHome grafana[1156]: logger=infra.usagestats t=2023-09-08T00:00:15.049258646+02:00 level=info msg="Usage stats are ready to report"
Sep  8 00:01:01 RPiAutoHome CRON[690226]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: State 'stop-sigterm' timed out. Killing.
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: Killing process 442741 (perl) with signal SIGKILL.
Sep  8 00:01:39 RPiAutoHome mariadbd[829]: 2023-09-08  0:01:39 741 [Warning] Aborted connection 741 to db: 'fhem' user: 'fhem' host: 'localhost' (Got an error reading communication packets)
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: Failed with result 'signal'.
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: Consumed 6h 40min 48.265s CPU time.
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: Scheduled restart job, restart counter is at 38.
Sep  8 00:01:39 RPiAutoHome systemd[1]: Stopped FHEM Home Automation.
Sep  8 00:01:39 RPiAutoHome systemd[1]: fhem.service: Consumed 6h 40min 48.265s CPU time.
Sep  8 00:01:39 RPiAutoHome systemd[1]: Starting FHEM Home Automation...
Sep  8 00:01:40 RPiAutoHome systemd[1]: Started FHEM Home Automation.
Sep  8 00:01:49 RPiAutoHome systemd[1]: fhem.service: Main process exited, code=killed, status=11/SEGV
Sep  8 00:02:01 RPiAutoHome CRON[690695]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 00:03:01 RPiAutoHome CRON[691087]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 00:03:19 RPiAutoHome systemd[1]: fhem.service: State 'stop-sigterm' timed out. Killing.
Sep  8 00:03:19 RPiAutoHome systemd[1]: fhem.service: Killing process 690493 (perl) with signal SIGKILL.
Sep  8 00:03:19 RPiAutoHome mariadbd[829]: 2023-09-08  0:03:19 2789 [Warning] Aborted connection 2789 to db: 'fhem' user: 'fhem' host: 'localhost' (Got an error reading communication packets)
Sep  8 00:03:19 RPiAutoHome systemd[1]: fhem.service: Failed with result 'signal'.
Sep  8 00:03:19 RPiAutoHome systemd[1]: fhem.service: Consumed 13.031s CPU time.
Sep  8 00:03:20 RPiAutoHome systemd[1]: fhem.service: Scheduled restart job, restart counter is at 39.
Sep  8 00:03:20 RPiAutoHome systemd[1]: Stopped FHEM Home Automation.
Sep  8 00:03:20 RPiAutoHome systemd[1]: fhem.service: Consumed 13.031s CPU time.
Sep  8 00:03:20 RPiAutoHome systemd[1]: Starting FHEM Home Automation...
Sep  8 00:03:20 RPiAutoHome systemd[1]: Started FHEM Home Automation.
Sep  8 00:03:30 RPiAutoHome systemd[1]: fhem.service: Main process exited, code=killed, status=11/SEGV
 

dann geht es genau eine Stunde lang so weiter:

Code Auswählen Erweitern

Sep  8 00:58:21 RPiAutoHome grafana[1156]: logger=plugins.update.checker t=2023-09-08T00:58:21.509515996+02:00 level=info msg="Update check succeeded" duration=105.842147ms
Sep  8 00:58:29 RPiAutoHome systemd[1]: fhem.service: Main process exited, code=killed, status=11/SEGV
Sep  8 00:59:01 RPiAutoHome CRON[715861]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: State 'stop-sigterm' timed out. Killing.
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: Killing process 715530 (perl) with signal SIGKILL.
Sep  8 00:59:59 RPiAutoHome mariadbd[829]: 2023-09-08  0:59:59 3446 [Warning] Aborted connection 3446 to db: 'fhem' user: 'fhem' host: 'localhost' (Got an error reading communication packets)
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: Failed with result 'signal'.
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: Consumed 12.184s CPU time.
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: Scheduled restart job, restart counter is at 71.
Sep  8 00:59:59 RPiAutoHome systemd[1]: Stopped FHEM Home Automation.
Sep  8 00:59:59 RPiAutoHome systemd[1]: fhem.service: Consumed 12.184s CPU time.
Sep  8 00:59:59 RPiAutoHome systemd[1]: Starting FHEM Home Automation...
Sep  8 01:00:00 RPiAutoHome systemd[1]: Started FHEM Home Automation.
Sep  8 01:00:01 RPiAutoHome CRON[716256]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 01:00:15 RPiAutoHome grafana[1156]: logger=infra.usagestats t=2023-09-08T01:00:15.046657391+02:00 level=info msg="Usage stats are ready to report"
Sep  8 01:01:01 RPiAutoHome CRON[716737]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 01:02:01 RPiAutoHome CRON[717138]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 01:03:01 RPiAutoHome CRON[717493]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 01:04:01 RPiAutoHome CRON[717893]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)
Sep  8 01:05:01 RPiAutoHome CRON[718288]: (pi) CMD (/home/pi/battery-ps5120e/ps5120e_rs232_mqtt.sh > /dev/null 2>&1)


[betateilchen]

Vermutlich ist das gar kein Problem von FHEM, sondern von Deiner (neuen) Systemumgebung.

ich habe mein System von einem Raspberry (Buster) auf einen anderen Raspberry mit Bullseye umgezogen.
Das funktionierte auch fast reibungslos.

Hast Du mal kontrolliert, ob die Zeitzone auf dem neuen Raspberry korrekt eingestellt ist?

auflistung was perl alles haben will für fhem bzw. deren eingebundenen module. Und nicht erst zur Laufzeit wenn das benötigt wird.

Dieser Gedanke ist doch einigermaßen unlogisch.

• Ein fehlendes zusätzliches perl-Modul würde sich schon beim FHEM-Start bemerkbar machen, nicht erst während der Laufzeit (mal abgesehen von der Neuanlage eines fhem devices).
• Darüber hinaus würde eine fehlende Voraussetzung immer fehlen, nicht nur im Zeitraum von 00:00 bis 01:00 Uhr.

[kask]

Die Zeitzone sollte passen. Zumindest habe ich diese gesetzt und andere funktion funktionieren auch mit der richtigen Zeitzone.

Dieser Gedanke ist doch einigermaßen unlogisch.
Ein fehlendes zusätzliches perl-Modul würde sich schon beim FHEM-Start bemerkbar machen, nicht erst während der Laufzeit (mal abgesehen von der Neuanlage eines fhem devices).
Darüber hinaus würde eine fehlende Voraussetzung immer fehlen, nicht nur im Zeitraum von 00:00 bis 01:00 Uhr.

Nunja, wenn der Aufruf nur zwischen 0 und 1 Uhr passiert von FunktionXY dann hätte man das Problem doch.
Bin kein Perl Profi.
Aber wie gesagt, meine Vermutung ist das Perl da was machen will was es nicht kann. Natürlich kann es auch am System selbst liegen, keine Frage.

Edit: Und da es jeden Tag zwischen 0 und 1 Uhr passiert. Seit dem Aufsetzen vor 4 Tagen. Lässt mich das darauf schließen das eine Zeit Funktion nicht wirklich funktioniert.

[betateilchen]

was steht denn im FHEM Log zu diesem Zeitpunkt?

[kask]

nichts!

Aber beim debuggen bin ich auf folgendes gestossen:

Code Auswählen Erweitern


2023.09.09 00:00:08.022 5: Starting notify loop for Venusstat, 1 event(s), first is Updated stats for: MQTT2_venus
2023.09.09 00:00:08.025 5: End notify loop for Venusstat
2023.09.09 00:00:08.025 5: statistics Venusstat: Notify.296 Notification of 'MQTT2_venus' received. Update statistics.
2023.09.09 00:00:08.028 5: End notify loop for MQTT2_venus
2023.09.09 00:00:08.031 5: Starting notify loop for ForecastDWD, 1 event(s), first is wrote cachefile plantconfig successfully
2023.09.09 00:00:08.033 5: End notify loop for ForecastDWD
2023.09.09 00:00:08.044 3: ForecastDWD - history day "09" deleted
2023.09.09 00:00:08.045 5: Starting notify loop for ForecastDWD, 1 event(s), first is wrote cachefile consumers successfully
2023.09.09 00:00:08.047 5: End notify loop for ForecastDWD
2023.09.09 00:00:08.087 5: HttpUtils url=https://opendata.dwd.de/weather/local_forecasts/mos/MOSMIX_L/single_stations/N9109/kml/MOSMIX_L_LATEST_N9109.kmz  Blocking via https
Speicherzugriffsfehler
pi@RPiAutoHome:/opt/fhem $ 2023.09.09 00:00:08.151 5: HttpUtils request header:



[schwatter]

Nutzt du SolarForecast? Das Modul hat gerade ein Problem.
Update kommt. Oder du downgradest auf eine 81er Version.

Gruß schwatter

[kask]

Nutze Solarforcast!

Und Mit dem DWD Daten update gibts wohl ein Problem. Ohne geht es mit ist um Mitternacht sense.
Der HTTPs request antwortet auch noch brav. also der kommt. Es scheint woanders im Modul was fritte zu sein. Zumindest bei mir.
Die anderen Forcasts mit dem Modul gehen.

Code Auswählen Erweitern

defmod ForecastDWD SolarForecast
attr ForecastDWD DbLogExclude .*
attr ForecastDWD affect70percentRule 0
attr ForecastDWD comment update per "wget -qO /opt/fhem/FHEM/76_SolarForecast.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/76_SolarForecast.pm"
attr ForecastDWD ctrlInterval 15
attr ForecastDWD ctrlLanguage DE
attr ForecastDWD disable 0
attr ForecastDWD event-on-change-reading .*
attr ForecastDWD flowGraphicAnimate 0
attr ForecastDWD flowGraphicShowConsumer 0
attr ForecastDWD flowGraphicShowConsumerDummy 0
attr ForecastDWD flowGraphicShowConsumerRemainTime 1
attr ForecastDWD flowGraphicSize 10
attr ForecastDWD graphicBeam1Color CBD4C1
attr ForecastDWD graphicBeam1Content pvForecast
attr ForecastDWD graphicBeam2Color 77FF00
attr ForecastDWD graphicBeam2Content pvReal
attr ForecastDWD graphicHeaderDetail all
attr ForecastDWD graphicHistoryHour 4
attr ForecastDWD graphicLayoutType double
attr ForecastDWD graphicShowDiff top
attr ForecastDWD graphicShowNight 0
attr ForecastDWD graphicShowWeather 1
attr ForecastDWD room Vorhersagen
attr ForecastDWD stateFormat Current_PV