Homegear in docker: zu viele offene dateien?


#1

Hallo zusammen,
files.txt (1,6 MB)

seit kurzem habe ich zwischendurch das Problem, dass ich mich am Raspberry mit der Fehlermeldung “too many open files” nicht mehr anmelden kann. Nach neustart (über Strom) geht’s wieder.

Bei der Suche nach dem Problem ist mir aufgefallen, dass homegear nach dem start in docker sehr viele dateien aufmacht und das evtl. zum Problem führen kann. Im Anhang ist die ausgabe von lsof | grep homegear zu finden nachdem homegear 10 minuten in docker mit folgendem Befehl läuft (ich verwende übrigens nur das MAX-Modul):

docker run -d \
      -v /homegear-data/etc:/etc/homegear:Z \
      -v /homegear-data/lib:/var/lib/homegear:Z \
      -v /homegear-data/log:/var/log/homegear:Z \
      -e TZ=Europe/Berlin \
      -e HOST_USER_ID=$(id -u) \
      -e HOST_USER_GID=$(id -g) \
      -d \
      -p 2001:2001 \
      -p 2002:2002 \
      -p 2003:2003 \
      --device=/dev/ttyACM0 \
      --name homegear \
      --restart=unless-stopped \
      homegear/rpi-homegear:stable

#2

Hallo @DOliana,

ich bin mir nicht sicher, ob die lsof-Ausgabe an dieser Stelle maßgeglich ist. Diese ist bei mir nämlich wesentlich größer (17283), als die maximale erlaubte Anzahl an geöffneten Dateien (1024). Schau mal, was ls -l /proc/<Prozess-ID>/fd sagt? Das gibt dir wirklich die offenen Dateideskriptoren zurück. Der Homegear-Hauptprozess sollte ca. 20 bis 30 offene Deskriptoren haben. Die anderen Homegear-Prozesse 4 bis 5.

Viele Grüße

Sathya


#3

Hallo @sathya,

Du hast recht - es sind sogar nur 15 offene dateien. Ich gestehe auch, dass ich kein Linux-Experte bin, aber lsof war der Befehl, den meine Recherche ergeben hat. Kannst Du mich evtl noch in die richtige Richtung bei der Suche nach dem Fehlerhaften Prozess schubsen?

Gruß,
Denis


#4

Hallo @DOliana,

sorry für die späte Antwort. Ich müsste allerdings selbst Google bemühen, um das Problem zu identifizieren. Du bist bisher der einzige, von dem ich mit diesem Problem weiß. Solltest du etwas herausfinden, immer her damit ;-). Irgendein Prozess öffnet bei dir offenbar viele Dateien. Du könntest zum Beispiel die Dateien im Ordner fd in allen allen /proc-Ordnern zählen. Das müsste Aufschluss darüber geben, welcher Prozess so viele Dateien öffnet.

Viele Grüße

Sathya


#5

Hi @sathya,

vielen Dank und keine Sorge wegen der späten Antwort - ich bin froh und dankbar, dass Du das Projekt überhaupt treibst und dich kümmerst! (Vielen Dank für die super Arbeit an der Stelle!)

Ich werde mich dann mal auf die Suche begeben - das ist so ein ganz tolles Problem, dass nur alle x Wochen auftritt und es mir in dem moment auch unmöglich macht per ssh an den Pi zu kommen. Hab jetzt erstmal den root-login aktiviert in der Hoffnung, dass ich dann noch per ssh drankomme um zu schauen, was da überhaupt los ist.

Gruß,
Denis


#6

Hallo zusammen,

ich habe exakt das gleiche Problem wie @DOliana. Ich betreibe Homegear neben weiteren Docker-Containern auf einem Raspberry Pi 2. Nach ca. 6-7 Tagen erhalte ich das identische Fehlerbild.

Der Fehler tritt erst auf, seit ich das Docker-Image für den Raspberry Pi verwende. Zuvor liefen Homegear & Co. auf einem Intel-NUC-System. Dieses System lief über Wochen und Monate stabil. Beim Migrieren habe ich nur die Konfiguration übernommen, mehr nicht (wollte logischerweise keine neuen Geräte anlernen). Ich nutze Homegear ausschließlich mit Homematic-Thermostaten sowie zwei Homematic-Tür-/Fenstersensoren (also das BidCos-Modul).

Der Fehler wird mit ziemlicher Sicherheit durch den Prozess “homegear-management” verursacht - wenn ich hier das Logfile ansehe, dann wird dort im Abstand von ca. 12s mitgeloggt “Could not connect to socket. Error: No such file or directory”. Analog dazu steigt unter /proc/pid-homegear-management/fd die Zahl der geöffneten Sockets kontinuierlich - aktuell sind es ca. 4800 (Homegear wurde heute morgen neu gestartet).

Hat jemand eine Idee wie ich herausfinden kann, was das Verhalten auslöst? Ich habe bereits den Wert des Debug-Level auf das Maximum gesetzt, erhalte allerdings keine detaillierten Fehlermeldungen außer der obigen.

@DOliana: Bist du bei der Eingrenzung des Fehlers weiter gekommen?

Viele Grüße,
Michael


#7

Nein, ich konnte leider nichts finden. Das Ganze wird auch immer komischer: An sich läuft alles stabil bis ein container (meistens der Logitech Media Server) durch watchtower aktualisiert wird, dann geht nichts mehr und ich komme auch nicht mehr auf den RPi und kann somit auch nichts analysieren…


#8

Kannst du die Aktualisierung vom LMS denn mal abstellen? Der hat sich meiner Ansicht nach in den letzten 5 Jahren nicht nennenswert verändert.


#9

Ja klar, wenn ich es abstelle läuft alles rcht stabil.Da das problem laut sathya auch nicht über lsof feststellbar ist, tippe ich aktuell auch nicht auf homegear. Auf der anderen Seite habe ich gerade nochmal geschaut und der homegear-management prozess hat laut lsof 133309 offene Dateien (was laut ulimit gra nicht möglich sein sollte?).

Hier die Ausgaben auf meinem System:

$ sudo lsof | awk '{print $2}' | sort | uniq -c | sort -n | tail
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
    305 1883
    336 1749
    540 534
    651 1116
    660 1748
    705 1022
   1920 734
  12730 1103
  65132 744
 134403 1123
$ ps ax | grep '1123\|744\|1103'
  744 ?        Ssl   42:24 /usr/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/
r/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dorg.ops4j.pax.web.listenin
addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Djava.endorsed.dirs=/usr/lib/jvm/zulu-embedded-8-arm
/jre/lib/endorsed:/usr/lib/jvm/zulu-embedded-8-armhf/lib/endorsed:/usr/share/openhab2/runtime/lib/endorsed -Djava.ext.dirs=/usr/lib/jvm/zulu-embedded-8-armhf/jre/lib/ext:/
r/lib/jvm/zulu-embedded-8-armhf/lib/ext:/usr/share/openhab2/runtime/lib/ext -Dkaraf.instances=/var/lib/openhab2/tmp/instances -Dkaraf.home=/usr/share/openhab2/runtime -Dka
f.base=/var/lib/openhab2 -Dkaraf.data=/var/lib/openhab2 -Dkaraf.etc=/var/lib/openhab2/etc -Dkaraf.logs=/var/log/openhab2 -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdi
/var/lib/openhab2/tmp -Djava.util.logging.config.file=/var/lib/openhab2/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -cla
path /usr/share/openhab2/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.1.5.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.jaas.boot-4.1.5.jar:/usr/share/o
nhab2/runtime/lib/boot/org.apache.karaf.main-4.1.5.jar:/usr/share/openhab2/runtime/lib/boot/org.osgi.core-6.0.0.jar org.apache.karaf.main.Main                             
 1103 ?        SLsl   8:22 /usr/bin/homegear -p /var/run/homegear/homegear.pid -u homegear -g homegear -d                                                                  
 1123 ?        SLsl   0:02 /usr/bin/homegear-management -p /var/run/homegear/homegear-management.pid -d                                                                    

#10

Hallo zusammen, ich konnte das Problem zwischenzeitlich “lösen”. Wobei der Begriff Lösung vielleicht nicht ganz passend ist - ich habe die Konfiguration sowie die Gerätedatenbank neu erzeugt (ergo die Geräte auch neu gepaired). Nun tritt der Fehler scheinbar nicht mehr auf - zumindest stehen keine Einträge mehr im Logfile und die Ausgabe von lsof sieht auch gut aus.

Ich vermute jedoch dass es in Homegear einen Bug gibt der verhindert, dass Sockets im Fehlerfall korrekt wieder geschlossen werden. Das würde erklären, warum die Anzahl der offenen Sockets kontinuierlich ansteigt.


#11

Ich habe gerade beim duchgehen der logs gesehen, dass beim Start von homegear folgende Fehlermeldung gelogt wird:

/etc/init.d/homegear: line 94: ulimit: real-time priority: cannot modify limit: Operation not permitted
cat: /boot/cmdline.txt: No such file or directory
Starting Homegear: homegear.
/etc/init.d/homegear-management: line 62: ulimit: real-time priority: cannot modify limit: Operation not permitted
Starting homegear-management: homegear-management.
/etc/init.d/homegear-influxdb: line 67: ulimit: real-time priority: cannot modify limit: Operation not permitted
Starting Homegear-InfluxDB: homegear-influxdb.
01/01/19 22:28:17.570 Homegear version 0.7.30-1900

#12

Hallo @DOliana,

die Logmeldungen kannst du ignorieren. Das liegt daran, dass du kein Echtzeitlinux installiert hast.

Eigentlich sollten alle Sockets im Fehlerfall geschlossen werden. Ich will aber trotzdem nicht ausschließen, dass einen Bug gibt, welcher nur in Dockercontainern zum Tragen kommt.

Viele Grüße

Sathya