FHEM beendet sich jedesmal nach 20min automatisch

[Stargazer]

Hallo zusammen,

seit Montag habe ich das Problem, dass sich FHEM immer nach ca. 20 min. automatisch beendet.
Ich habe eine Instanz nur für das erfassen von Energieflüsse hier im Haus (PV, Windanlage sowie Verbrauch und Einspeisung).
Doch diese schließt sich komischerweise immer von selber. Ich habe schon einiges gemacht. Die letzten 20 Einträge im Log sind immer
unterschiedlich.

Die CPU-Last ist im Betrieb normal.

Mittels "top" - Befehl sehe ich, dass der user FHEM läuft. Nach den ca. 20min ist der User verschwunden. Dann starte ich manuell nochmal
noch komplett neu (erst stop, dann start). Es läuft wieder alles und der user fhem ist wieder in der liste vertreten.

Auch ist er in den Prozessen zu finden.

Was kurios ist. Es wird ein Graph dargestellt, der, wenn das Phänomen auftritt, sich trotzdem um diese Zeit wieder aktualisiert.
D.h., er bildet statt einer Kurve, Treppenstufen ab. Speicher sind alle im grünen Bereich (Lüfterloses System mittels VM (Ubuntu LTS 16.04 LTS)).

Leider bin ich nicht so der Linux - Kenner.

Hätte da jemand noch einen Tipp für mich ?

Besten Dank und viele Grüße

André 

[KölnSolar]

Hallo Andre,

Mittels "top" - Befehl sehe ich, dass der user FHEM läuft. Nach den ca. 20min ist der User verschwunden. Dann starte ich manuell nochmal
noch komplett neu (erst stop, dann start).

Heißt ja eher, dass fhem läuft. Mit sudo ps -e kannst Du das genauer sehen.

Wenn es tatsächlich ein fhem-Absturz ist, könntest Du das restart, sofern bei VM möglich, über einen System-watchdog automatisieren.

Um dem Grund des Problems auf die Spur zu kommen, könnte ein verbose 5 beim global-device helfen.

Grüße Markus

[MadMax-FHEM]

Wollte auch schreiben: den "User" fhem siehst du in top nicht immer, sondern nur wenn fhem AKTIV was tut und so in top "nach oben  wandert"...

Genauer geht es mit ps (wie geschrieben).

Wenn du nicht stoppst/neu startest ist dann fhem "von alleine" wieder da?

Weil es sieht eher nach "Blockieren" aus.
Also fhem wartet auf etwas -> nichts zu tun -> "raus" aus top...
...solnage fhem BLOCKIEREND auf etwas wartet ist es auch nicht erreichbar und zeichnet nat. auch keine Readings/Logs auf...

Spricht auch ein wenig für die Beschreibung deiner Logs/Grafik etc.

Evtl. mal freezemon aktivieren...

Gruß, Joachim

[Stargazer]

Hallo zusammen,

erst einmal vielen Dank für eure Antworten.

Ich habe noch versucht, etwas mehr über das Freezing habe ich noch nicht heraus bekommen.
Erst dachte ich, es sei das EnergyMeter von SMA. Dann dachte ich, dass der SMA Wechselrichter schuld sei.
Wie gesagt, das System wurde in letzter Zeit nicht verändert. Auch nix bei den Geräte, wo er drauf zu greift.

Ich habe FreezeMon mal am start. Wusste garnicht, dass es mittlerweile so ein Modul gibt .

Persönlich habe ich auch das Gefühl, dass es eher FHEM betrifft.
Nun habe ich natürlich gestern, nachdem der Fehler bereits auftrat, ein Update von FHEM gemacht.

Bei "sudo ps -e" taucht der PID, den ich bei dem "sudo service fhem status" eigebe, nicht auf.

Trotzdem läuft FHEM.


Hier aktuell mit dem Status, wenn das System läuft:

● fhem.service - LSB: FHEM server
   Loaded: loaded (/etc/init.d/fhem; bad; vendor preset: enabled)
   Active: active (running) since Sat 2021-07-10 13:10:50 CEST; 20min ago
     Docs: man:systemd-sysv-generator(
  Process: 19566 ExecStop=/etc/init.d/fhem stop (code=exited, status=0/SUCCESS)
  Process: 19577 ExecStart=/etc/init.d/fhem start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/fhem.service
           └─19584 perl fhem.pl fhem.cfg

Jul 10 13:10:49 ubuntu systemd[1]: Starting LSB: FHEM server...
Jul 10 13:10:49 ubuntu fhem[19577]: Starting fhem...
Jul 10 13:10:50 ubuntu systemd[1]: Started LSB: FHEM server.



...und hier, bei einem crash...:

● fhem.service - LSB: FHEM server
   Loaded: loaded (/etc/init.d/fhem; bad; vendor preset: enabled)
   Active: active (running) since Sat 2021-07-10 12:08:32 CEST; 1h 0min ago
     Docs: man:systemd-sysv-generator(
  Process: 17919 ExecStop=/etc/init.d/fhem stop (code=exited, status=1/FAILURE)
  Process: 17931 ExecStart=/etc/init.d/fhem start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/fhem.service
           ├─17938 perl fhem.pl fhem.cfg
           └─19504 perl fhem.pl fhem.cfg

Jul 10 12:08:31 ubuntu systemd[1]: Starting LSB: FHEM server...
Jul 10 12:08:31 ubuntu fhem[17931]: Starting fhem...
Jul 10 12:08:32 ubuntu systemd[1]: Started LSB: FHEM server.

Was meint ihr ?

Besten Dank und viele Grüße

André

[KölnSolar]

Bei "sudo ps -e" taucht der PID, den ich bei dem "sudo service fhem status" eigebe, nicht auf.

Achte auf perl-Prozesse. Ggfs. gibt es mehrere(bei z.B. BlockingCall). Stabil(dauerhaft) dürfte es nur genau einen geben.
systemctl zeigt sich so mit der selben PID

Code Auswählen Erweitern

fhem.service - FHEM service
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2021-07-04 00:17:12 CEST; 6 days ago
  Process: 545 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 628 (perl)
    Tasks: 1 (limit: 2062)
   CGroup: /system.slice/fhem.service
           └─628 /usr/bin/perl fhem.pl fhem.cfg

Jul 04 00:17:06 raspberrypi systemd[1]: Starting FHEM service...
Jul 04 00:17:12 raspberrypi systemd[1]: Started FHEM service.


[Stargazer]

Hi,

folgender Prozess taucht bei "sudo ps -e" auf, obwohl das System gerade wieder nicht via Browser erreichbar ist

Code Auswählen Erweitern

19584 ?        00:02:04 perl


Dazu das systemctl...:

Code Auswählen Erweitern

● fhem.service - LSB: FHEM server
   Loaded: loaded (/etc/init.d/fhem; bad; vendor preset: enabled)
   Active: active (running) since Sat 2021-07-10 13:10:50 CEST; 1h 23min ago
     Docs: man:systemd-sysv-generator(8)
  Process: 19566 ExecStop=/etc/init.d/fhem stop (code=exited, status=0/SUCCESS)
  Process: 19577 ExecStart=/etc/init.d/fhem start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/fhem.service
           └─19584 perl fhem.pl fhem.cfg

Jul 10 13:10:49 ubuntu systemd[1]: Starting LSB: FHEM server...
Jul 10 13:10:49 ubuntu fhem[19577]: Starting fhem...
Jul 10 13:10:50 ubuntu systemd[1]: Started LSB: FHEM server.


Diesesmal steht in der "ExecStop..."-Zeile kein Failed, obwohl das System nicht erreichbar ist.

Der PID tauch nun auch überall auf.



FreezeMon zeigt folgendes..:

Code Auswählen Erweitern

1 - 2021-07-10: s:13:49:16 e:13:56:12 f:416.978 d:no bad guy found :-(
1 - 2021-07-10: s:13:58:44 e:14:15:35 f:1011.901 d:tmr-SMAInverter_GetData(SB4000) tmr-CODE(0xa6fa920)(GetUpdate) tmr-SMAWebbox_GetUpdate(Windturbine)
1 - 2021-07-10: s:14:18:23 e:14:38:57 f:1234.216 d:no bad guy found :-(

Alles komisch...

[Wernieman]

Mir währe lieber:

Code Auswählen Erweitern

ps aux | grep [f]hem

Und

Code Auswählen Erweitern

netstat -lntp

im zweifel bitte als root oder sudo Aufrufen. Kann es gerade nicht nachstellen ...

[KölnSolar]

folgender Prozess taucht bei "sudo ps -e" auf, obwohl das System gerade wieder nicht via Browser erreichbar ist

Heißt: FHEM läuft noch, aber furchterregende Blockierung u. genau im 20' Rhythmus.

Code Auswählen Erweitern

1 - 2021-07-10: s:13:49:16 e:13:56:12 f:416.978 d:no bad guy found :-(
1 - 2021-07-10: s:13:58:44 e:14:15:35 f:1011.901 d:tmr-SMAInverter_GetData(SB4000) tmr-CODE(0xa6fa920)(GetUpdate) tmr-SMAWebbox_GetUpdate(Windturbine)
1 - 2021-07-10: s:14:18:23 e:14:38:57 f:1234.216 d:no bad guy found :-(Zuerst "nur" 7', dann 17' dann 20,5'

Es gibt auch ein separates freeze-Log. Da sollte man den Schuldigen erkennen können.

[Stargazer]

Hallo,

hier das Ergebnis zu "sudo ps aux | [f]hem und anschließend "sudo netstat -lntp" :

Code Auswählen Erweitern

stargazer@ubuntu:~$ sudo ps aux | grep [f]hem
fhem     23123 16.1  2.6  58672 54480 ?        R    15:41   0:07 perl fhem.pl fhem.cfg
fhem     23158 11.4  2.7  62392 57368 ?        SN   15:41   0:01 perl fhem.pl fhem.cfg
stargazer@ubuntu:~$ sudo netstat -lntp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:7072            0.0.0.0:*               LISTEN      23123/perl
tcp        0      0 0.0.0.0:8083            0.0.0.0:*               LISTEN      23123/perl
tcp        0      0 0.0.0.0:8084            0.0.0.0:*               LISTEN      23123/perl
tcp        0      0 0.0.0.0:8085            0.0.0.0:*               LISTEN      23123/perl
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      845/sshd
tcp6       0      0 :::22                   :::*                    LISTEN      845/sshd
stargazer@ubuntu:~$


Mit dem Freezelog muss ich noch mal schauen.

Ich musste erst das Log anlegen. Habe jetzt in den Attributen folgendes angelegt :

"attr FreezeMonitoring fm_logFile /home/freezinglog.log"

Ich hoffe, dass passt so ? Bis jetzt kann ich an der Stelle noch keine Datei sehen.

VG

André

[Wernieman]

Also ich würde auch darauf tippen, das fhem einen freez hat und sich eben NICHT beendet.

[Stargazer]

Hallo,

ich zeige euch nochmal einen Mitschnitt aus dem EventMonitor. Da meldet sich das EnergyMeter von SMA.
Wir haben noch die erste Version, ohne den integrierten Home Manager.

Code Auswählen Erweitern

2021.07.10 17:43:04 5 : SMAEM SMA_EM - received 600 bytes from "1900235xxx" but interval 4s isn't expired.
2021.07.10 17:43:05 5 : SMAEM SMA_EM - received 600 bytes from "1900235xxx" but interval 4s isn't expired.
2021.07.10 17:43:06 5 : SMAEM SMA_EM - received 600 bytes from "1900235xxx" but interval 4s isn't expired.
2021.07.10 17:43:07 4 : SMAEM SMA_EM - ###############################################################
2021.07.10 17:43:07 4 : SMAEM SMA_EM - ### Begin of new SMA Energymeter 1900235xxx get data cycle ###
2021.07.10 17:43:07 4 : SMAEM SMA_EM - ###############################################################
2021.07.10 17:43:07 4 : SMAEM SMA_EM - discarded cycles since module start: 0
2021.07.10 17:43:07 4 : SMAEM SMA_EM - last update time set to: 10.07.2021 / 17:43:07
2021.07.10 17:43:07 4 : BlockingCall (SMAEM_DoParse): created child (25768), uses telnetPort to connect back
2021.07.10 17:43:07 4 : SMAEM SMA_EM - Blocking process with PID: 25768 started
2021.07.10 17:43:07 4 : Connection accepted from telnetPort_127.0.0.1_57174
2021.07.10 17:43:07 4 : SMAEM SMA_EM - last update time set to: 10.07.2021 / 17:43:07
2021.07.10 17:43:07 4 : SMAEM SMA_EM - wrote new energy values to INTERNALS - GRIDIN_SUM_1900235xxx: 11849.879, GRIDOUT_SUM_1900235xxx: 37818.9322
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_WirkP_Zaehler_Diff: 0.0042
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_WirkP_Kosten_Diff: 0.0011
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_WirkP_Zaehler_Diff: 0
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_WirkP_Verguet_Diff: 0.0000
2021-07-10 17:43:08 SMAEM SMA_EM -3805.3
2021-07-10 17:43:08 SMAEM SMA_EM Saldo_Wirkleistung: -3805.3
2021-07-10 17:43:08 SMAEM SMA_EM Saldo_Wirkleistung_Zaehler: -25969.1
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Wirkleistung: 3805.3
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Wirkleistung_Zaehler: 37818.9322
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Wirkleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Wirkleistung_Zaehler: 11849.8790
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Blindleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Blindleistung_Zaehler: 7456.5
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Blindleistung: 1261.5
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Blindleistung_Zaehler: 2214.4
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Scheinleistung: 4008.9
2021-07-10 17:43:08 SMAEM SMA_EM Bezug_Scheinleistung_Zaehler: 39712.4
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Scheinleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM Einspeisung_Scheinleistung_Zaehler: 12402.7
2021-07-10 17:43:08 SMAEM SMA_EM CosPhi: 0.949
2021-07-10 17:43:08 SMAEM SMA_EM SoftwareVersion: 1.02.04.R
2021-07-10 17:43:08 SMAEM SMA_EM SerialNumber: 1900235xxx
2021-07-10 17:43:08 SMAEM SMA_EM SUSyID: 270
2021-07-10 17:43:08 SMAEM SMA_EM OBISnewItems: none
2021-07-10 17:43:08 SMAEM SMA_EM L1_Saldo_Wirkleistung: -1930.3
2021-07-10 17:43:08 SMAEM SMA_EM L1_Saldo_Wirkleistung_Zaehler: -20369.8
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Wirkleistung: 1930.3
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Wirkleistung_Zaehler: 21405.6
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Wirkleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Wirkleistung_Zaehler: 1035.8
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Blindleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Blindleistung_Zaehler: 8223.7
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Blindleistung: 190.1
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Blindleistung_Zaehler: 211.3
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Scheinleistung: 1939.6
2021-07-10 17:43:08 SMAEM SMA_EM L1_Bezug_Scheinleistung_Zaehler: 23446.9
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Scheinleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L1_Einspeisung_Scheinleistung_Zaehler: 1172.5
2021-07-10 17:43:08 SMAEM SMA_EM L1_Strom: 8.57
2021-07-10 17:43:08 SMAEM SMA_EM L1_Spannung: 228.0
2021-07-10 17:43:08 SMAEM SMA_EM L1_CosPhi: 0.995
2021-07-10 17:43:08 SMAEM SMA_EM L2_Saldo_Wirkleistung: -478.4
2021-07-10 17:43:08 SMAEM SMA_EM L2_Saldo_Wirkleistung_Zaehler: 4087.4
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Wirkleistung: 478.4
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Wirkleistung_Zaehler: 11431.7
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Wirkleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Wirkleistung_Zaehler: 15519.1
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Blindleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Blindleistung_Zaehler: 932.4
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Blindleistung: 547.1
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Blindleistung_Zaehler: 3171.6
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Scheinleistung: 726.8
2021-07-10 17:43:08 SMAEM SMA_EM L2_Bezug_Scheinleistung_Zaehler: 12244.6
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Scheinleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L2_Einspeisung_Scheinleistung_Zaehler: 15829.2
2021-07-10 17:43:08 SMAEM SMA_EM L2_Strom: 3.15
2021-07-10 17:43:08 SMAEM SMA_EM L2_Spannung: 236.3
2021-07-10 17:43:08 SMAEM SMA_EM L2_CosPhi: 0.658
2021-07-10 17:43:08 SMAEM SMA_EM L3_Saldo_Wirkleistung: -1396.6
2021-07-10 17:43:08 SMAEM SMA_EM L3_Saldo_Wirkleistung_Zaehler: -9686.7
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Wirkleistung: 1396.6
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Wirkleistung_Zaehler: 12049.2
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Wirkleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Wirkleistung_Zaehler: 2362.5
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Blindleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Blindleistung_Zaehler: 1375.7
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Blindleistung: 524.4
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Blindleistung_Zaehler: 1906.7
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Scheinleistung: 1491.8
2021-07-10 17:43:08 SMAEM SMA_EM L3_Bezug_Scheinleistung_Zaehler: 12853.0
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Scheinleistung: 0.0
2021-07-10 17:43:08 SMAEM SMA_EM L3_Einspeisung_Scheinleistung_Zaehler: 2559.4
2021-07-10 17:43:08 SMAEM SMA_EM L3_Strom: 6.56
2021-07-10 17:43:08 SMAEM SMA_EM L3_Spannung: 229.7
2021-07-10 17:43:08 SMAEM SMA_EM L3_CosPhi: 0.936

Den habe ich auch immer noch im Verdacht. Ich habe das Modul mal auf "disabled" stehen.

Ich werde berichten...