Hallo zusammen,
mein FHEM auf einem PI2 bringt im Abstand von ungefähr zwei Tagen diese Fehlermeldung ins LOG:
recv() returned an error: 110
send() returned an error: 107
danach ist das System nicht mehr erreichbar und nur durch einen Neustart des PI wieder zu beleben.
Kennt jemand dieses Problem?
LG
Gibt es zu den Zeiten etwas in der System-Logfiles?
Die letzten Meldungen waren:
In der Syslog:
Feb 8 07:17:01 raspberrypi rsyslogd0: action 'action 17' resumed (module 'builtin:ompipe') [try http://www.rsyslog.com/e/0 ]
Feb 8 07:17:01 raspberrypi rsyslogd-2359: action 'action 17' resumed (module 'builtin:ompipe') [try http://www.rsyslog.com/e/2359 ]
In der Messages:
Feb 8 06:25:01 raspberrypi rsyslogd-2007: action 'action 17' suspended, next retry is Mon Feb 8 06:26:31 2016 [try http://www.rsyslog.com/e/2007 ]
Feb 8 06:25:12 raspberrypi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="490" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Der Absturz erfolgte aber ein paar Minuten später.......letzte FHEM Meldung war:
2016.02.08 07:49:18 3: SMAspot called
recv() returned an error: 110
send() returned an error: 107
Hoffe das wir dem Problem näher kommen. Ein System das unregelmäßig abstürzt ist sehr frustrierend.
LG
Kannst Du den loglevel hochdrehen?
Da bin ich leider noch Anfänger.
Geht das mit "Verbose" oder so?
Wäre nett wenn Du mir sagen könntest wie es geht ;)
LG
Siehe Wiki
http://www.fhemwiki.de/wiki/Verbose (http://www.fhemwiki.de/wiki/Verbose)
und Doku:
http://fhem.de/commandref_DE.html#verbose (http://fhem.de/commandref_DE.html#verbose)
Oder einfach mal eine Suche im Forum ...
als Kurzfassung:
attr global verbose 5
Aber Achtung: Müllt Dir sehr schnell das Logfile voll.
Habe jetzt den Loglevel auf 5 und folgende Logs vor den Fehler:
2016.02.10 17:32:54 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0641617 d:2CD5EE O:2CD5EE t:BFDBE6CF IDcnt:0003 L:1 %
2016.02.10 17:33:08 5: Triggering Ruecklauf (2 changes)
2016.02.10 17:33:08 5: Notify loop for Ruecklauf T: 37.312
recv() returned an error: 110
send() returned an error: 107
Danach hilft nur ein Reboot des Raspberry
Danach hilft nur ein Reboot des RaspberryWirklich? Was sagt denn zu dem Zeitpunkt die Konsole, ein manueller start von FHEM o.Ä.?
Hinweis:
Linux ist nicht gleich Windows. Wenn Du den RasPi neu bootest, verliehrst Du die Debugmöglichkeiten für den Fehler. Probiere erstmal, ob Du danach FHEM "per Hand" wieder starten kannst, bzw. warum nicht.
Ist eigentlich wirklich FHEM weg, oder das WEB nur nicht mehr erreichbar?
Zitatps aux | grep fhem
netstat -lntp
Loglevel hochdrehen, Stacktrace anschalten, FHEM Log posten.
Hast du irgendwelche USB Geräte für FHEM angeschlossen?
Hallo und Danke für Eure Hilfe
Loglevel und Stacktrace sind jetzt eingeschaltet und ich warte den nächsten Fehler ab.
Am USB habe ich einen Stick auf den ich die Log´s automatisch speichere und einen Bluetooth Adapter um einen Wechselrichter abzufragen.
Beim nächsten Fehler melde ich mich.....
Danke
Nach einem Tag Pause war der Fehler jetzt wieder da.
Wenn ich mit Putty abfrage kommt:
Last login: Thu Feb 11 08:17:24 2016
pi@raspberrypi ~ $ sudo /etc/init.d/fhem status
fhem is running
pi@raspberrypi ~ $ sudo /etc/init.d/fhem stop
Stopping fhem...
pi@raspberrypi ~ $ sudo /etc/init.d/fhem status
fhem is running
Fehlerbild in der Logdatei ist weiter:
2016.02.15 09:47:37 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0641617 d:2CD5EE O:2CD5EE t:14DC3CB7 IDcnt:0003 L:1 %
2016.02.15 09:47:40 5: Triggering Speicher (2 changes)
2016.02.15 09:47:40 5: Notify loop for Speicher T: 52.437
2016.02.15 09:47:42 5: Triggering Aussen (2 changes)
2016.02.15 09:47:42 5: Notify loop for Aussen T: 3.437
2016.02.15 09:47:43 5: Triggering Wohntemp (2 changes)
2016.02.15 09:47:43 5: Notify loop for Wohntemp T: 18
2016.02.15 09:47:43 4: Connection closed for WEB_192.168.178.26_38077: EOF
2016.02.15 09:47:43 4: WEB_192.168.178.26_38079 GET /fhem/?XHR=1&inform=type%3Draw%3Bfilter%3D.*&_=1455445766375; BUFLEN:0
2016.02.15 09:47:43 1: Error: has no TYPE
2016.02.15 09:47:45 5: Triggering Vorlauf (2 changes)
2016.02.15 09:47:45 5: Notify loop for Vorlauf T: 49
2016.02.15 09:47:45 5: Triggering Ruecklauf (2 changes)
2016.02.15 09:47:45 5: Notify loop for Ruecklauf T: 39.937
2016.02.15 09:48:02 5: HMLAN_Send: HMLAN1 I:K
2016.02.15 09:48:02 5: HMLAN/RAW: /HHM-LAN-IF,03C4,LEQ0641617,2CD5EE,2CD5EE,14DC9E73,0003,01
2016.02.15 09:48:02 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0641617 d:2CD5EE O:2CD5EE t:14DC9E73 IDcnt:0003 L:1 %
2016.02.15 09:48:16 4: Closing inactive connection WEB_192.168.178.26_38078
2016.02.15 09:48:16 5: ENIGMA2 Dreambox: called function ENIGMA2_GetStatus()
2016.02.15 09:48:27 5: HMLAN_Send: HMLAN1 I:K
2016.02.15 09:48:27 5: HMLAN/RAW: /HHM-LAN-IF,03C4,LEQ0641617,2CD5EE,2CD5EE,14DD0029,0003,01
2016.02.15 09:48:27 5: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0641617 d:2CD5EE O:2CD5EE t:14DD0029 IDcnt:0003 L:1 %
recv() returned an error: 110
send() returned an error: 107
FHEM ist dann nicht mehr erreichbar und arbeitet auch nicht.
Wenn ich über Putty neu starte kommt:
pi@raspberrypi ~ $ sudo /etc/init.d/fhem start
Starting fhem...
pi@raspberrypi ~ $
Und im Log das:
2016.02.15 10:48:33 5: Initializing Type Library:
2016.02.15 10:48:33 1: Including fhem.cfg
2016.02.15 10:48:33 5: Cmd: >attr global userattr cmdIcon devStateIcon devStateStyle genericDeviceType:switch,outlet,light,blind,speaker,thermostat icon sortby webCmd widgetOverride<
2016.02.15 10:48:33 5: Cmd: >attr global autoload_undefined_devices 1<
2016.02.15 10:48:33 5: Cmd: >attr global group Xtras<
2016.02.15 10:48:33 5: Cmd: >attr global latitude 51.3246<
2016.02.15 10:48:33 5: Cmd: >attr global logfile /media/usbstick/log/fhem-%Y-%m.log<
2016.02.15 10:48:33 5: Cmd: >attr global longitude 7.6968<
2016.02.15 10:48:33 5: Cmd: >attr global modpath .<
2016.02.15 10:48:33 5: Cmd: >attr global motd Messages collected while initializing FHEM:
configfile: Solar: unknown attribute delay. Type 'attr Solar ?' for a detailed list.
<
2016.02.15 10:48:33 5: Cmd: >attr global stacktrace 1<
2016.02.15 10:48:33 5: Cmd: >attr global statefile ./log/fhem.save<
2016.02.15 10:48:33 5: Cmd: >attr global updateInBackground 1<
2016.02.15 10:48:33 5: Cmd: >attr global verbose 5<
2016.02.15 10:48:33 5: Cmd: >define TABLETUI HTTPSRV ftui/ ./www/tablet Tablet-UI<
2016.02.15 10:48:33 5: Loading ./FHEM/02_HTTPSRV.pm
2016.02.15 10:48:33 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet:
2016.02.15 10:48:33 3: Registering HTTPSRV TABLETUI for URL /ftui and assigned link ftui/ ...
2016.02.15 10:48:33 5: Cmd: >attr TABLETUI group Xtras<
2016.02.15 10:48:33 5: Cmd: >define telnetPort telnet 7072 global<
2016.02.15 10:48:33 5: Loading ./FHEM/98_telnet.pm
2016.02.15 10:48:34 1: telnetPort: Can't open server port at 7072: Address already in use. Exiting.
Also ..... bitte gib uns mal mehr Daten:
ps aux | grep [f]hem
netstat -nltp | grep perl
Anschließend könntest Du probieren, ob Du es per Hand gestopt, gestartet bekommst:
ps aux | grep [f]hem
kill PidDesfhemProzesses_s.o.
ps aux | grep [f]hem
/etc/init,d/fhem start
Wenn der kill so nicht funktionieren sollte, nochmals probieren, wenn nach 3-4 Mal er immer noch nicht weg ist, mal ein "kill -9" probieren.
Was ist hier Text und was Logausgabe?
Tags würden das ganze etwas augenfreundlicher machen.
Ok, ich versuche Alles um weiter zu kommen. Hier mehr Daten
pi@raspberrypi ~ $ ps aux | grep [f]hem
fhem 783 1.9 8.0 40068 35892 ? S Feb11 117:16 perl fhem.pl fhem.cfg
fhem 7181 0.0 0.7 4620 3412 ? S 09:48 0:00 /opt/fhem/sbfspot/bin/Release/SBFspot -nocsv -v
pi@raspberrypi ~ $ sudo netstat -nltp | grep perl
tcp 0 0 0.0.0.0:7072 0.0.0.0:* LISTEN 783/perl
tcp 0 0 0.0.0.0:8083 0.0.0.0:* LISTEN 783/perl
tcp 0 0 0.0.0.0:8084 0.0.0.0:* LISTEN 783/perl
tcp 0 0 0.0.0.0:8085 0.0.0.0:* LISTEN 783/perl
Bei starten per Hand kommt :
pi@raspberrypi ~ $ ps aux | grep [f]hem
fhem 783 1.9 8.0 40068 35892 ? S Feb11 117:16 perl fhem.pl fhem.cfg
fhem 7181 0.0 0.7 4620 3412 ? S 09:48 0:00 /opt/fhem/sbfspot/bin/Release/SBFspot -nocsv -v
pi@raspberrypi ~ $ kill PidDesfhemProzesses_s.o.
-bash: kill: PidDesfhemProzesses_s.o.: arguments must be process or job IDs
pi@raspberrypi ~ $ ps aux | grep [f]hem
fhem 783 1.9 8.0 40068 35892 ? S Feb11 117:16 perl fhem.pl fhem.cfg
fhem 7181 0.0 0.7 4620 3412 ? S 09:48 0:00 /opt/fhem/sbfspot/bin/Release/SBFspot -nocsv -v
pi@raspberrypi ~ $ /etc/init,d/fhem start
-bash: /etc/init,d/fhem: No such file or directory
pi@raspberrypi ~ $
Da war ich etwas zu schnell. Habe die Befehle nicht richtig verstanden. Sorry !!
Nach dem Kill der Prozesse 783 und 7181 kommte ich FHEM neu starten.
Habe bislang immer mit Abstürzen, incl. nicht der Nicherreichbarkeit von Fhem nach reboot (RPi2) zu kämpfen gehabt. Netzteiltausch und Log Beobachtung haben nichts gebracht.
Allerdings machte mich stutzig, dass die Abstürze irgendwie mit der (Nicht-) Erreichbarkeit von mysql- und owfs server zusammenhingen. Folgendes hat zu einer bisher zufriedenstellenden Lösung geführt:
- Habe die Logs (mit mysql) auf einen zweiten RPi mit fhem2fhem ausgelagert.
- Habe owserver/OWFS durch OWX ersetzt.
Somit greift Fhem jetzt nicht mehr auf externe Hilfsserver zu.
Vielleicht hilft das jemandem bei der pragmatischen Fehlerbeseitigung...
LG
Jorge
Wenn ich selber versuche das Problem zu analysieren kommt mir folgendes Seltsam vor:
Der Prozess : fhem 7181 0.0 0.7 4620 3412 ? S 09:48 0:00 /opt/fhem/sbfspot/bin/Release/SBFspot -nocsv -v
startet um 9:48...das ist die vermutlich auch die Zeit des Fehlers.
Der Prozess gehört zur Abfrage des Wechselrichters mit dem Modul 99_SMAUtils.pm.
Wenn meine Analyse stimt, wie komme ich dann weiter mit der Fehlereingrenzung?
Oder denke ich ganz falsch.
Natürlich nochmal ein Dankeschön für eure weitere Hilfe
1. Zur besseren Lesbarkeit, verwende anstatt Farben den "Code" tag, den Du hinter dem # im Web-Editor findest
2. Startest Du den SBFspot im init-File?
bzw. wo startest Du denn den genau?
3. Wenn Du "nur" fhem abschießt, kannst Du dieses dann starten?
Ich hoffe jetzt als Anfänger nicht allzu dumme Antworten zu geben.
Den SBFSpot habe ich nach dieser Anleitung installiert : http://www.fhemwiki.de/wiki/SMAWechselrichter
Also steht im fhem.cfg "define Solar SMAUtils 00:80:25:0B:19:5A 600"
Wo genau der SBFspot gestartet wird kann ich leider nicht genau sagen ( Anfänger). Wo muß ich suchen ?
Zu Punkt 3..... kann ich erst feststellen wenn der Fehler wieder da ist.
Danke für den Tipp mit dem Code einfügen !!
Du hast also die /etc/init.d/fhem nicht geändert?
Mir ist momentan auch ein Rätsel, wo der Deamon gestartet wird. ich glaube, da mus ein SMAWechselrichter-Spezialist ran ....
P.S. Wenn Du fhem normal beendest, beendet sich dann auch dieser Prozess? Also einfach mal mit "shutdown" testen ...
Nachdem FHEM neu gestartet ist und ich die Prozesse mit "ps aux | grep [f]hem" abgefragt habe,
ist nur der Prozess von fehm aktiv.
Wenn ich die Abfrage mehrmals wiederhole sehe ich, dass der Prozess vom SBFSpot in regelmäßigen Abständen startet und stoppt.
Wenn ich FHEM mit shutdown beende, sind keine Prozesse mehr aktiv.
Dann wird der Prozess vom Modul gestartet.
Wenn Dir mal wieder fhem einfriehrt, gucke mal mit top, htop o.Ä. nach, was auf Deinem system so los ist. Ich habe die Vermutung, das dieser Prozess sich aufhängt ...