Ich habe vor ein paar Tagen ein Update von FHEM gemacht und seit dem täglich einen Absturz:
2017.02.22 10:42:28 1: BlockingInformParent (BlockingStart): Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
2017.02.22 10:42:28 1: BlockingInformParent (PRESENCE_ProcessLocalScan): Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
Danach startet monit bei mir den FHEM-Server neu und alles läuft wieder.
Hat jemand vielleicht einen Hinweis für mich wo das herkommen kann?
7072 ist der Telnetport, der ist also scheinbar bei Dir nicht erreichbar.
ABER .. warum, das müstest Du näher debuggen. Woher kommt Deine Meldung?
Startest Du nur fhem oder auch den Server neu?
Klar mit dem Port, warum das passiert weiß ich nur nicht.
Gestern gingen die Lichter nicht an, kurzer Blick ins Terminal und festgestellt...FHEM is not running.
Also doch mal lieber wieder monit eingebunden, damit FHEM automatisch neu gestartet wird.
FHEM raucht also komplett ab. Neu gestartet wird da nur FHEM per /etc/init.fhem start.
Und heute wieder, gleiches Problem, gleiche Meldung im Log.
Wüsste nicht, wie ich da weiter kommen kann. Einzig ein fhem update gemacht.
Was steht denn im FHEM-LOg?
Wenn fhem "weg" ist, sind eventuell noch fhem-Prozesse da?
Und .. was sagen die Systemlogs?
Bitte um Input für mehr Output!
Im FHEM Log steht nicht weiter bevor der Absturz kommt.
Heute war das um 10:45, um 10:03 ging die Terrassentür auf. Das war der letzte Eintrag.
Auch im Syslog steht überhaupt nichts im Umkreis einer halben Stunde vor dem Absturz.
Für mich erst einmal leider kein weiterer Hinweis, wo ich ansetzen könnte.
Dann hilft nur, verbose erhöhen
Hatte schon mal gefragt:
Du startest nur fhem und nicht den PI durch?
"Neu gestartet wird da nur FHEM per /etc/init.fhem start."
Der NUC wird nicht neu gestartet, nur FHEM.
Ja, muss ich wohl mal erhöhen. Was empfiehlt sich da? 5?
So, da bin ich wieder. Wie jeden Tag nun der Absturz.
Nun lief aber FHEM komplett mit verbose 5 und siehe da:
2017.02.23 14:58:22 5: PRESENCE (Handy) - ping command returned with output:
PING 192.168.178.22 (192.168.148.22) 56(84) bytes of data.
From 192.168.178.24 icmp_seq=1 Destination Host Unreachable
From 192.168.178.24 icmp_seq=2 Destination Host Unreachable
From 192.168.178.24 icmp_seq=3 Destination Host Unreachable
From 192.168.178.24 icmp_seq=4 Destination Host Unreachable
--- 192.168.178.22 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 2999ms
pipe 4
Out of memory!
Hat jemand einen Hinweis dazu?
An der Konfiguration hat sich nichts getan und auch die Maschine (Intel NUC) schwächelt eigentlich nicht.
df -h
Dateisystem Größe Benutzt Verf. Verw% Eingehängt auf
/dev/sda1 36G 5,6G 28G 17% /
udev 10M 0 10M 0% /dev
tmpfs 772M 82M 690M 11% /run
tmpfs 1,9G 0 1,9G 0% /dev/shm
tmpfs 5,0M 4,0K 5,0M 1% /run/lock
tmpfs 1,9G 0 1,9G 0% /sys/fs/cgroup
tmpfs 150M 172K 150M 1% /var/cache/apt/archives
tmpfs 20M 0 20M 0% /var/tmp
tmpfs 70M 27M 44M 38% /var/log
tmpfs 100M 16K 100M 1% /tmp
/dev/sdb1 29G 7,8G 20G 29% /media/backups
tmpfs 386M 0 386M 0% /run/user/1000
Out of memory!
Steht im Kern log bezüglich oom-Killer?
Steht im fhem.log unter /opt/fhem/log
Schau mal ins Syslog unter /var/log/messages. Da müsste sich zur fraglichen Zeit etwas zum oom-Killer finden.
Gruß,
Stephan
Alternativ /var/log/syslog ... oder /var/log/kern.log
Beim kern.log kann es auch, wenn Du reboot machst, das kern.log.1 sein (oder kern.log.1.gz)
Hm, in /var/log/messages ist die letzte Nachricht um 14:42, also weit vorher und auch nicht spannendes:
Feb 23 14:42:14 HomeServer rsyslogd-2007: action 'action 13' suspended, next retry is Thu Feb 23 14:42:44 2017 [try http://www.rsyslog.com/e/2007 ]
In /var/log/syslog steht in dem Zeitfenster und auch davor gar nichts.
Und kern.log hat Einträge vom 03.12.16!? Da sind auch keine archivierten kern.logs :-(
?? Was hast Du für aktuelle Logs unter /var/log?
Und .... wie voll ist Dein Speicher? (df -h)
"df -h" -> siehe oben, alles gut
/var/log
-rw-r--r-- 1 root root 38701 Dez 3 2015 alternatives.log
drwxr-x--- 2 root adm 260 Feb 24 00:17 apache2
drwxr-xr-x 2 root root 80 Dez 3 2015 apt
-rw-r----- 1 root adm 23664 Feb 24 18:57 auth.log
-rw------- 1 root utmp 0 Feb 20 18:06 btmp
-rw-r----- 1 root adm 3098013 Feb 24 18:57 cronauth.log
drwxr-xr-x 2 root root 100 Dez 3 2015 cups
-rw-r----- 1 root adm 176658 Dez 3 2015 daemon.log
-rw-r--r-- 1 root root 856 Feb 20 18:08 dasher.err
-rw-r--r-- 1 root root 281512 Feb 23 21:45 dasher.log
-rw-r----- 1 root adm 160956 Dez 3 2015 debug
-rw-r----- 1 root adm 31 Dez 3 2015 dmesg
-rw-r--r-- 1 root root 899354 Feb 20 18:19 dpkg.log
drwxr-s--- 2 Debian-exim adm 80 Feb 20 18:17 exim4
-rw------- 1 root root 1533 Feb 20 18:08 fail2ban.log
-rw-r--r-- 1 root root 32032 Feb 20 18:19 faillog
-rw-r--r-- 1 root root 0 Feb 20 18:08 fhem.js.error
-rw-r--r-- 1 root root 3426130 Feb 23 15:03 fhem.js.log
drwxr-xr-x 2 root root 40 Dez 12 2014 firebird
-rw-r--r-- 1 root root 2587 Dez 3 2015 fontconfig.log
drwxr-xr-x 2 root root 80 Dez 3 2015 fsck
drwxr-xr-x 3 root root 60 Dez 3 2015 hp
drwxr-xr-x 3 root root 160 Dez 3 2015 installer
-rw-r----- 1 root adm 675064 Dez 3 2015 kern.log
-rw-rw-r-- 1 root utmp 292292 Feb 24 18:57 lastlog
drwx--x--x 2 root root 160 Dez 3 2015 lightdm
-rw-r----- 1 root adm 282 Feb 20 18:08 mail.err
-rw-r----- 1 root adm 3185 Feb 24 07:35 mail.info
-rw-r----- 1 root adm 282 Feb 20 18:08 mail.warn
-rw-r--r-- 1 root root 71593 Feb 23 14:42 messages
-rw-r--r-- 1 root root 181442 Feb 24 18:33 minidlna.log
-rw-r----- 1 root root 2581 Feb 23 21:49 monit.log
drwxr-xr-x 2 mosquitto root 60 Feb 20 18:19 mosquitto
drwx------ 2 speech-dispatcher root 40 Dez 5 2014 speech-dispatcher
-rw-r----- 1 root adm 1133038 Feb 24 18:57 syslog
-rw-r----- 1 root adm 3156087 Feb 23 13:17 syslog.1
-rw-r----- 1 root adm 2522 Dez 3 2015 user.log
-rw-rw-r-- 1 root utmp 9600 Feb 24 18:57 wtmp
-rw-r--r-- 1 root root 32517 Dez 3 2015 Xorg.0.log
-rw-r--r-- 1 root root 42357 Dez 3 2015 Xorg.0.log.old
Zitat von: HansDampfHH am 23 Februar 2017, 21:19:57
Hm, in /var/log/messages ist die letzte Nachricht um 14:42, also weit vorher und auch nicht spannendes:
Feb 23 14:42:14 HomeServer rsyslogd-2007: action 'action 13' suspended, next retry is Thu Feb 23 14:42:44 2017 [try http://www.rsyslog.com/e/2007 ]
In /var/log/syslog steht in dem Zeitfenster und auch davor gar nichts.
Und kern.log hat Einträge vom 03.12.16!? Da sind auch keine archivierten kern.logs :-(
Dann solltest du dir mal die Logging Optionen des rsyslogd ansehen. Ggf. sind die so eingestellt, dass gar kein Log erzeugt wird, oder dass es nur auf die Konsole geloggt wird - immerhin handelt es sich ja um ein System welches naturgemäß so wenig wie möglich auf die SD Karte schreiben soll und da haben die Autoren ggf. daran gedreht.
Gruß,
Stephan
So, da bin ich mal wieder. Neustart bzw. Absturz von FHEM kommt nicht mehr so oft vor, von daher erst heute ein Feedback.
Ich habe das kern.log aktiviert und in letzter Zeit "nur" zwei Abstürze gehabt. Exakt zur gleichen Zeit kommt folgender Eintrag im kern.log:
Mar 5 07:37:52 HomeServer kernel: [1085441.844492] perl[17906]: segfault at 40000a56d0fc ip 00007f7b938bd807 sp 00007ffd299e0dc0
Mar 10 13:43:01 HomeServer kernel: [1539346.132409] perl[24417]: segfault at 3f853211c740 ip 00003f853211c740 sp 00007ffe7259b3c8
Hat jemand dazu erhellende Hinweise?
Wenn der oem-Killer zuschlägt, kann so etwas vorkommen.
Steht etwas im Syslog?
Was mir noch einfällt:
Du hattest "gepingt" .. wieviele Ping-Prozesse läst Du zu?
(P.S. welche Pi Version mit wieviel RAM)
Ping wird default ausgeführt, also wohl ping_count 4.
Ist ein Intel NUC mit Debian und einem 4GB Riegel.
Im syslog steht nichts weiter zur fraglichen Uhrzeit.
Was mich dann wundert .. wieso hast Du "Out Of Memory" ... was hast DU alles "auf der Kiste" laufen?
Kannst DU mal bitte per htop gucken, wie die Mem belastung ist (besser währe top, aber schwieriger zu lesen)
Das ist es ja, gibt keinen Grund dafür. Die Auslastung liegt durchgehend bei 1-3%CPU.
Da ich kein Linux-Profi bin kann ich mit der Mem Angabe nicht viel anfangen.
Soweit mir bekannt nutzt Linux doch eh immer den gesamten Ram bzw. gibt den nicht gleich frei.
Welche Angabe kann ich Dir geben?
Unter Mem steht 1018/385 bzw. für die perl-Prozesse (fhem) jeweils 3,5%.
Also, ich habe auch schon mal sporadisch den ganzen Speicher voll gehabt. Auf meinem pi liefen bis vor kurzen aber auch noch ein paar andere Services wie Nextcloud und MariaDB mit. Die habe ich inzwischen mal woanders hin migriert... Wenn der Speicher sehr schnell, sehr plötzlich dermaßen voll geht, dass nix mehr funktioniert oder der OOM-Killer zuschlägt, dann wird es sehr schwer werden das herauszufinden.
Dazu müsste man das System sehr genau beobachten, wofür man normalerweise die Zeit gar nicht hat.
Wichtig ist schon mal, dass das Sytem im Normalzustand nicht swappen sollte. Das war bei meinem pi vorher der Fall, auch wenn es sich nicht so um 128MB gehandelt hatte.
Jetzt läuft auf meinem pi nur noch FHEM, Hombrige und Alexa-FHEM, sowie ein Apache als Reverse-Proxy... seit dem swappt der pi nicht mehr.
Ich würde mal wetten, dass auf dem NUC - der ist ja deutlich größer, als ein pi, noch mehr als nur FHEM läuft... oder?
Gruß,
Stephan
htop zeigt Dir auch die Speicherauslastung.
Ansonsten bei htop nach Speicher sortieren lassen und gucken, wer (im Normalfall) was braucht.
btw: Hast Du eine DB am laufen?
Das sieht alles nicht ungewöhnlich aus. Wie gesagt, mem bei den FHEM Prozessen 3,5%...da kommt nicht viel zusammen.
Eine DB läuft nicht und auch sonst nichts weiter. Nun ist es wieder stabil, tritt eben sehr sporadisch auf.
Monit läuft nun und startet bei Bedarf FHEM umgehend neu. Nicht schön, aber so ist das zumindest keine spürbare Einschränkung.
Darüber bekomme ich eine Email und schau dann immer mal wieder ins Log. Nun passiert das aber auch nicht mehr täglich.
Okay, ein weiteres Feedback.
Ich habe nun noch weitere Geräte eingehängt, die ich anpinge und das PRESENCE Modul nutze.
Das sind ein paar Handys, TV, HTPC, PS4 und somit nun insgesamt 10 Devices.
Seit dem ich die letzten 3 Geräte eingehängt habe friert das System ständig ein.
Wenn Devices nicht anwesend sind wird j ständig gepingt. Das flutet wohl das System:
TCP: Possible SYN flooding on port 7072. Sending cookies. Check SNMP counters.
Kann mir jemand vielleicht verraten an welcher Schraube ich drehen könnte / müsste?
Da ich schon relativ zeitnah wissen möchte welche Devices HOME sind möchte ich keinen großen Intervall beim pingen einstellen.
Lediglich ping_count habe ich auf 2 gestellt, das hat aber nichts gebracht.
Du kannst versuchen die maximal erlaubte Anzahl ausstehender syn requests zu erhöhen. Such mal nach: net.ipv4.tcp_max_syn_backlog
Also ein "echo 1024 > /proc/sys/net/ipv4/tcp_max_syn_backlog" hat bisher wunder gewirkt.
Konnte alle Devices wieder anpingen und FHEM ist nun seit fast 3 Tagen stabil. Bisher also vielleicht der richtige Hinweis :-)
Ich hänge mich mal hier dran.
Hab seit ein paar Tagen auch ständig Abstürze und habe gerade mal ein bisschen geforscht.
Nachdem ich den Loglevel hochgenommen habe, habe ich festgestellt, dass fhem mit Out of memory! abstürzt.
Das System ist ein NUC mit 8GB, darauf läuft fhem, Alexa, Homebridge, UnifiController mit MongoDB, Apache2, Monit und eine Backupsoftware.
Top und htop zeigen eine normale Auslastung: 1GB von 9GB genutzt.
UnifiController braucht ca 5.3% RAM, Apache 2.1% und fhem 2.0%, also alles im Rahmen.
Ich habe auch schon das PRESENCE Module in Verdacht, da ich da drei Devices dazu genommen habe.
Könnte die tcp_max_syn_backlog Geschichte bei mir helfen?
Kannst Du den Memverbrauch mitloggen?
@Mitch: Nein, tcp_max_syn_backlog hat nichts mit oom zu tun.
Wie kann ich denn den Speicher loggen?
Ich kenne nur top und htop.
Ich habe aber Monit laufen und das zeigt mir alle 2 Minuten CPU und Memory der überwachten Prozesse.
Mir ist aufgefallen, dass Fhem immer mal wieder auf 60 bis 80% CPU Last geht. Leider finde ich dazu nichts passendes im Log, es wird auch nichts geschalten.
Anbei mal eine Momentaufnahme von Monit.
Es gibt dafür ein FHEM Modul .. alternativ per script das "free" Kommando auswerten
Ich hatte den oem Fehler auch nur einmal Anfangs. Danach waren es nur noch die Fehler "Possible SYN flooding on port 7072".
Die Änderung mit tcp_max_syn_backlog hat schlußendlich auch nicht geholfen.
Ich habe bei mir erst mal alle Devices disabled. Dann festgestellt, dass es doppelte IPs gab.
Durch unseren neuen Anbieter und der neuen Fritte haben die alle neue IPs bekommen. Da habe ich wohl nicht alle korrekt geändert.
Nachdem ich die korrigiert habe, habe ich die Devices einzeln wieder enabled.
Das hat bis auf die Handys funktioniert. Wenn ich eines der drei Handys wieder enabled habe ist die GUI sofort eingefroren und ich konnte fhem nur killen.
Ich habe dann gestern Abend die 3 Devices komplett gelöscht und neu angelegt. Und siehe da..ließen sich sofort enablen und bisher läuft das ganze auch.
Im Zuge der Problematik habe ich aber auch mal das ganze System aufgefrischt (neuer Kernel und upgrade).
Mal sehen wir lange das gut geht ;-)
Vielleicht hatten die Devices aber auch einen "Ditsch" und mussten neu angelegt werden?