Homegear "hängt" sich auf

Hallo,

erst mal vielen Dank für das coole Projekt. Dadurch wird es mir erst möglich mit meinen Homematic-Komponenten und openhab Spaß zu haben

Ich habe jedoch ein kleines subtiles Problem bei dem ich nicht weiterkomme. Momentan lasse ich Homegear in folgendem Setup laufen:

Raspberry Pi mit CCD von busware.de (sowas wie das COC, nur mit Display)
Folgende Devices habe ich verbunden:
ID1 : HM-Sec-SD
ID2 : HM-Sec-SC-2
ID3 : HM-LC-Sw1-Pl-2

Nun hatte ich das Problem, dass in Verbindung mit Openhab nach ein paar Minuten keine Nachrichten mehr gesendet/empfangen wurden. Am Türkontakt konnte man das ganz gut erkennen: Wenn der Kontakt geschalten wurde, dann leuchtete das Lämpchen rot (normalerweise blinkt es kurz grün). Wenn ich in das Logfile von homegear geschaut habe, konnte ich zwar sehen, dass openhab über xmlrpc kommuniziert, es ging aber nichts raus.

Ich habe daraufhin einen kleinen Client für XMLRPC geschrieben, der ein paar Kommandos schickt um das Problem einzugrenzen. Die erste Version des Client sendet alle 2 Sekunden an den Schalter immer abwechselnd “ein” und “aus”. Da konnte ich keinerlei Probleme feststellen. Dann habe ich ein bisschen rumprobiert und aus dem Rauchmelder die Batterie rausgenommen. Der Rauchmelder ist also nicht mehr erreichbar!

Nun setzt mein Client alle 2 Sekunden beim Rauchmelder das INSTALL_TEST und beim Schalter das “STATE” flag auf abwechslend true und false.

	boolean state = true;
	for (int i = 1; i < 20; i++) {
		homegear.setValue(1, 1, "INSTALL_TEST", state);
		homegear.setValue(3, 1, "STATE", state);
		state = !state;
		try {
			Thread.sleep(2000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}
	}

Damit schaffe ich es, dass sich homegear nach ein paar durchläufen “aufhängt” - der Schalter schaltet nicht mehr. Ins Logfile kommen aber immer noch Meldungen wenn neue Kommandos über XMLRPC kommen.

Beim INSTALL_TEST sieht das so aus (habe aus dem log die XMLRPC aufrufe entfernt):

04/09/14 19:12:35.521 Info: Connection from 192.168.0.131:56017 accepted. Client number: 13
04/09/14 19:12:35.522 Listening for incoming packets from client number 13.
04/09/14 19:12:35.525 Debug: Packet received: 504F5354202F786D6C72706320485454502F312E310D0A436F6E74656E742D547970653A20746578742F786D6C0D0A557365722D4167656E743A2041706163686520584D4C2052504320332E30202853756E2048545450205472616E73706F7274290D0A43616368652D436F6E74726F6C3A206E6F2D63616368650D0A507261676D613A206E6F2D63616368650D0A486F73743A2072617370626572727970693A323030310D0A4163636570743A20746578742F68746D6C2C20696D6167652F6769662C20696D6167652F6A7065672C202A3B20713D2E322C202A2F2A3B20713D2E320D0A436F6E6E656374696F6E3A206B6565702D616C6976650D0A436F6E74656E742D4C656E6774683A203238350D0A0D0A3C3F786D6C2076657273696F6E3D22312E302220656E636F64696E673D225554462D38223F3E3C6D6574686F6443616C6C3E3C6D6574686F644E616D653E73657456616C75653C2F6D6574686F644E616D653E3C706172616D733E3C706172616D3E3C76616C75653E3C69343E313C2F69343E3C2F76616C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E3C69343E313C2F69343E3C2F76616C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E494E5354414C4C5F544553543C2F76616C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E3C626F6F6C65616E3E303C2F626F6F6C65616E3E3C2F76616C75653E3C2F706172616D3E3C2F706172616D733E3C2F6D6574686F6443616C6C3E
04/09/14 19:12:35.526 Info: Method called: setValue Parameters:
(Integer) 1
(Integer) 1
(String) INSTALL_TEST
(Boolean) 0
04/09/14 19:12:35.530 Info: Sending: 0BA394401F71D5FD120100CF
04/09/14 19:12:35.541 Info: Connection to client number 13 closed.
04/09/14 19:12:36.130 Info: Sending: 0BA494401F71D5FD120100CF
04/09/14 19:12:36.731 Info: Sending: 0BA594401F71D5FD120100CF
04/09/14 19:12:37.330 Info: Sending: 0BA694401F71D5FD120100CF
04/09/14 19:12:37.930 Info: Sending: 0BA794401F71D5FD120100CF
04/09/14 19:12:38.531 Info: Sending: 0BA894401F71D5FD120100CF

Beim STATE so:

04/09/14 19:15:45.361 Info: Connection from 192.168.0.131:56044 accepted. Client number: 13 04/09/14 19:15:45.362 Listening for incoming packets from client number 13. 04/09/14 19:15:45.364 Debug: Packet received: 504F5354202F786D6C72706320485454502F312E310D0A436F6E74656E742D547970653A20746578742F786D6C0D0A557365722D4167656E743A2041706163686520584D4C2052504320332 E30202853756E2048545450205472616E73706F7274290D0A43616368652D436F6E74726F6C3A206E6F2D63616368650D0A507261676D613A206E6F2D63616368650D0A486F73743A2072617370626572727970693A323030310D0A4163636570743A 20746578742F68746D6C2C20696D6167652F6769662C20696D6167652F6A7065672C202A3B20713D2E322C202A2F2A3B20713D2E320D0A436F6E6E656374696F6E3A206B6565702D616C6976650D0A436F6E74656E742D4C656E6774683A203237380 D0A0D0A3C3F786D6C2076657273696F6E3D22312E302220656E636F64696E673D225554462D38223F3E3C6D6574686F6443616C6C3E3C6D6574686F644E616D653E73657456616C75653C2F6D6574686F644E616D653E3C706172616D733E3C706172 616D3E3C76616C75653E3C69343E333C2F69343E3C2F76616C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E3C69343E313C2F69343E3C2F76616C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E53544154453C2F766 16C75653E3C2F706172616D3E3C706172616D3E3C76616C75653E3C626F6F6C65616E3E303C2F626F6F6C65616E3E3C2F76616C75653E3C2F706172616D3E3C2F706172616D733E3C2F6D6574686F6443616C6C3E 04/09/14 19:15:45.365 Info: Method called: setValue Parameters: (Integer) 3 (Integer) 1 (String) STATE (Boolean) 0 04/09/14 19:15:45.367 Debug: STATE of peer 3 with serial number KEQ0423048:1 was set to 00. 04/09/14 19:15:45.369 Creating SAVEPOINT BidCoSQueue2263902_17 04/09/14 19:15:45.370 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:45.665 Sending from resend thread 0 of queue 17. 04/09/14 19:15:45.666 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:45.867 Sending from resend thread 1 of queue 17. 04/09/14 19:15:45.868 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:46.070 Sending from resend thread 2 of queue 17. 04/09/14 19:15:46.071 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:46.272 Sending from resend thread 3 of queue 17. 04/09/14 19:15:46.274 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:46.775 Sending from resend thread 4 of queue 17. 04/09/14 19:15:46.776 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:47.278 Sending from resend thread 5 of queue 17. 04/09/14 19:15:47.279 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:48.281 Sending from resend thread 6 of queue 17. 04/09/14 19:15:48.282 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:49.284 Sending from resend thread 7 of queue 17. 04/09/14 19:15:49.285 Info: Sending: 0EE9A011FD1201228B5E0201C80000 04/09/14 19:15:54.288 Sending from resend thread 8 of queue 17. 04/09/14 19:15:54.289 Info: Sending: 0EE9A011FD1201228B5E0201C80000 (

Wenn ich homegear dann neustarte, schaltet der Schalter mit STATE wieder. Allerdings werden mit dem ersten Kommando an STATE anscheinend die Ganzen nicht ausgelieferten Meldungen mitgeschickt. Der Schalter schaltet ein paar sekunden wild ein und aus. Danach geht er wieder in den “2 Sekunden” modus.

Ich hoffe Du kannst mir helfen. Ich kann auch detaillierte Logfiles schicken oder was ausprobieren. Irgendwie habe ich das Gefühl, dass das TEST_INSTALL irgendwo in eine queue reinläuft und dann jegliche Kommunikation verhindert…

Viele Grüße
Markus

P.S.: das CCD läuft übrigens mit folgenden Einstellungen
deviceType = coc
device = /dev/ttyAMA0
responseDelay = 95
gpio1 = 17
gpio2 = 22

Hey Markus,

tut mir leid, dass ich so spät antworte - die letzten drei Tage hatte ich schriftliches Examen . Ich schaue mir das Problem heute oder morgen an und werde dann auch direkt einen Fix bereitstellen.

Liebe Grüße

Sathya

Nachtrag: Habs gerade bei mir getestet und kann das Problem reproduzieren. Mir ist es vermutlich bisher noch nicht aufgefallen, weil ich weder COC noch CUL verwende. Mit dem CRC tritt das Problem nicht auf.
Nachtrag 2: Mit dem CUL tritt das Problem auch nicht auf. Also ein reines COC-Problem. Der Quelltext für das Ansprechen des COC und des CUL ist fast der gleiche. Daher kann es auch sein, dass es ein Problem mit der COC-Firmware ist.

Hey Markus,

hab das Problem gefunden. Aus irgendeinem Grund verlässt der COC/CCD manchmal nach dem Senden den Empfangsmodus. Als Workaround aktiviere ich jetzt nach jedem gesendeten Paket den Empfangsmodus wieder. Morgen schaue ich auch mal, ob ich das Problem nicht vielleicht auch in der COC/CCD-Firmware ausfindig machen kann. Die gefixte Homegear-Version findest du unten als Anhang. Schau mal, ob es damit jetzt klappt. Wenn du alle zwei Sekunden “INSTALL_TEST” setzt, wird der Schalter zwar zunächst auch nicht reagieren, weil das Senden jedes INSTALL_TEST-Pakets ca. 320ms in Anspruch nimmt und dadurch die Schalter-Antworten vom COC/CCD meist nicht empfangen werden (das ist ein sogenanntes Wake-on-Radio-Paket, daher die lange Sendezeit). Aber nach Ende des Scripts sollte das Schalten dann wieder funktionieren. Zur Zeit arbeitet Homegear noch so, dass alle Wert-Änderungen in einer Warteschleife landen, die dann abgearbeitet wird. Das heißt, der Schalter wird, sobald er wieder erreichbar ist, auch nach wie vor mehrmals an- und ausgehen. Ich schreib mir mal auf die Todo-Liste, dass bei Änderung eines Wertes geschaut wird, ob bereits ein Paket zur Änderung dieses Wertes in der Warteschleife ist und wenn ja, das alte Paket aus der Warteschleife gelöscht wird.

Liebe Grüße

Sathya

[Anhang gelöscht]

Jetzt werden auch die alten Wert-Änderungen aus der Warteschleife gelöscht. Bin gespannt auf dein Feedback .

Cool, vielen Dank! Ich werde das heute Abend (oder morgen früh) gleich mal ausprobieren und mich dann melden.

So, jetzt habe ich es endlich geschafft. Hatte leider kurzfristig ein paar Probleme mit meinem Netzwerk, dadurch konnte ich das nicht gut testen. Ist mir schon ganz peinlich, weil Du sehr schnell reagiert hast!

Der Workaround hat geholfen, es hängt jetzt nicht mehr. Bei meinem Test mit INSTALL_TEST an einen nicht funktionierenden RM und einem darauffolgenden STATE-wechsel auf der Steckdose hängt sich das System zwar nicht mehr auf, aber nicht jeder STATE-wechsel wird registriert. Das liegt aber vermutlich daran, dass die queue nicht schnell genug abgearbeitet werden kann - ist für mich kein Problem.

Auch die schnellen “ein/aus” schaltvorgänge passieren jetzt nicht mehr.

Vielen Dank!

Hey Markus,

schön, dass es jetzt klappt . Genau, das Problem ist, dass die Queue nicht schnell genug abgearbeitet werden kann. Die Leitung ist quasi die ganze Zeit blockiert. Die Wake-on-Radio-Pakete brauchen sehr viel Zeit. In der Praxis wird das Gerät aber hoffentlich erreichbar sein - dann sollte es selbst mit 2 Sekunden “sleep” klappen. Wobei du vermutlich nicht vor hast, alle zwei Sekunden ein “INSTALL_TEST” zu senden . Bei Nicht-Wake-on-Radio-Paketen (also die meisten) besteht das Problem nicht. Mit 4 oder 5 Sekunden “sleep” sollte aber auch dein Script bereits einwandfrei funktionieren. Auch mit zwei Sekunden sollte aber der letzte State-Wechsel korrekt an den Schalter übertragen werden - wenn auch mit Verzögerung. Hab mir zum Testen jetzt übrigens auch mal ein CCD bestellt .

Wenn noch irgendwelche Probleme auftreten sollten, melde dich!

Liebe Grüße

Sathya

Absolut nicht Das “Progrämmchen” war ja nur dazu da, den Hänger mit openhab irgendwie isoliert nachzustellen. Jetzt wechsel’ ich wieder auf openhab.

Ich habe übrigens ein bisschen in culfw geschmökert und sogar das Datenblatt des CC1101 gewälzt. Ich konnte nicht erkennen, wieso der nicht wieder auf RX gehen würde. Habe aber auch nicht alles voll verstanden… Z.B. wie das mit dem Burst (wake on radio?) funktioniert. Sendet der Chip, obwohl nichts im FIFO liegt? Egal, man muß nicht alles wissen

Auf jeden Fall müsste er ja in rf_asksin.c entweder zwischen

  // enable TX, wait for CCA
  do {
    ccStrobe(CC1100_STX);
  } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_TX);

und

  if(asksin_on) {
    do {
      ccStrobe(CC1100_SRX);
    } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_RX);
  } else {
    set_txrestore();
  }

rausfliegen, oder asksin_on wird plötzlich false - das sehe ich beides nicht…

Vielleicht ist auch von irgendeinem Paket die Länge falsch und es wird etwas als Kommando interpretiert, das nicht als Kommando gemeint ist? Ich werde weiter forschen

Richtige Probleme sind erst mal keine mehr in Sicht, nur eine Frage zu STICKY_UNREACH bzw. UNREACH: Gibt es eigentlich eine Möglichkeit durch ein periodisches Signal (nicht unbedingt alle zwei Sekunden ) abzufragen, ob der Rauchmelder noch verbunden ist? Ich stelle mir das als interessantes Feature vor, vor allem bei einer “wackeligen” Verbindung, die nur bei Aktivität von manchen Störquellen ausfällt, oder bei geschlossenen Türen. Klar, würde sich das auf die Batterien negativ auswirken, aber das könnte ja man über die Polling-Periode regulieren. Die Frage ist, geht das technisch überhaupt?

Viele Grüße
Markus

Ich habe damals selbst eine Weile gebraucht, um Wake-on-Radio zu verstehen. Das ist auch grottig dokumentiert. Im Wake-on-Radio-Modus wacht der CC1101 in definierten Zeitabständen auf (ich meine, es waren alle 350ms) und lauscht dann ganz kurz (2,4ms), ob ein Preamble-Signal gesendet wird. Falls das der Fall ist, wechselt das Gerät in den RX-Modus, um das eigentliche Paket zu empfangen. Das Preamble-Signal lässt sich senden, indem man den CC1101 in den TX-Modus setzt, ohne dass irgendwas im FIFO liegt. Entsprechend der Aufwach-Zeitabstände muss das Signal so lange gesendet werden, dass man das Aufwachen sicher trifft. Hier mal eine Abbildung mit den Verschiedenen Stromsparstrategien aus Christians und meinem Vortrag auf dem 30C3:

pwr save strategies.png764×400 31.4 KB

Ich habe selbst auch schon in die culfw geschaut und das Problem auch nicht auf Anhieb gefunden. Die rf_asksin.c wird sowohl vom CUL als auch vom COC/CCD verwendet. Der CUL zeigt das Problem aber nicht. Das spricht ein bisschen dagegen, dass das Problem dort zu suchen ist und ich sehe auch keinen Fehler. Der sinnvollste nächste Schritt wäre vermutlich, mit einem Logic-Analyzer auf den SPI-Leitungen zu lauschen und zu schauen, was genau eigentlich passiert (wird der Asksin-Modus verlassen? Werden Pakete empfangen?). Mir scheint, der COC wird nicht so häufig verwendet. Das Problem tritt nämlich sicher auch mit FHEM auf (oder aktiviert FHEM den Asksin-Modus nach jedem Senden - hab ich nicht geschaut?).

Ein Problem mit der Paketlänge ist es nicht. Aber es kann tatsächlich sein, dass der RPI über UART irgendwas sendet, was als Kommando interpretiert wird. Damit gab es auch schon in der Vergangenheit Probleme. Also auch Sniffen von UART lohnt sich vielleicht.

So oder so, es funktioniert ja erstmal - auch wenn das Reaktivieren des Asksin-Modus nach jedem Senden etwas Zeit in Anspruch nimmt, während der natürlich nichts empfangen werden kann.

Hmm, normalerweise reicht es, einfach irgendwas an das Gerät zu senden. Bei Nicht-Empfang wird dann UNREACH gesetzt. Allerdings ist das bei den Rauchmeldern nicht ganz so simpel, weil es nicht so wirklich Konfigurationsparameter gibt und ich meine, keine Antworten auf die STATE-Pakete gesendet werden. Vermutlich muss ich die Funktion also wirklich neu in Homegear einprogrammieren - ist aber recht simpel. Was hältst du von einer neuen RPC-Funktion “poll” mit dem Gerät als Parameter? Zyklisch ließe sich das dann gezielt über getimete Events realisieren?

Liebe Grüße

Sathya

Vielen Dank für die Info, jetzt ist mir das klarer…

Das wäre super, dann könnte man das komplett selbst triggern. Ich könnte im homematic-binding von openhab eine Funktion einbauen, mit der man geräte pollen kann. Ich wollte mich sowieso etwas mit den actions von openhab beschäftigen. Vielleicht wäre aber auch ein spezielles Binding für das “UNREACH” sinnvoll, dem man optional ein “homegearPollInterval” mitgeben könnte. Dann hat man gleich ein item mit dem UNREACH-Status, das nach dem polling intervall auf jeden Fall aktuell ist. Vielleicht ist auch eine Kombination aus action und binding sinnvoll, damit man das polling auch außerhalb des Intervalls aktiv auslösen kann.
Wäre in Summe ein gutes Feature, vor allem für Sicherheitsanwendungen. Könntest Du das denn in homegear reinbekommen?

Steht jetzt auf der Todo-Liste . Werd’s nach meinem Examen nächste Woche einprogrammieren.

Steht jetzt auf der Todo-Liste . Werd’s nach meinem Examen nächste Woche einprogrammieren.[/quote]

Cool! Viel Erfolg!