FHEM - hängt sich ab und zu auf

[presskopf]

Hallo FHEM-Gemeinde,

ich hoffe, ich bin in diesem Subforum richtig.
Mein Fhem mit TSCUL, Jeelink und 433MHz-pilight-Sender läuft auf einem Raspberry 3 mit Stretch. Eigentlich ist es sehr stabil. Dennoch kommt es von Zeit zu Zeit, geschätzt 1 x pro Monat zu einem Absturz. Dabei rennt das FHEM mit 100 % und ist weder ansprechbar noch neu startbar. Nur ein kill -9 bzw. ein Reboot hilft.
Stromquelle ist ein 2A-Netzteil.

Hier das fhem-Log, das mein einziger Ansatzpunkt ist.
Ich glaube nicht, dass der gassistant was damit zu tun hat; aber vielleicht kann dessen log auch bei der Fehlersuche helfen. Sehen tue ich abe nix.
Ich selbst bin relativ ratlos und weiß noch nicht, wie ich nun vorgehen soll.
Verbose ist im fhem.log auf 3. Das stelle ich mal auf 4 bis wieder etwas passiert.

Code Auswählen Erweitern


pi@raspi-4:/opt/fhem/log# tail -n50 fhem-2019-05.log
2019.05.29 06:23:03 3: LogHist CUL5:  159701 A F001 15197796 00 0D 0A 8410 516081 E47309 06012200 -65.5dB
2019.05.29 06:23:03 3: LogHist CUL5:  172714 A F002 15210864 00 01 AE _ping
2019.05.29 06:23:03 3: LogHist CUL5:  203667 A F002 15241820 00 01 AE _ping
2019.05.29 06:23:03 3: LogHist CUL5:  208568 A F001 15246676 00 0C A9 865A 43110F 000000 90E432 -78dB
2019.05.29 06:23:03 3: LogHist CUL5:  217268 A F001 15255252 00 0D 1D 8041 430EFE 4B7CB0 074E0080 -75.5dB
2019.05.29 06:23:03 3: LogHist CUL5:  228516 A F001 15266680 00 0C A9 8470 43110F 000000 00E432 -78dB
2019.05.29 06:23:03 3: LogHist CUL5:  230236 A F001 15268344 00 0C F4 865A 430ED3 000000 98D635 -76dB
2019.05.29 06:23:03 3: LogHist CUL5:  235180 A F002 15273340 00 01 AE _ping
2019.05.29 06:23:03 3: LogHist CUL5:  246245 A F00C 15284396 00 0D D1 A610 44BC95 E47309 06010000 -82.5dB _AEScommReq
2019.05.29 06:23:03 3: LogHist CUL5:  246398 A F103 15284492 01 11 D1 A002 E47309 44BC95 0476C56D12C53702 _CCAdly:4 _dhmSt:96
2019.05.29 06:23:03 3: TSCUL_ParseTsHM: CUL5 HM AES Comm Req device authentication timed out from 44BC95/door_base:  246620 A F112 15284780 00 0D D1 A610 44BC95 E47309 06010000 -82.5dB _AuthTimeout
2019.05.29 06:35:00 3: CUL_HM set roll_sleep_window 100
2019.05.29 06:35:10 3: CUL_HM set roll_leonard 100
2019.05.29 06:35:20 3: CUL_HM set roll_vincent 100
2019.05.29 06:35:30 3: CUL_HM set roll_stairs 100
2019.05.29 06:35:40 3: CUL_HM set roll_kitchen 100
2019.05.29 06:35:50 3: CUL_HM set roll_dining_left 100
2019.05.29 06:36:00 3: CUL_HM set roll_living 100
2019.05.29 06:36:10 3: CUL_HM set roll_office 40
2019.05.29 06:36:20 3: CUL_HM set roll_bathroom_guest 100
2019.05.29 06:37:51 3: CUL_HM set roll_dining_left statusRequest
2019.05.29 06:38:01 3: CUL_HM set roll_living statusRequest
2019.05.29 06:38:11 3: CUL_HM set roll_office statusRequest
2019.05.29 09:37:06 3: eq3: Read response to update didn't match any Reading
2019.05.29 14:32:28 3: CUL_HM set roll_dining_right on
2019.05.29 21:24:46 3: TSCUL_ParseTsHM: CUL3 HM CCA channel busy error to 5160AA/motion_main:  347271 A F104 02371972 00 0D 0A 8002 E47309 5160AA 01012200 _sfail
2019.05.29 21:45:12 3: CUL_HM set roll_living off
2019.05.29 21:47:13 3: CUL_HM set roll_living statusRequest
2019.05.30 00:00:21 3: TelegramBot_Callback PesthundRaspi4: Digest: Number of poll failures on 2019-05-29 is :0:
2019.05.30 00:00:32 3: gassistant: using logfile: ./log/gassistant-2019-05-30.log
2019.05.30 00:29:25 1: PERL WARNING: Use of uninitialized value $buff in concatenation (.) or string at /usr/share/perl5/XML/Stream.pm line 1631.
2019.05.30 00:29:25 1: PERL WARNING: Use of uninitialized value $buff in string eq at /usr/share/perl5/XML/Stream.pm line 1635.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1829.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in concatenation (.) or string at /usr/share/perl5/XML/Stream.pm line 2740.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 2742.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in concatenation (.) or string at /usr/share/perl5/XML/Stream.pm line 1668.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1669.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at /usr/share/perl5/XML/Stream.pm line 1669.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1671.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1673.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in numeric eq (==) at /usr/share/perl5/XML/Stream.pm line 1673.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1675.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 1678.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value $sid in hash element at /usr/share/perl5/XML/Stream.pm line 2620.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at /usr/share/perl5/XML/Stream.pm line 1440.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in numeric eq (==) at /usr/share/perl5/XML/Stream.pm line 1443.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value within %status in numeric eq (==) at /usr/share/perl5/XML/Stream.pm line 1506.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in subtraction (-) at /usr/share/perl5/XML/Stream.pm line 1507.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in hash element at /usr/share/perl5/Net/XMPP/Connection.pm line 433.
2019.05.30 00:56:38 1: PERL WARNING: Use of uninitialized value in hash element at /usr/share/perl5/Net/XMPP/Connection.pm line 440.

Code Auswählen Erweitern


pi@raspi-4:/opt/fhem/log# tail -n 50 gassistant-2019-05-30.log
[30.5.2019, 00:15:51] update reading: roll_bathroom_guest:state = 92
[30.5.2019, 00:15:52] reportstate: roll_bathroom_guest
[30.5.2019, 00:16:22] update reading: roll_bathroom_guest:pct = 0
[30.5.2019, 00:16:22] update reading: roll_bathroom_guest:state = off
[30.5.2019, 00:16:23] reportstate: roll_bathroom_guest
[30.5.2019, 00:19:01] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:19:18] update reading: LaCrosse_smoke:temperature = 13.4
[30.5.2019, 00:19:23] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:19:39] update reading: LaCrosse_loft:temperature = 16.3
[30.5.2019, 00:19:48] update reading: LaCrosse_smoke:temperature = 13.4
[30.5.2019, 00:19:57] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:28:51] update reading: LaCrosse_garden:temperature = 12.7
[30.5.2019, 00:28:51] update reading: LaCrosse_garden:humidity = 70
[30.5.2019, 00:38:37] update reading: LaCrosse_smoke:temperature = 13.2
[30.5.2019, 00:38:37] update reading: thermo_bath_og_Climate:measured-temp = 22.6
[30.5.2019, 00:38:49] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:38:49] update reading: LaCrosse_smoke:temperature = 13.2
[30.5.2019, 00:39:02] update reading: LaCrosse_garden:humidity = 69
[30.5.2019, 00:39:14] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:39:14] update reading: LaCrosse_smoke:temperature = 13.2
[30.5.2019, 00:39:51] update reading: LaCrosse_loft:temperature = 16.2
[30.5.2019, 00:39:51] update reading: LaCrosse_smoke:temperature = 13.3
[30.5.2019, 00:39:52] update reading: LaCrosse_smoke:temperature = 13.2
[30.5.2019, 00:44:42] update reading: roll_dining_right:pct = 90
[30.5.2019, 00:44:42] update reading: roll_dining_right:state = 90
[30.5.2019, 00:44:43] update reading: roll_kitchen:pct = 90
[30.5.2019, 00:44:43] reportstate: roll_dining_right
[30.5.2019, 00:44:43] update reading: roll_kitchen:state = 90
[30.5.2019, 00:44:44] reportstate: roll_kitchen
[30.5.2019, 00:45:06] update reading: roll_dining_right:pct = 0
[30.5.2019, 00:45:06] update reading: roll_dining_right:state = off
[30.5.2019, 00:45:07] update reading: roll_kitchen:pct = 0
[30.5.2019, 00:45:07] update reading: roll_kitchen:state = off
[30.5.2019, 00:45:07] reportstate: roll_dining_right
[30.5.2019, 00:45:08] reportstate: roll_kitchen
[30.5.2019, 00:46:49] update reading: thermo_leonard_Climate:humidity = 52
[30.5.2019, 00:48:05] update reading: roll_sleep_window:pct = 92
[30.5.2019, 00:48:05] update reading: roll_sleep_window:state = 92
[30.5.2019, 00:48:06] reportstate: roll_sleep_window
[30.5.2019, 00:48:25] update reading: thermo_stairs_Climate:humidity = 54
[30.5.2019, 00:48:25] update reading: roll_sleep_window:pct = 19.5
[30.5.2019, 00:48:25] update reading: roll_sleep_window:state = 19.5
[30.5.2019, 00:48:26] reportstate: roll_sleep_window
[30.5.2019, 00:50:59] update reading: thermo_bath_og_Climate:measured-temp = 22.7
[30.5.2019, 00:57:33] update reading: thermo_sleep_Climate:measured-temp = 20.8
[30.5.2019, 00:59:04] update reading: LaCrosse_garden:temperature = 12.6
[30.5.2019, 00:59:05] update reading: LaCrosse_garden:humidity = 70
[30.5.2019, 00:59:16] update reading: LaCrosse_smoke:temperature = 13.1
[30.5.2019, 00:59:16] update reading: LaCrosse_smoke:temperature = 13.2
[30.5.2019, 01:00:05] update reading: LaCrosse_loft:temperature = 16.1

[viegener]

@presskopf: Aus Deinem logfile kann ich gar nichts lesen, da nicht klar ist, wann und ob das Problem in diesem logfile aufgetreten ist.

100% CPU muss nicht zwingend an einem Modul liegen, gibt es bei Dir auch eigenen perl-code (z.B. myutils) ? Endlosschleifen in eigenem Code sind auch eine wunderbare Ursache für 100% CPU und kompletten Stillstand.

Vorschlag: Ich denke es wäre vermutlich sinnvoller den Beitrag im Anfängerfragen-Bereich zu stellen.

[presskopf]

Da sage ich gleich mal DoppelDanke.
Die Myutils habe ich mit Debianmail, urDewpoint, Jabber und Homematic eq3 Firmwareupdate.
Das guck ich mir auch nochmal an.

Ich lass den Thread verschieben; das passt wohl wirklich besser.

[presskopf]

Hmmm, ich traue dem Braten nicht, aber seitdem das Jabbermodul raus ist, ist Ruhe eingekehrt.