[Gelöst] - fhem.pl verabschiedet sich "einfach so"

[maxritti]

Hallo zusammen,

derzeit entwickele ich an einem Modul, welches Daten via Modbus aus meinem Solarlog meiner PV Anlage auslesen soll.
Als Ansatz habe ich dieses Post hier gefunden:

http://forum.fhem.de/index.php/topic,13128.msg86975.html#msg86975

Das mit den Dummies war mit dann nicht ganz so sympatisch, so dass ich das in ein Modul packen wollte.
Im Internet habe ich dann parallel noch ein Modbus Modul gefunden, welches ich verwende.
Damit habe ich dann die eigentliche Kommunikation aus meinem Perl Modul separiert.

Die beidem Dateien habe ich hier mal angehangen.
Es klappt soweit auch alles wunderbar.
Ich kann mir ein Device anlegen, dann in einem Attribut "register" meine Register definieren, welche ausgelesen werden sollen und die Werte kommen wunderbar zurück.

Nun kommt das Aber.

Irgendwann und das war bisher schon 3-4 mal, ist FHEM morgens einfach so beendet.
Merkwürdigerweise immer so kurz nach 3 Uhr.
Wenn ich dann fhem neu starte sieht man das schön an den Plots, dass es um 3 Uhr weg war also kein Logeintrag mehr erfolgt ist und heute morgen ging es dann wieder weiter.
Im fhem log selber ist gar nichts mehr zu sehen. Das letzte mal gesterm so gegen 21 Uhr, wo ich mal ein "update check" ausgeführt habe. Sonst gar nichts.

Und wie gesagt, der perl Prozess auf meinem Linux ist einfach weg. "/etc/init.d/fhem status" sagt "fhem not running"

Irgendwie fällt es mir da im moment schwer den Fehler zu finden bzw das Problem zu lokalisieren.

Es wäre cool, wenn hier jemand einen Ansatz für mich hätte.
Das einzige was mir einfällt wäre verbose auf 5 zu stellen und zu schauen, was dann passiert.

[rudolfkoenig]

Es sollte entweder auf der Console, wo man fhem startet, oder im fhem-log stehen, warum fhem.pl weg ist.

[Elektrolurch]

Hallo,

ist fhem wirklich beendet?
was sagt denn:
ps | grep fhem

Ich suche nämlich derzeit auch noch nach einem Fehler, aber bei mir läuft fhem noch, aber wohl in einer Endlosschleife.
siehe auch:
http://forum.fhem.de/index.php/topic,24676.msg177692.html#msg177692

Gruß

Elektrolurch

[maxritti]

Es sollte entweder auf der Console, wo man fhem startet, oder im fhem-log stehen, warum fhem.pl weg ist.

Danke Dir schon mal für die Info.
Hätte ich ja eigentlich auch drauf kommen können, das log mal anzuhängen.
FHEM läuft in meiner Entwicklungsumgebung auf einem Debian Linux, welches in einer VM Ware auf einem MacMini läuft.

Hier mal das fhem-log aus dem betreffenden Zeitraum:

Code Auswählen Erweitern

2014.07.02 12:58:21 3: ----------------------------------------
2014.07.02 12:58:21 3: ConnectSolarlog mySL
2014.07.02 12:58:21 3:   register: 3502 - attr: Pac
2014.07.02 12:58:21 3:     -> 2050
2014.07.02 12:58:21 3:   register: 3504 - attr: Pdc
2014.07.02 12:58:21 3:     -> 2167
2014.07.02 21:06:21 3: update get http://fhem.de/fhemupdate4/svn/controls_fhem.txt
2014.07.03 07:12:31 1: Including fhem.cfg
2014.07.03 07:12:31 3: telnetPort: port 7072 opened
2014.07.03 07:12:31 3: WEB: port 8083 opened
2014.07.03 07:12:31 3: WEBphone: port 8084 opened
2014.07.03 07:12:31 3: WEBtablet: port 8085 opened


Und hier das Log von meinem Device aus dem Zeitraum, wo man die Events sieht:

Code Auswählen Erweitern

2014-07-03_03:00:28 mySL Pac_new: 0
2014-07-03_03:00:28 mySL Pdc_new: 0
2014-07-03_03:00:38 mySL Pac_new: 0
2014-07-03_03:00:38 mySL Pdc_new: 0
2014-07-03_03:00:48 mySL Pac_new: 0
2014-07-03_03:00:48 mySL Pdc_new: 0
2014-07-03_03:00:58 mySL Pac_new: 0
2014-07-03_03:00:58 mySL Pdc_new: 0
2014-07-03_03:01:08 mySL Pac_new: 0
2014-07-03_03:01:08 mySL Pdc_new: 0
2014-07-03_03:01:18 mySL Pac_new: 0
2014-07-03_03:01:18 mySL Pdc_new: 0
2014-07-03_03:01:28 mySL Pac_new: 0
2014-07-03_03:01:28 mySL Pdc_new: 0
2014-07-03_03:01:38 mySL Pac_new: 0
2014-07-03_03:01:38 mySL Pdc_new: 0
2014-07-03_03:01:48 mySL Pac_new: 0
2014-07-03_03:01:48 mySL Pdc_new: 0
2014-07-03_03:01:58 mySL Pac_new: 0
2014-07-03_03:01:58 mySL Pdc_new: 0
2014-07-03_07:12:41 mySL Pac: 92
2014-07-03_07:12:41 mySL Pdc: 104
2014-07-03_07:12:41 mySL Pac_new: 30.6666666666667
2014-07-03_07:12:41 mySL Pdc_new: 156
2014-07-03_07:12:51 mySL Pdc: 103
2014-07-03_07:12:51 mySL Pac_new: 30.6666666666667
2014-07-03_07:12:51 mySL Pdc_new: 154.5


Irgendetwas ist da also um 03:01:58 passiert, so dass es dann mit FHEM nicht mehr weiter geht.
Im /var/log/syslog des Debian Server sehe ich dies:
Das kommt aber auch an anderen Zeitpunkten, soltle somit doch nicht Auslöser des Problems sein.

Code Auswählen Erweitern

Jul  3 02:38:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 02:39:01 tdfsr178194 /USR/SBIN/CRON[14827]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find /var/lib/php5/ -type f -cmin +$(/usr/lib/php5/maxlifetime) -delete)
Jul  3 02:48:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 02:58:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:08:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:09:01 tdfsr178194 /USR/SBIN/CRON[14877]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find /var/lib/php5/ -type f -cmin +$(/usr/lib/php5/maxlifetime) -delete)
Jul  3 03:17:01 tdfsr178194 /USR/SBIN/CRON[14885]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jul  3 03:18:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:28:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status



In /var/log/messes steht auch das mit dem RAID Status

Code Auswählen Erweitern

Jul  3 02:48:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 02:58:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:08:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:18:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:28:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status
Jul  3 03:38:24 tdfsr178194 mpt-statusd: detected non-optimal RAID status

Mir fällt es jetzt ein wenig schwer etwas in der Konsole zu sehen, wo fhem gestartet wird.
Gestartet wird es ja über das /etc/init.d/fhem Skript und wird ja quasi im Hintergrund ausgeführt.

Ein "ps -aux" liefert dies hier:

Code Auswählen Erweitern

fhem     15626  0.0  2.2  17048 11532 pts/1    S    07:38   0:04 perl fhem.pl fhem.cfg

Wäre da dann das pts/1 die Konsole, wo ich mal was nachschauen sollte?
So mittels switch command?

Kannst Du mir da vielleicht ein wenig beschreiben, wo ich da noch Infos abgreifen könnte?

Hallo,

ist fhem wirklich beendet?
was sagt denn:
ps | grep fhem

Ich suche nämlich derzeit auch noch nach einem Fehler, aber bei mir läuft fhem noch, aber wohl in einer Endlosschleife.
siehe auch:
http://forum.fhem.de/index.php/topic,24676.msg177692.html#msg177692

Gruß

Elektrolurch

Ich meine, dass da wirklich nichts mehr gewesen ist.
Vom Prinzip macht ein "fhem status" doch solch ein grep.
Und da kommt "fhem is not runnig" zurück.

Code Auswählen Erweitern

'status')
        cnt=`ps -ef | grep "fhem.pl" | grep -v grep | wc -l`
        if [ "$cnt" -eq "0" ] ; then
                echo "fhem is not running"
        else
                echo "fhem is running"
        fi


Aber ich kann das beim nächsten mal (eventuell schon morgen) mal schauen.
Und Dein Post werde ich mir mal durchlesen.

[rudolfkoenig]

Gestartet wird es ja über das /etc/init.d/fhem Skript und wird ja quasi im Hintergrund ausgeführt.

Ja, und deswegen sind diese Meldungen auch weg.
Ich wuerde zum debuggen FHEM direkt starten, z.Bsp. in einem screen session, und vorher noch "attr global logfile -" setzen, damit FHEM nicht im Hintergrund laeuft, und die Konsolenmeldungen direkt mit den FHEM-Logfile Meldungen korrelieren.

[justme1968]

bei solchen problemen ist es auch hilfreich wenn man das start script so ändere das stdout und stderr in ein file umgeleitet werden. sie z.b. hier: http://forum.fhem.de/index.php/topic,17506.msg115469.html#msg115469

man kann auch über ein at timestamps nach stdout, stderr und ins fhem log schreiben lassen um zu sehen bis wann alles funktioniert hat.

gruss
  andre

[maxritti]

bei solchen problemen ist es auch hilfreich wenn man das start script so ändere das stdout und stderr in ein file umgeleitet werden. sie z.b. hier: http://forum.fhem.de/index.php/topic,17506.msg115469.html#msg115469

man kann auch über ein at timestamps nach stdout, stderr und ins fhem log schreiben lassen um zu sehen bis wann alles funktioniert hat.

gruss
  andre

Das mit den zusätzlichen at's ist nicht notwendig.
Denn mein Modul habe ich mal so gepimpt, dass es alle 10 Sekunden meinen Datenlogger abfragt.
Wenn da keine Werte mehr im Log auftauchen ist fhem weg.

Ich lasse FHEM jetzt mal so laufen, wie Rudolf das beschrieben hat.
Bin mal gespannt, was die Nacht bringt.

[maxritti]

So, es ist wieder passiert.
Heute morgen steht meine Konsole so wie im Bild zu sehen da.

Die letzte Zeile "unable to connect to 192.168.178.22" kommt auch eindeutig aus meinem Solarlogmodul.
Warum auch immer ist mein Datenlogger augenscheinlich zu dem Zeitpunkt mal nicht erreichbar.

Das wird auch in meinem Modul abgefragt.
Augenscheinlich ist das die dort ein wenig zu heftig.
Kann es sein, dass dieser Befehl fhem.pl beendet?

Da baue ich wohl dann mal besser ein grosses if drum.

Code Auswählen Erweitern

##############################
sub Solarlog_ConnectSolarlog($)
{

  my ($hash) = @_;
  my $name = $hash->{NAME};
  my $host = $hash->{HOST};
  my @reg = split(',', AttrVal($name, "register", ""));

#  Log (3, "----------------------------------------");
#  Log (3, "ConnectSolarlog $name");

  my $sl = MBclient->new();
  #$sl->{debug} = 1;
  $sl->host($host);
  $sl->unit_id(1);
  die "unable to connect to $host\n" if (!$sl->open());

[rudolfkoenig]

MWn bedeutet "die" Sterben 
Siehe auf "perldoc -f die"

[maxritti]

Jo, schon klar.

War heute morgen der Meinung, dass das die dann "nur" für das Modul gilt.
Ist aber ja quatsch, da das ja von der fhem.pl gesteuert wird.

Ich setze das dann hier mal auf solved.
Danke schön an alle Beteiligten.