Z-Wave-Probleme seit Update auf 5.1

Ich habe seit dem Update auf 5.1 alle 2-3 Wochen das Problem, dass sich der Symcon-Dienst auf dem Raspi beendet. Im Logfile steht als letztes immer was von „Zeitüberschreitung beim Warten auf Bestätigung“. Hier mal ein paar Auszüge:

02.08.2019 10:00:14 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 35 ~ Absender: TimerEvent
02.08.2019 10:02:12 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
02.08.2019 10:03:04 | 58529 | MESSAGE | VariableManager      | [Location\Altitude] = 35,8359366125
02.08.2019 10:03:20 | 29680 | MESSAGE | VariableManager      | [Location\Azimuth] = 107,2306821595
02.08.2019 10:03:28 | 11170 | ERROR   | TimerPool            | OpenWeatherMap - Datenabruf (UpdateData): Waiting for script result timed out
02.08.2019 10:03:28 | 52067 | DEBUG   | VariableManager      | [Untergeschoss\Gästezimmer\Dimmer Deckenlampe (NodeID 006)\Meter (0), Electric, kWh] = 8,4600000000
02.08.2019 10:03:41 | 49844 | DEBUG   | VariableManager      | [Z-Wave Gateway\HomeID] = E26BAAD9
02.08.2019 10:04:08 | 12146 | DEBUG   | VariableManager      | [Z-Wave Gateway\NodeID] = 1
02.08.2019 10:04:56 | 49844 | DEBUG   | VariableManager      | [Z-Wave Gateway\HomeID] = E26BAAD9
02.08.2019 10:04:56 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Antwort
24.08.2019 02:30:25 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 35 ~ Absender: TimerEvent
24.08.2019 02:33:18 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
24.08.2019 02:33:27 | 18746 | DEBUG   | VariableManager      | [Obergeschoss\Schlafzimmer\Nachttisch links (NodeID 005)\Value] = 0,0000000000
24.08.2019 02:33:27 | 51785 | DEBUG   | VariableManager      | [Obergeschoss\Schlafzimmer\Nachttisch links (NodeID 005)\Value\Power] = 0,0000000000
24.08.2019 02:33:27 | 58529 | MESSAGE | VariableManager      | [Location\Altitude] = -26,3460569647
24.08.2019 02:33:27 | 29680 | MESSAGE | VariableManager      | [Location\Azimuth] = 15,5423710012
24.08.2019 02:33:27 | 30939 | DEBUG   | VariableManager      | [Obergeschoss\Schlafzimmer\Nachttisch links (NodeID 005)\Sensor Multilevel (Leistung)] = 0,0000000000
24.08.2019 02:34:34 | 18746 | DEBUG   | VariableManager      | [Obergeschoss\Schlafzimmer\Nachttisch links (NodeID 005)\Value] = 0,0000000000
24.08.2019 02:34:45 | 51785 | DEBUG   | VariableManager      | [Obergeschoss\Schlafzimmer\Nachttisch links (NodeID 005)\Value\Power] = 0,0000000000
24.08.2019 02:34:48 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung

08.09.2019 12:09:23 | 20788 | DEBUG   | VariableManager      | [Obergeschoss\Wannenbad\Rolladen (NodeID 024)\Meter (0), Electric, kWh] = 0,4600000000
08.09.2019 12:09:35 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 0 ~ Absender: TimerEvent ~ Dauer: 169730 ms
08.09.2019 12:09:38 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 34 ~ Absender: TimerEvent
08.09.2019 12:10:35 | 20788 | DEBUG   | VariableManager      | [Obergeschoss\Wannenbad\Rolladen (NodeID 024)\Meter (0), Electric, kWh] = 0,4600000000
08.09.2019 12:10:35 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
08.09.2019 12:11:45 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 35 ~ Absender: TimerEvent
08.09.2019 12:13:25 | 58529 | MESSAGE | VariableManager      | [Location\Altitude] = 41,6093743579
08.09.2019 12:13:51 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
08.09.2019 12:14:21 | 29680 | MESSAGE | VariableManager      | [Location\Azimuth] = 153,0700153973
08.09.2019 12:16:30 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung

18.09.2019 14:25:03 | 12548 | DEBUG   | VariableManager      | [Alarm\Außensirene (NodeID 027)\Sensor Multilevel (Lufttemperatur)] = 21,3000000000
18.09.2019 14:25:05 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 117 ~ Absender: RunScript
18.09.2019 14:25:40 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 0 ~ Absender: TimerEvent ~ Dauer: 92129 ms
18.09.2019 14:25:49 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
18.09.2019 14:25:53 | 13968 | DEBUG   | VariableManager      | [Alarm\Außensirene (NodeID 027)\Wert] = 21,3000000000
18.09.2019 14:25:56 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 35 ~ Absender: TimerEvent
18.09.2019 14:25:57 | 35077 | DEBUG   | VariableManager      | [Alarm\Außensirene (NodeID 027)\Wert\Temperature] = 21,3000000000
18.09.2019 14:26:09 | 12548 | DEBUG   | VariableManager      | [Alarm\Außensirene (NodeID 027)\Sensor Multilevel (Lufttemperatur)] = 21,3000000000
18.09.2019 14:27:09 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung
18.09.2019 14:28:46 | 56520 | ERROR   | TimerPool            | Z-Wave Gateway (KeepAlive): Zeitüberschreitung beim Warten auf Bestätigung

Ich nutze einen Raspberry Pi 1B mit einem Aeonlabs Gen5 USB Z-Wave Stick und knapp 30 Z-Wave-Nodes. Es funktioniert in der übrigen Zeit alles problemlos und unauffällig. Ich habe zwischenzeitlich sogar einen weiteren Aktor angelernt, der einwandfrei funktioniert. Das Update auf 5.2 brachte auch nichts. Wenn das Problem auftritt und der Dienst beendet wird, ist der Raspi weiterhin über Konsole erreichbar, aber der Symcon-Dienst ist halt weg.

Mir ist aufgefallen, dass der Static Controller (Node ID 1) im Z-Wave-Konfigurator rot markiert ist. Ist das normal? Habe schon versucht, den Static Controller in Symcon zu entfernen, aber es kommt der Hinweis ich solle ihn am Gerät exkludieren. Ich komme hier momentan nicht weiter.

Zwave Gateway Time Out hatte ich auch Mal auf meinem razby…
Hast du zufällig zway ebenfalls auf dem raspi installiert und das ist nach dem raspi OS Upgrade wieder aktiviert? Das ist mir passiert bei Umzug auf das neue raspbian os…

Zway gestoppt danach iOS neu gestartet und alles war gut…
Danach zway dauerhaft deaktivieren und nur zur Sicherung des Gateways nutzen…

Mir ist aufgefallen, dass der Static Controller (Node ID 1) im Z-Wave-Konfigurator rot markiert ist. Ist das normal? Habe schon versucht, den Static Controller in Symcon zu entfernen, aber es kommt der Hinweis ich solle ihn am Gerät exkludieren. Ich komme hier momentan nicht weiter.

Die Instanz kannst du löschen. Das Gateway mit der NodeID 1 braucht keine Instanz. (Man konnte mal dort eine Erstellen, was ein Fehler war) Schaden tut diese aber nicht.

Wenn IP-Symcon abstürzt kann ich dir nur das hier empfehlen: Debugging für Experten (Raspberry Pi, Linux) Damit kommen wir der Sache am schnellsten auf die Spur.

paresy

Ich habe nun endlich einen Absturz mit gdb erwischt. Leider hat das Speichern der gdb.txt nicht funktioniert wie beschrieben, die Datei war leer. Die angehängte txt-Datei ist copy&paste aus dem Terminal-Fenster. Pw kommt per pn. Danke.

2019-10-30_gdb.zip (14.1 KB)

Danke für das Log! Am Ende steht ein (gdb) und dann stirbt es mit SIGKILL? Hast du da gdb von extern gestoppt? Hattest du die Gelegenheit ein „bt“ für backtrace einzutippen? Denn leider fehlt mir dort noch ein Ausgabe :slight_smile:

paresy

Hi und danke fürs Kümmern. Nein, ich habe nichts manuell gestoppt. Ich habe es nach dem Absturz des symcon-Prozesses mit


set logging on
thread apply all bt
set logging off

versucht wie im Link beschrieben, aber er hat nur eine leere gdb.txt erstellt. Daraufhin habe ich einfach kopiert, was noch im Terminal-Fenster (Putty) stand. Bin in Sachen Linux aber auch völlig unfit.

Also das mit dem Logging funktioniert irgendwie nicht. Habe jetzt extra Bildschirm und Tastatur direkt am Raspberry angeschlossen. Nach einigen Tagen schmiert der Symcon-Prozess dann reproduzierbar ab.

Nach Eingabe von

thread apply all bt

kommt dann folgende Fehlermeldung:

Unable to fetch general registers.: Kein passender Prozess gefunden.

Das ist dann auch das einzige, was im Logfile steht.

Irgendwelche Tips die mich der Lösung des Problems näher bringen?

Magst du ggf. mal auf die Beta-Version wechseln? Evtl. betrifft dich auch das Out-of-Memory Problem, welches dann auch die kuriosen Abstürze erklärt.

paresy

Ok, Beta ist installiert, Logger läuft, werde berichten.

Installation der Beta hat leider auch nichts gebracht. Symcon wird nach ein paar Tagen wie gehabt einfach beendet. Wenigstens hat es jetzt mal mit dem Logging funktioniert, Datei hängt an.

gdb.txt (32.9 KB)

Da ist bisher nichts auffälliges. Magst du mal „dmesg“ eintippen? Kommen da ggf. am Ende einige OOM Meldungen?

Magst du ggf. mal die Version aus dem Testing Kanal installieren? Es könnte sein, dass du ebenfalls von den sporadischen Abstürzen betroffen bist, die nichts mit Z-Wave zu tun haben.

paresy

Feedback: der Wechsel auf den Testing-Kanal hat es jetzt scheinbar gebracht. Ich hatte Anfang Februar das letzte Mal vom Testing-Kanal aktualisiert, seither läuft Symcon stabil ohne Absturz. Ich hoffe, dass es dabei bleibt. Danke für den Support!

Kann man schon sagen, wann die Änderungen in die Stable-Version einfließen?

Dauert noch ein wenig. Sobald wir die Version als sehr gut erachten, ziehen wir die nach Stable hoch.

paresy

Zu früh gefreut. Heute Nacht hat sich der Symcon-Dienst mal wieder selbst beendet. Letzte Nachrichten im Logfile erneut Z-Wave-relevant. Ich kriege das Problem seit Update auf 5.1 einfach nicht in den Griff. :frowning:

01.03.2020 03:34:56 | 59364 | DEBUG | VariableManager | [Untergeschoss\Gästezimmer\Hue bloom\Modus] = 0
01.03.2020 03:35:00 | 49887 | MESSAGE | Z-Wave Module | Optimiere Gerät…
01.03.2020 03:35:02 | 49887 | NOTIFY | Z-Wave Module | Optimieren gestartet…
01.03.2020 03:35:15 | 00000 | DEBUG | ScriptEngine | Skriptausführung (Text) - Länge: 0 ~ Absender: TimerEvent ~ Dauer: 22080 ms
01.03.2020 03:35:19 | 49844 | DEBUG | VariableManager | [Z-Wave Gateway\HomeID] = E26BAAD9
01.03.2020 03:35:19 | 12146 | DEBUG | VariableManager | [Z-Wave Gateway\NodeID] = 1
01.03.2020 03:35:20 | 00000 | DEBUG | ScriptEngine | Skriptausführung (Text) - Länge: 35 ~ Absender: TimerEvent
01.03.2020 03:35:23 | 52771 | MESSAGE | Connect Control | Einstellungen gespeichert
01.03.2020 03:35:27 | 49887 | NOTIFY | Z-Wave Module | Optimierung des Geräts fehlgeschlagen!
01.03.2020 03:35:29 | 49887 | NOTIFY | Z-Wave Module | Optimierung des Geräts fehlgeschlagen!

Hallo,
Habe auch seit dem Update das Problem mit dem KeepAlive auf einem Windows10 System.
Kann mir hier vielleicht jemand helfen?

Gruß
MaBu