Queues werden nicht abgearbeitet

Deutsche Foren Fehler
#1

Hallo,

ich habe folgendes Problem:
Nach einem Neustart von meinem Pi (Version 2), auf dem Openhab und Homegear jeweils in einem Docker-Container laufen, werden Befehle an meine Homematic-Komponenten häufig nicht mehr gesendet.
Die REST-Api von Homegear gibt mir allerdings die neuen Werte zurück.
Auffällig ist, dass jeweiligen Queues der Komponenten dann nicht leer sind. Leere ich diese aktiv, funktioniert die Kommunikation danach wieder einwandfrei.

Beispiel:

  • Ein Heizthermostat steht auf Soll-Temperatur 17 Grad
  • Ich starte meinem Pi neu
  • Ich setze über Openhab die Soll-Temperatur auf 21 Grad
  • Die Temperatur am Thermostat bleibt unverändert
  • Im openhab.log kriege ich folgende Meldung:
    2018-02-04 10:04:37.303 [ERROR] [ematic.handler.HomematicThingHandler] - -100 No answer from device. (sending setValue()
    MEQ1589433:4
    SET_TEMPERATURE
    20.0
    )
  • In der Homegear-Queues des Gerätes sind mehr als 10 Einträge
  • Die Homegear-Rest-Api liefert als Soll-Temperatur 21
  • Ich resette die Queue in Homegear und wiederhole das Setzen der Temperatur über Openhab
  • Nun klappt alles. Die Temperatur wird am Thermostat richtig eingerichtet

Sys-Info:

  • Homegear-Version: 0.7.15-1580
  • Komm-Modul: HM-MOD-RPI-PCB
Häufige Kommunikationsprobleme mit HM-Sec-RHS
#2

Die ganze Woche über lief Homegear ohne Probleme. Nach dem wöchentlichen Systemupdate und Reboot am Samstag musste ich wieder alles Queues löschen.

@sathya muss ich beim runterfahren des Docker-Containers irgendwas beachten?
Und gibt es eine Möglichkeit das Löschen der queues zu automatisieren bzw. dafür ein Skript zu schreiben?

#3

Hallo @marbon,

da scheint es Kommunikationsprobleme mit den Geräten zu geben. Hast du mal ein Log für mich?

Viele Grüße

Sathya

#4

Hi @sathya,

hier das Log. Ich habe folgendes gemacht:

  1. Raspi neu gestartet
  2. Soll-Temperatur von Device 2 per REST abgefragt (Response war falsch)
  3. Soll-Temperatur am Gerät geändert
  4. Soll-Temperatur von Device 2 per REST abgefragt (Response war falsch)
  5. Queues von Device 2 geleert
  6. Nach ein paar Sekunden war der Wert in der REST-Response korrekt.

homegear.log (50,2 KB)

#5

Hi @marbon,

in dem Log wird kein einziges Paket gesendet, das hilft also leider nicht weiter. Leere mal die Queues und zeichne dann das Log auf, bis der Fehler auftritt. Dieses Log benötige ich. Das zeigt hoffentlich, warum das Problem auftritt.

Viele Grüße

Sathya

#6

Hi @sathya,

das Problem ist, dass ich sobald ich ein Paket über Homegear senden lassen (z.B. die Temperatur eines Thermostats ändere über Openhab ändere) werden die Queues abgearbeitet, vorher aber nicht.
Solange die Queues voll sind, kriege ich aber keine aktuellen Daten ausgelesen ohne vorher welche zu senden.
Ich habe das Log nochmal angehängt, ich vermute aber darauf wird nichts zu finden sein :confused:
homegear.log (384,4 KB)

#7

Hallo @marbon,

im Log sieht soweit alles in Ordnung aus.

das Problem ist, dass ich sobald ich ein Paket über Homegear senden lassen (z.B. die Temperatur eines Thermostats ändere über Openhab ändere) werden die Queues abgearbeitet

Jetzt verstehe ich Bahnhof :stuck_out_tongue:. Die Queues werden doch nur beim Senden von Paketen angelegt? Du könntest aber von einem Fehler betroffen sein, den ich gerade behoben haben, nämlich wenn du das 2. und 3. Wochenprogramm bearbeitet hast. Dann wurden die Queues tatsächlich nie abgearbeitet. Aktualisier mal auf das aktuelle Nightly und schaue, ob die Fehler noch auftreten.

Viele Grüße

Sathya

#8

Die Nightly würde ich gerne testen, aber für Raspi gibt es leider noch keine nightly-Docker-Images.

Um nochmal mein Problem zu erklären: ich kriege keine aktuellen Werfe gelesen. Wenn ich dann einen Wert schreibe, der entsprechend über Homegear gesendet wird, werden auch die Queues abgearbeitet und danach kann ich die aktuellen Werte auch lesen.

#9

Naja, prinzipiell schon: https://hub.docker.com/r/homegear/rpi-homegear/

Nur werden die Docker-Nightlies nicht so häufig erzeugt, wie die Pakete.

Wenn ich dann einen Wert schreibe, der entsprechend über Homegear gesendet wird, werden auch die Queues abgearbeitet und danach kann ich die aktuellen Werte auch lesen.

Die Frage ist, was erzeugt dann die Queues? Dabei handelt es sich ja um zu sendende Pakete?

Viele Grüße

Sathya

#10

Sorry, das nightly-Tag habe ich in der Mobil-Ansicht von hub.docker.com nicht gesehen (den Reiter Tags gibt es dort komischerweise nicht) und aus dem letzten Upload-Status hatte ich geschlossen, dass es noch gar keine Nightlies gibt.
Ich werde das IMage gleich mal lokal bauen und dann die Nightly testen.

Mit der aktuellen Release-Version habe ich folgende Pakete nach einem Neustart in der Queue:

Queue 1:
  Number of packets: 2
  Packet 1 (Type: Packet): 1087A001FDBEC5391EB500040000000000
  Packet 2 (Type: Message): Type: 10
Queue 2:
  Number of packets: 2
  Packet 1 (Type: Packet): 1088A001FDBEC5391EB500040000000007
  Packet 2 (Type: Message): Type: 10
Queue 3:
  Number of packets: 2
  Packet 1 (Type: Packet): 1089A001FDBEC5391EB500040000000008
  Packet 2 (Type: Message): Type: 10
Queue 4:
  Number of packets: 2
  Packet 1 (Type: Packet): 108AA001FDBEC5391EB500040000000009
  Packet 2 (Type: Message): Type: 10
Queue 5:
  Number of packets: 2
  Packet 1 (Type: Packet): 108BA001FDBEC5391EB501040000000001
  Packet 2 (Type: Message): Type: 10
Queue 6:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B8CA001FDBEC5391EB50103
  Packet 2 (Type: Message): Type: 10
Queue 7:
  Number of packets: 2
  Packet 1 (Type: Packet): 108DA001FDBEC5391EB502040000000001
  Packet 2 (Type: Message): Type: 10
Queue 8:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B8EA001FDBEC5391EB50203
  Packet 2 (Type: Message): Type: 10
Queue 9:
  Number of packets: 2
  Packet 1 (Type: Packet): 108FA001FDBEC5391EB503040000000001
  Packet 2 (Type: Message): Type: 10
Queue 10:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B90A001FDBEC5391EB50303
  Packet 2 (Type: Message): Type: 10
Queue 11:
  Number of packets: 2
  Packet 1 (Type: Packet): 1091A001FDBEC5391EB506040000000001
  Packet 2 (Type: Message): Type: 10
Queue 12:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B92A001FDBEC5391EB50603
  Packet 2 (Type: Message): Type: 10
Queue 13:
  Number of packets: 2
  Packet 1 (Type: Packet): 1093A001FDBEC5391EB507040000000001
  Packet 2 (Type: Message): Type: 10
Queue 14:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B94A001FDBEC5391EB50703
  Packet 2 (Type: Message): Type: 10

Sagt dir der Typ irgendwas? bzw. wie kann ich sonst genauer sehen, was das für Pakete sind?

#11

Genau der Fehler sollte in den aktuellen Nightlies gefixed sein ;-). Das werden Konfigurationsparameter gesetzt (z. B. Wochenprogramme).

Viele Grüße

Sathya

#12

ok, super. Docker-Build läuft gerade…

#13

Der build schlägt leider fehl:

##########################################################################
##########################################################################
### Please modify the file /etc/homegear/families/homematicwired.conf  ###
### according to your needs  and restart Homegear.                     ###
##########################################################################
##########################################################################
(Reading database ... 11379 files and directories currently installed.)
Preparing to unpack homegear-homematicwired_current_raspbian_stretch_armhf.deb ...
homegear: unrecognized service
dpkg: error processing archive homegear-homematicwired_current_raspbian_stretch_armhf.deb (--install):
 subprocess new pre-installation script returned error exit status 1
Errors were encountered while processing:
 homegear-homematicwired_current_raspbian_stretch_armhf.deb

Habe einfach die buildImage.sh ausgeführt

#14

Ich habe auf die aktuelle Nightly (version 0.8.0-2129) aktualisiert, habe aber trotzdem nach jedem Neustart volle Queues:

» docker exec -it homegear homegear -r
Connected to Homegear (version 0.8.0-2129).
> fs 0
Device family "HomeMatic BidCoS" selected.
For information about the family's commands type: "help"
(Family)> ps 2
Peer with id 2 and device type 0x95 selected.
For information about the peer's commands type: "help"
(Peer)> queues info
Number of Pending queues: 14
Queue 1:
  Number of packets: 2
  Packet 1 (Type: Packet): 1015A001FDBEC543F6D000040000000000
  Packet 2 (Type: Message): Type: 10
Queue 2:
  Number of packets: 2
  Packet 1 (Type: Packet): 1016A001FDBEC543F6D000040000000007
  Packet 2 (Type: Message): Type: 10
Queue 3:
  Number of packets: 2
  Packet 1 (Type: Packet): 1017A001FDBEC543F6D001040000000001
  Packet 2 (Type: Message): Type: 10
Queue 4:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B18A001FDBEC543F6D00103
  Packet 2 (Type: Message): Type: 10
Queue 5:
  Number of packets: 2
  Packet 1 (Type: Packet): 1019A001FDBEC543F6D002040000000001
  Packet 2 (Type: Message): Type: 10
Queue 6:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B1AA001FDBEC543F6D00203
  Packet 2 (Type: Message): Type: 10
Queue 7:
  Number of packets: 2
  Packet 1 (Type: Packet): 101BA001FDBEC543F6D003040000000001
  Packet 2 (Type: Message): Type: 10
Queue 8:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B1CA001FDBEC543F6D00303
  Packet 2 (Type: Message): Type: 10
Queue 9:
  Number of packets: 2
  Packet 1 (Type: Packet): 101DA001FDBEC543F6D004040000000001
  Packet 2 (Type: Message): Type: 10
Queue 10:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B1EA001FDBEC543F6D00403
  Packet 2 (Type: Message): Type: 10
Queue 11:
  Number of packets: 2
  Packet 1 (Type: Packet): 101FA001FDBEC543F6D005040000000001
  Packet 2 (Type: Message): Type: 10
Queue 12:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B20A001FDBEC543F6D00503
  Packet 2 (Type: Message): Type: 10
Queue 13:
  Number of packets: 2
  Packet 1 (Type: Packet): 1021A001FDBEC543F6D006040000000001
  Packet 2 (Type: Message): Type: 10
Queue 14:
  Number of packets: 2
  Packet 1 (Type: Packet): 0B22A001FDBEC543F6D00603
  Packet 2 (Type: Message): Type: 10
(Peer)>
#15

Hast du probiert, noch einmal den Anlernknopf am entsprechenden Gerät zu drücken? In der Queue sind noch Pakete des Anlernprozesses. Eigentlich müssten diese jetzt abgearbeitet werden. Falls das nicht klappt, poste noch einmal das Log.

#16

Hi @sathya,

sorry fuer die spaete Antwort, ich bin leider in den letzten Wochen nicht dazu gekommen und so lange ich meinen Pi bzw. den Homegear-Container nicht neu starte, läuft alles.

Dein Tipp hat so halb geholfen. Wenn ich Homegear starte sind die Queues erstmal voll mit den oben genannten Paketen. Wenn ich am Homematic-Gerät den Anlernknopf drücke, werden diese auch an das Gerät übertragen und die Queues geleert. Beim nächsten Neustart von Homegear bzw. vom Docker-Container, sind die Queues aber wieder voll. Keine Ahnung warum Homegear die Pakete immer wieder neu senden möchte.
Hier nochn das Log.

homegear.log (21,3 KB)

#17

Hallo @marbon,

hab gerade noch einmal in den Quelltext geschaut. Jetzt ist mir das Problem endlich klar :roll_eyes:: Die Queues werden beim Herunterfahren von Homegear gespeichert. Beim Stoppen des Dockercontainers wird Homegear aber nicht korrekt heruntergefahren. Im aktuellen Dockerimage sollte es gefixed sein. docker stop muss allerdings mit dem Parameter --time 60 ausgeführt werden, da das Timeout sonst zu gering ist:

docker stop --time 60 homegear

Alternativ kann der Docker-Konfigurationsparameter shutdown-timeout in /etc/docker/daemon.json gesetzt werden.

Viele Grüße

Sathya

#18

Vielen Dank für deine Mühe! Leider wird bei mir der Container immer noch nicht richtig beendet, trotz eines Timeouts von 120s.

Ich habe das Timeout in meinem docker-compose-File mit stop_grace_period definiert (Siehe https://docs.docker.com/compose/compose-file/compose-file-v2/#stop_grace_period).
Beim stoppen / restarten wartet docker auch die 120s ab (das Stoppen dauert 120s), aber nach dem Restart sind die Queues wieder voll.
Ich habe auch schon den Anlernknopf nochmal gedrückt, um die Queues einmalig zu leeren, aber trotzdem sind die Queues nach dem nächsten Neustart dann wieder voll.

Ich habe es auch mit sudo docker restart --time 60 homegear probiert, macht keinen Unterschied.

Ich nutzt das aktuelle nightly-Docker-Image:

REPOSITORY              TAG                  IMAGE ID            CREATED             SIZE
homegear/rpi-homegear   nightly              a230881f9842        39 minutes ago      643MB
#19

Hallo @marbon,

rpi-homegear ist gerade erst hochgeladen gewesen, als du getestet hast. Schau mal, ob du noch die alte Version hattest. Falls nicht, muss ich noch einmal schauen. Mit dem amd64-Image habe ich es getestet. Der Herunterfahrvorgang muss auch im Homegear-Log angezeigt werden.

Viele Grüße

Sathya

#20

Hi @sathya, ich habe leider schon die neuste Version. Wäre nett, wenn du nochmal reinschauen kannst.
Hier noch mein Log, falls du es brauchst:
homegear.log (514,8 KB)