Ständig kleinere Freeze und manchmal einen Absturz

Begonnen von Jewe, 23 März 2023, 12:16:02

Vorheriges Thema - Nächstes Thema

Jewe

Hallo,

mein Fhem hat gestern Nacht um 23:18 mal wieder die Arbeit eingestellt. Heute Morgen habe ich dann den Pi aus und wieder eingeschaltet.
In der letzten Zeit häufen sich diese Abstürze. Uber den Tag verteilt gibt es mehrere Freeze 3-5s. Manchmal kann es auch sein, dass wenn ich einen in Raum mit meheren wechsele, dass dann Fhem einen neustart macht.
Mir ist nicht ganz klar, wie ich das eingrenzen kann um dann den eigentlichen Fehler zu finden.

Hier ein paar Auszüge aus den unterschiedlichen Log-Files

Fhem Log:
2023.03.22 23:17:52 3: OWCOUNT:  Device OWC1_NV defined.
2023.03.22 23:17:52 3: OWCOUNT:  Device OWC2 defined.
2023.03.22 23:17:52 3: PiHoleInfo: Defined with URL http://192.168.6.2/admin/api.php and interval 30 featurelevel 6.2
2023.03.22 23:18:10 3: TABLETUI7: new ext defined infix:tablet7/: dir:./www/tablet7:
2023.03.22 23:18:10 3: Registering HTTPSRV TABLETUI7 for URL /tablet7   and assigned link tablet7/ ...
2023.03.22 23:18:10 3: AptToDate (fhemServerApt) - defined
2023.03.22 23:18:10 3: UnifiSwitch_Define - Adress: udm_UDM_Pro
2023.03.22 23:18:10 3: UnifiSwitch_Define - Adress: Buero
2023.03.22 23:18:10 3: UnifiSwitch_Define - Adress: Netzwerkschrank
2023.03.22 23:18:11 1: Including ./log/fhem.save
2023.03.22 23:18:12 1: Messages collected while initializing FHEM:SecurityCheck:
  mqtt2Server is not password protected

Protect this FHEM installation by configuring the allowed device allowed_WEB
You can disable this message with attr global motd none

2023.03.22 23:18:12 3: Opening HMLAN device 192.168.6.21:1000
2023.03.22 23:18:12 1: HMLAN_Parse: HMLAN new condition init
2023.03.22 23:18:12 3: HMLAN device opened
2023.03.22 23:18:12 3: Opening myHmUARTLGW device 192.168.6.29:23
2023.03.22 23:18:16 3: FB_CALLMONITOR [Callmonitor: identifyPhoneBooksViaTR064.1903] - INFO: found 1 phonebooks
2023.03.22 23:18:16 3: FB_CALLMONITOR [Callmonitor: identifyPhoneBooksViaTR064.1980] - INFO: found 3 blocking rules (deflections)
2023.03.22 23:18:17 3: FB_CALLMONITOR [Callmonitor: readPhonebook.1392] - INFO: read 78 contacts from remote phonebook "Telefonbuch"
2023.03.22 23:18:17 2: FULLY: [Fully] Polling activated
2023.03.22 23:18:17 1: PERL WARNING: ^* matches null string many times in regex; marked by <-- HERE in m/^* <-- HERE ._Clima$/ at ./FHEM/33_readingsGroup.pm line 131.
2023.03.22 23:18:17 2: alexa: starting alexa-fhem: /usr/bin/alexa-fhem -c ./alexa-fhem.cfg -a xx:xx
2023.03.22 23:18:17 3: alexa: starting
2023.03.22 23:18:18 3: alexa: using logfile: ./log/alexa-2023-03-22.log
2023.03.23 07:53:16 1: usb create starting
sh: 1: echo: echo: I/O error
2023.03.23 07:53:16 3: Probing ZWDongle device /dev/serial1
2023.03.23 07:53:16 3: Probing CUL device /dev/ttyAMA0
2023.03.23 07:53:16 3: Probing TCM_ESP3 device /dev/ttyAMA0

Freezemon:
023-03-22_23:16:26 freezemon fs_N/A_t: 686998.477
2023-03-22_23:17:47 freezemon s:23:17:43 e:23:17:47 f:4.808 d:tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:17:47 freezemon freezeTime: 4.808
2023-03-22_23:17:47 freezemon fcDay: 1815
2023-03-22_23:17:47 freezemon ftDay: 6799.463
2023-03-22_23:17:47 freezemon freezeDevice: tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:17:47 freezemon fs_N/A_c: 260216
2023-03-22_23:17:47 freezemon fs_N/A_t: 687003.285
2023-03-22_23:19:09 freezemon s:23:19:04 e:23:19:09 f:5.775 d:tmr-HMUARTLGW_CheckCredits(myHmUARTLGW) tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:19:09 freezemon freezeTime: 5.775
2023-03-22_23:19:09 freezemon fcDay: 1816
2023-03-22_23:19:09 freezemon ftDay: 6805.238
2023-03-22_23:19:09 freezemon freezeDevice: tmr-HMUARTLGW_CheckCredits(myHmUARTLGW) tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:19:09 freezemon fs_myHmUARTLGW_c: 114744
2023-03-22_23:19:09 freezemon fs_myHmUARTLGW_t: 300919.238
2023-03-22_23:19:09 freezemon fs_N/A_c: 260217
2023-03-22_23:19:09 freezemon fs_N/A_t: 687009.06
2023-03-22_23:20:30 freezemon s:23:20:24 e:23:20:30 f:6.29 d:tmr-ENIGMA2_GetStatus(Dreambox800) tmr-ENIGMA2_GetStatus(Dreambox520) tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:20:30 freezemon freezeTime: 6.29
2023-03-22_23:20:30 freezemon fcDay: 1817
2023-03-22_23:20:30 freezemon ftDay: 6811.528
2023-03-22_23:20:30 freezemon freezeDevice: tmr-ENIGMA2_GetStatus(Dreambox800) tmr-ENIGMA2_GetStatus(Dreambox520) tmr-HttpUtils_TimeoutErr(N/A)
2023-03-22_23:20:30 freezemon fs_N/A_c: 260218
2023-03-22_23:20:30 freezemon fs_N/A_t: 687015.35
2023-03-22_23:20:30 freezemon fs_Dreambox800_c: 10430
2023-03-22_23:20:30 freezemon fs_Dreambox800_t: 31751.489
2023-03-22_23:20:30 freezemon fs_Dreambox520_c: 10409
2023-03-22_23:20:30 freezemon fs_Dreambox520_t: 31683.362
2023-03-23_07:53:50 freezemon s:07:53:37 e:07:53:50 f:13.572 d:no bad guy found :-(
2023-03-23_07:53:50 freezemon freezeTime: 13.572
2023-03-23_07:53:50 freezemon fcDay: 1827
2023-03-23_07:53:50 freezemon ftDay: 6810.62199999999
2023-03-23_07:53:50 freezemon freezeDevice: no bad guy found :-(
2023-03-23_07:53:53 freezemon s:07:53:52 e:07:53:53 f:1.369 d:tmr-CODE(0x5fb0b28)(PQprocess) tmr-CUL_HM_sndIfOpen(HMLAN) tmr-HMLAN_KeepAliveCheck(HMLAN) tmr-CUL_HM_procQs(N/A) tmr-FHEM::Installer::PollChild(fhemInstaller) tmr-HttpUtils_TimeoutErr(N/A) tmr-HttpUtils_TimeoutErr(N/A) tmr-HM485_LAN_CheckResendQueueItems(00000001)
2023-03-23_07:53:53 freezemon freezeTime: 1.369
2023-03-23_07:53:53 freezemon fcDay: 1828
2023-03-23_07:53:53 freezemon ftDay: 6811.99099999999
2023-03-23_07:53:53 freezemon freezeDevice: tmr-CODE(0x5fb0b28)(PQprocess) tmr-CUL_HM_sndIfOpen(HMLAN) tmr-HMLAN_KeepAliveCheck(HMLAN) tmr-CUL_HM_procQs(N/A) tmr-FHEM::Installer::PollChild(fhemInstaller) tmr-HttpUtils_TimeoutErr(N/A) tmr-HttpUtils_TimeoutErr(N/A) tmr-HM485_LAN_CheckResendQueueItems(00000001)
2023-03-23_07:53:53 freezemon fs_PQprocess_c: 1102
2023-03-23_07:53:53 freezemon fs_PQprocess_t: 3962.139
2023-03-23_07:53:53 freezemon fs_fhemInstaller_c: 188
2023-03-23_07:53:53 freezemon fs_fhemInstaller_t: 514.023
2023-03-23_07:53:53 freezemon fs_HMLAN_c: 26784
2023-03-23_07:53:53 freezemon fs_HMLAN_t: 78439.05
2023-03-23_07:53:53 freezemon fs_00000001_c: 17
2023-03-23_07:53:53 freezemon fs_00000001_t: 48.224
2023-03-23_07:53:53 freezemon fs_N/A_c: 258724
2023-03-23_07:53:53 freezemon fs_N/A_t: 681120.276
2023-03-23_07:53:59 freezemon s:07:53:58 e:07:53:59 f:1.152 d:tmr-CODE(0x5fb0b28)(PQprocess) tmr-HMUARTLGW_GetSetParameters(myHmUARTLGW) tmr-FHEM::Installer::PollChild(fhemInstaller)
2023-03-23_07:53:59 freezemon freezeTime: 1.152
2023-03-23_07:53:59 freezemon fcDay: 1829
2023-03-23_07:53:59 freezemon ftDay: 6813.14299999999
2023-03-23_07:53:59 freezemon freezeDevice: tmr-CODE(0x5fb0b28)(PQprocess) tmr-HMUARTLGW_GetSetParameters(myHmUARTLGW) tmr-FHEM::Installer::PollChild(fhemInstaller)
2023-03-23_07:53:59 freezemon fs_fhemInstaller_c: 189
2023-03-23_07:53:59 freezemon fs_fhemInstaller_t: 515.175
2023-03-23_07:53:59 freezemon fs_PQprocess_c: 1103
2023-03-23_07:53:59 freezemon fs_PQprocess_t: 3963.291
2023-03-23_07:53:59 freezemon fs_myHmUARTLGW_c: 114318
2023-03-23_07:53:59 freezemon fs_myHmUARTLGW_t: 299519.104
2023-03-23_07:54:02 freezemon s:07:54:00 e:07:54:02 f:2.314 d:tmr-CODE(0x5fb0b28)(PQprocess) tmr-CODE(0x9a34dd8)(__ANON__) tmr-OWX_PrQueue(1W_USB) tmr-CODE(0xabf08a8)(__ANON__) tmr-CODE(0x6732478)(HandleSendQueue) tmr-CODE(0xac9c7e0)(__ANON__)
2023-03-23_07:54:02 freezemon freezeTime: 2.314
2023-03-23_07:54:02 freezemon fcDay: 1830
2023-03-23_07:54:02 freezemon ftDay: 6815.45699999999
2023-03-23_07:54:02 freezemon freezeDevice: tmr-CODE(0x5fb0b28)(PQprocess) tmr-CODE(0x9a34dd8)(__ANON__) tmr-OWX_PrQueue(1W_USB) tmr-CODE(0xabf08a8)(__ANON__) tmr-CODE(0x6732478)(HandleSendQueue) tmr-CODE(0xac9c7e0)(__ANON__)
2023-03-23_07:54:02 freezemon fs_HandleSendQueue_c: 429

Freeze:
023.03.22 23:18:17.796 5: UnifiController (Unifi_DoUpdate) - executed.
2023.03.22 23:18:17.797 5: Activity: not on any display, ignoring notify
2023.03.22 23:18:17.797 5: Batterie: not on any display, ignoring notify
2023.03.22 23:18:17.803 5: End notify loop for UnifiController
2023.03.22 23:18:17.803 5: UnifiController (Unifi_Login_Send) - executed.
2023.03.22 23:18:17.804 5: IP: 192.168.6.1 -> 192.168.6.1
2023.03.22 23:18:17.804 5: UnifiController (Unifi_initCustomClientReadings) - parsed part: .  ->  ^accesspoint|^essid|^hostname|^last_seen|^snr|^uptime
2023.03.22 23:18:17.804 5: UnifiController (Unifi_initCustomClientReadings) - parsed Attribute customClientReadings: {"parts":{"0000000_part":{"nameRegEx":".","ReadingRegEx":"^accesspoint|^essid|^hostname|^last_seen|^snr|^uptime"}},"attr_value":".:^accesspoint|^essid|^hostname|^last_seen|^snr|^uptime"}.
2023.03.22 23:18:17.827 5: Cmd: >{sunset()}<
2023.03.22 23:18:17.827 5: Compute sunrise/sunset for latitude 48.80994 , longitude 9.45654
2023.03.22 23:18:17.829 5: Cmd: >{sunset()}<
2023.03.22 23:18:17.829 5: Compute sunrise/sunset for latitude 48.80994 , longitude 9.45654
2023.03.22 23:18:17.863 2: alexa: starting alexa-fhem: /usr/bin/alexa-fhem -c ./alexa-fhem.cfg -a xx:xx
2023.03.22 23:18:17.864 5: alexa: using /usr/bin/alexa-fhem
2023.03.22 23:18:17.872 3: alexa: starting
2023.03.22 23:18:17.876 5: createNotifyHash
2023.03.22 23:18:18.043 5: Activity: not on any display, ignoring notify
2023.03.22 23:18:18.043 5: Batterie: not on any display, ignoring notify
2023.03.22 23:18:18.050 5: End notify loop for alexa
2023.03.22 23:18:18.052 3: alexa: using logfile: ./log/alexa-2023-03-22.log
2023.03.22 23:18:18.074 5: Installer (fhemInstaller) - Notify: $VAR1 = [
  'INITIALIZED'
];

--- log skips 30895.028 secs.
2023.03.23 07:53:13.102 4: FHEM::Meta::__GetMetadata WARNING: Unregistered core module or package:
  FHEM/ABFALL_getEvents.pm has defined VCS data but is not registered in MAINTAINER.txt.
  Added acting maintainer with limited support status
2023.03.23 07:53:13.131 4: FHEM::Meta::__GetMetadata WARNING: Unregistered core module or package:
  FHEM/ABFALL_setUpdate.pm has defined VCS data but is not registered in MAINTAINER.txt.
  Added acting maintainer with limited support status
2023.03.23 07:53:13.164 4: FHEM::Meta::__GetMetadata WARNING: Unregistered core module or package:
  FHEM/57_ABFALL.pm has defined VCS data but is not registered in MAINTAINER.txt.
  Added acting maintainer with limited support status
2023.03.23 07:53:13.557 4: FHEM::Meta::__GetMetadata WARNING: Unregistered core module or package:
  FHEM/10_HM485.pm has defined VCS data but is not registered in MAINTAINER.txt.
  Added acting maintainer with limited support status
2023.03.23 07:53:13.690 4: FHEM::Meta::__GetMetadata WARNING: Unregistered core module or package:
  FHEM/RTypes.pm has defined VCS data but is not registered in MAINTAINER.txt.
  Added acting maintainer with limited support status
--- log skips     2.436 secs.
2023.03.23 07:53:16.127 5: SubProcess 778 created.
2023.03.23 07:53:16.129 5: createNotifyHash
2023.03.23 07:53:16.332 5: Activity: not on any display, ignoring notify
2023.03.23 07:53:16.333 5: Batterie: not on any display, ignoring notify
2023.03.23 07:53:16.342 5: Installer (fhemInstaller) - Notify: $VAR1 = [
  'state: command \'getCpanVersion\' in progress'
];

2023.03.23 07:53:16.345 5: End notify loop for fhemInstaller
2023.03.23 07:53:16.346 4: Installer (fhemInstaller) - execute command asynchronously (PID= 778)
2023.03.23 07:53:16.346 4: Installer (fhemInstaller) - control passed back to main loop.
2023.03.23 07:53:16.346 5: AptToDate (fhemServerApt) - Notify: $VAR1 = [
  'INITIALIZED'
];

2023.03.23 07:53:16.349 4: AptToDate (fhemServerApt) - stateRequestTimer: Call Request Timer
2023.03.23 07:53:16.360 5: SubProcess 788 created.
2023.03.23 07:53:16.364 5: Activity: not on any display, ignoring notify
2023.03.23 07:53:16.366 5: Batterie: not on any display, ignoring notify
2023.03.23 07:53:16.387 5: AptToDate (fhemServerApt) - Notify: $VAR1 = [

Aurel_B

Könnte ein Hardwareproblem sein, was verwendest du denn als Laufwerk auf deinem Pi? Gibt es in /var/log/messages oder in dmesg irgendwelche Auffälligkeiten? Gibt es sonstige Dienste auf deinem Pi und wenn ja, laufen diese stabil?

KölnSolar

Aus dem freezemon-Log ist ja eher kein Absturz, sondern eine Endlosschleife zu erkennen. Ich habe ein ähnliches Phänomen mit einem meiner in Entwicklung befindlichen Module.

Warum auch immer, ist die Symptomatik:
- auf FHEM lässt sich nicht mehr zugreifen
- aber sehr wohl noch auf den PI
- per SSH kann ich FHEM stoppen und neu starten
- lustigerweise hat FHEM sich dann sauber beendet und ich habe sogar Logeinträge über den shutdown.

Will damit sagen, Du musst nicht den Stecker ziehen, was bekanntlich der SD bzw. dem OS nicht gut bekommt, um FHEM wieder ans laufen zu kriegen.

Grüße Markus
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

Jewe

#3
Hallo Markus,
das ist mir bekannt und so versuche ich es normalerweise auch wenn ich am LG bin.
Könnte ich nur heute morgen nicht. Habe einen PI 4 mit SSD über USB.
 Die Symptome bei bei, mir meine ich, die selben.
Um welche Module handelt es sich bei Dir?

 Grüßle Jens

KölnSolar

#4
Hallo Jens
bei mir ist das der UPNPController in nicht reproduzierbaren Fällen. Verursacher sind dann devices, die falsche Daten liefern. Aber das Modul wirst Du sicherlich nicht einsetzen.

Ich halte es für wenig wahrscheinlich, aber denkbar wäre, dass Du ein "Multimedia"-Modul(Sonos, Yamaha...) nutzt, das auf das gleiche perl-Fremdpaket zugreift wie mein Modul. Ggfs. mal im SourceCode nach "upnp" suchen.

Grüße Markus

Edit: So richtig klar geworden ist mir das auch erst, weil mein Testsystem keinen "Notfallmechanismus" hat und nicht FHEM nicht zugänglich war. Produktiv lasse ich den PI-watchdog auf die Aktualisierung meiner fhem.save(per at update alle 15") prüfen und dadurch rebootet er recht schnell.
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

frank

oder war hier eventuell die internetverbindung "weg"?
zb weil über nacht jemand wlan ausschaltet?
FHEM: 6.0(SVN) => Pi3(buster)
IO: CUL433|CUL868|HMLAN|HMUSB2|HMUART
CUL_HM: CC-TC|CC-VD|SEC-SD|SEC-SC|SEC-RHS|Sw1PBU-FM|Sw1-FM|Dim1TPBU-FM|Dim1T-FM|ES-PMSw1-Pl
IT: ITZ500|ITT1500|ITR1500|GRR3500
WebUI [HMdeviceTools.js (hm.js)]: https://forum.fhem.de/index.php/topic,106959.0.html

Jewe

Internet war nicht gestört.
Es gibt schon einige Module in denen UPNP zu finden ist. Siehe Bild.
Sonos hatt ich bis vor ein paar Tagen noch verwendet, ist aber nun nicht mehr in Verwendung.

Fritzbox, FB_Callmonitor und DLNARenderer verwende ich noch.


KölnSolar

Der DLNARenderer wäre ein mutmaßlicher "Multimedia-"Kandidat. Kannst den ja mal rausnehmen.
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

Jewe

Ja, denke ich auch und ist auch schon weg. Werde nun mal beobachten.

Beta-User

Da du wohl auch CUL_HM im Einsatz hast: (bei mehrkanaligen Devices:) Kommunikationsevents in den Kanälen hast du abgeschaltet?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Jewe

Nicht absichtlich. Was und warum muss ich da machen ?

Beta-User

Wenn nicht absichtlich, hat sich das unabsichtlich geändert (keine Ironie). (An dem Punkt) zurück zum Stand vor vielen Monaten geht es (hoffentich, aus dem Kopf) mit
attr TYPE=CUL_HM:FILTER=DEF=.{6} commStInCh off
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Jewe

Vielen Dank für den Hinweis auf das Attribut in den HM Device. Das hatte ich nicht mitbekommen. So wie es aussieht macht das ja mächtig traffic auf dem PI.

Jens

DasQ

Ganz ehrlich, seit ich den Pi durch ein echten pc (Mac Mini) ersetzt habe. Läuft FHEM bedeutend besser. Hatte zuvor ein 3b+ im Einsatz und der tat es auch die ersten 4 Jahre problemlos.


Dann fing es langsam an zu nerven wenn latenzen oder Reaktion bis ins unendliche liefen.

Not gedrungen hab ich den Pi in Rente geschickt und hab nun einen 10 Jahre alten macmini im Einsatz. De4 tut das was er soll und das bei gerade mal 15w
Fhem on MacMini/Ubuntu.
Absoluter Befürworter der Konsequenten-Kleinschreibung https://de.wikipedia.org/wiki/Kleinschreibung
Infos zu Klimawandel http://www.globalcarbonatlas.org