Keine Event-Meldungen von ZWAVE-Sensoren

Begonnen von PNinBB, 11 Juni 2018, 11:47:03

Vorheriges Thema - Nächstes Thema

rudolfkoenig

Da FHEM offensichtlich etwas verpasst, helfen die nachtraeglich hochgedrehten Logs wenig, auch strace muesste vom Zeitpunkts des Problems berichten. Beim Betrachten der strace Logs fiel mir ein, dass die Zeitstempel fehlen, das kann man mit "strace -tt ..." aktivieren.

Im strace Log sind etliche  clone() Aufrufe zu sehen (vermutlich wg BlockingCall), das koennte bei einem Programmierfehler auch die Ursache sein (beide Prozesse lesen von der Schnittstelle), ich meine aber nach Sortieren/Interpretiren des strace Logs, dass das nicht der Fall ist. Waere es trotzdem moeglich, das Problem in einer ueberwachten (strace+loglevel), separaten FHEM Instanz zu reproduzieren, was nur die ZWave Geraete und die zum Schalten benoetigte Logik enthaelt?

ZitatNachtrag: ich habe den Verdacht, dass dies garnichts mit FHEM zu tun hat, sondern sich ein anderer Prozess mit an diese serielle Schnittstelle hängt.
Das wuerde die Probleme erklaeren, und sowas kann man als root mit "lsof | grep /dev/ttyAMA" pruefen, allerdings ist das eine Momentaufnahme. 

PNinBB

Es ist schon schwierig, den Moment des Auftretens der 'Macke' zu treffen. Ich hoffe, jetzt ist es mir gelungen.
1. Auszug aus dem fhem.log:
2018.10.28 16:19:25.492 1: KU_GZ_FS meldet 'offen'
2018.10.28 16:19:25.495 3: ZWave set AZ_SK_D1 on
2018.10.28 16:19:28.878 1: KU_GZ_FS meldet 'zu'
2018.10.28 16:19:28.881 3: ZWave set AZ_SK_D1 off
2018.10.28 16:26:07.111 2: ZWDongle_ProcessSendStack: no ACK, resending message 0109001316028408252b73
2018.10.28 16:28:12.395 1: KU_GZ_FS meldet 'offen'
2018.10.28 16:28:12.397 3: ZWave set AZ_SK_D1 on
2018.10.28 16:28:14.463 1: KU_GZ_FS meldet 'zu'
2018.10.28 16:28:14.465 3: ZWave set AZ_SK_D1 off

Um 16:19:25 lief es noch, wie es sollte.
Ich denke, dass ich etwa um oder nach 16:26:07 herum versucht habe, den Vorgang (Aktivieren des Sensors und Einschalten des Lichtes) zu testen. Es gab keine Reaktion.
In jeder Sekunde xx:yy:43 wird die 'homeID' abgefragt. Danach (16:28:12.395) ging es wieder.

2. In diesem Zeitintervall lief auch 'strace'; die Datei ist angefügt.

Ich werde als nächstes versuchen, ein fhem zu stricken, welches nur die fraglichen Komponenten enthält.
Danke an Rudi und schönen Abend.
Peter
Raspi 4B + RaZberry2 (Deb 10), FritzBox 7490;
AEOTec: KeyFobGen5: 1x;
Danfoss: Living Connect 2.51: 3x;
Fibaro: FGK: 10x: 3x; FGBS: 001: 8x, 222: 1x; FGMS001: 2x; FGR: 222: 3x, 223: 2x; FGRGBWM-441: 1x; FGBS: 222: 2x, 223: 2x,224: 1x;
Philio: PAN06-1A: 3x;

rudolfkoenig

Leider kann ich das Log ohne Wissen deraktuellen ZWDongle FD nicht wirklich auswerten.
Was mir auffaellt:
- "nmap -p <port>" wird gestartet (das geht effizienter, mit 2-3 Syscalls statt mit 800, evtl mit ein paar Perl-Codezeilen mehr, und dann heisst es, FHEM waere ineffizient.), liest aber vermutlich keine Daten vom Dongle weg.
- dein strace Log enthaelt Daten von 16:25:57 bis 16:26:08, deckt also vermutlich nicht das Problem ab.

ZitatIch werde als nächstes versuchen, ein fhem zu stricken, welches nur die fraglichen Komponenten enthält.
Danke, und lsof (s.o.) nicht vergessen.

PNinBB

Ich habe gestern früh ein einfaches FHEM (mit fhem.cfg) gestrickt und es lief den ganzen Tag ohne Besonderheiten; vor allem die "Blockierung" ist nie aufgetreten.
Damit habe ich eine weitere Fehlersuche erst einmal eingestellt.
Ich konzentriere mich jetzt erst einmal auf die vielen Systemrufe und ähnliche Sachen, die ich im Laufe der Monate (auch Jahre!) in FHEM eingebaut habe. Wahrscheinlich laufen alle im FHEM-Hauptthread und blockieren damit das System. Das wird einige Zeit in Anspruch nehmen; ich melde mich wieder.
Herzlichen Dank an Rudi.
Schönen Abend
Peter
Raspi 4B + RaZberry2 (Deb 10), FritzBox 7490;
AEOTec: KeyFobGen5: 1x;
Danfoss: Living Connect 2.51: 3x;
Fibaro: FGK: 10x: 3x; FGBS: 001: 8x, 222: 1x; FGMS001: 2x; FGR: 222: 3x, 223: 2x; FGRGBWM-441: 1x; FGBS: 222: 2x, 223: 2x,224: 1x;
Philio: PAN06-1A: 3x;

thewolfman

Hallo,
ich bin ein völliger Anfänger was das Thema FHEM betrifft, möchte aber trotzdem auf meinen Post hier hinweisen: https://forum.fhem.de/index.php/topic,87812.0.html der den Effekt auch auf einer anderen HW Plattform erwähnt.

PNinBB

#35
Zuerst allen, vor allem den aktiven Ratgebern, beste Wünsche für das neue Jahr.
Nach einer etwas längeren Pause melde ich mich wieder mit ein paar Neuigkeiten nach einem fast kompletten "Umbau" meines Systems.
1. Ich habe alle Funktionen (FHEM und andere (Wetter, Kalender etc.), die bisher auf Raspi (zuletzt Raspi 3B+) liefen, auf zwei Rechner aufgesplittet:
  • der Raspi 3 (HA-Server) erledigt nur noch ZWAVE-Funktionen, also alles was Aktoren und Sensoren betrifft,
  • ein Odroid XU4 (IS-Server) macht alles andere, beispielsweise Wetterdienste, Unwetterwarnungen, Kalender, FritzBox u. ä.
2. Einige (wenige) Verbindungen zwischen den Systemen erledige ich mit FHEM2FHEM.
3. Das Hauptproblem ist und bleibt das "Interface" zum Nutzer. Ich hatte bisher FTUI, was ich sehr geschätzt habe, da man einen großen Freiheitsgrad hat, sich die Details so anzeigen zu lassen und das Aussehen so zu gestalten, wie man es möchte. Das will ich zukünftig mit Node-Red erledigen. Einiges geht schon; ich bin nur (momentan) unzufrieden mit dem automatischen Placement der Elemente. Das kann man sicher abschalten bzw. beeinflussen, aber dazu habe ich noch nichts gefunden.

Die erste Einschätzung: es verbleiben zwei Punkte:
1. FHEM läuft wesentlich stabiler; bis auf zwei Probleme (siehe extra Beitrag).
Vor drei Tagen ist allerdings der Raspi 3 wieder "gestorben"; möglicherweise wieder den Hitztot wie bereits im August. Dabei habe ich den HA-Server im mitgelieferten  Gehäuse mit zusätzlichen Öffnungen und zwei aufgesetzten kleinen Lüftern betrieben. Diese wurden über die GPIO-Kontakte und "etwas Elektronik" und einem Perl-Service (ausserhalb von FHEM) in Abhängigkeit von der CPU-Temperatur geschaltet. Dies lief ca. 3 Monate problemlos. Kühlkörper auf die kritischen ICs kann man wegen der ZWAVE-Platine schlecht aufbringen. Alles befindet sich hinter einer Pressstoffplatte in einem recht großen Freiraum mit aufgeschraubten gelöcherten Blende. Also eigentlich unverständlich. Einen weiteren Raspi 3 werde ich nicht kaufen.
Da ich noch den Raspi 2 hatte, habe ich die ZWAVE-Platine und die SDCard vom Raspi 3 genommen, auf den Raspi 2 gesteckt und alles lief problemlos. Es sollte zwar so ein, aber schön, wenn es sich bestätigt.
2. Es gibt auf dem IS-Server nur ein Problem mit dem Kalender; dabei werden wiederkehrende Termine nicht richtig wiedergegeben, aber dies auch in einem separaten Beitrag.
Peter
Raspi 4B + RaZberry2 (Deb 10), FritzBox 7490;
AEOTec: KeyFobGen5: 1x;
Danfoss: Living Connect 2.51: 3x;
Fibaro: FGK: 10x: 3x; FGBS: 001: 8x, 222: 1x; FGMS001: 2x; FGR: 222: 3x, 223: 2x; FGRGBWM-441: 1x; FGBS: 222: 2x, 223: 2x,224: 1x;
Philio: PAN06-1A: 3x;

PNinBB

Noch eine Ergänzung, die ich vergessen habe anzufügen und die eigentlich den Kern dieses Themas betrifft:
Gibt es noch den "Totzustand" ? ? ? ?
Die Antwort ist eindeutig  JA !!
Er ist allerdings in den letzten Wochen sehr selten aufgetreten, so "gefühlt" einmal alle 2 Wochen.
Dabei ist für mich die entscheidende Frage: Wie behandelt das System einen Interrupt ?
Für mich ist eine Meldung eines Sensors, der einen, wie auch immer gearteten Zustandswechsel signalisieren will, ein Interrupt, also ein "asynchrones" Ereignis.
Dafür gibt es die bekannten Lösungsansätze, die alle darin bestehen, ein laufendes Programm zu unterbrechen, den Interrupt zu bedienen und dann das unterbrochene Programm wieder fortzusetzen.
Die Alternative ist ein, wie auch immer geartetes Pollingverfahren, welches dann u.U. dem asynchronen Charakter nicht gerecht wird. Die Folge ist: ein nicht bedientes Anforderunsgsignal.
Meine Fragen wären:
1. Wie lange bleibt ein solches Signal im ZWAVE Controller erhalten, wenn es von FHEM nicht umgehend "abgenommen" wird. Bei meinen Test hatte ich mehrmals den Effekt, dass, wenn der "Totzustand" vorbei war, das Signal danach "ankam" und verarbeitet wurde, aber eben nicht immer.
2. Gibt es in FHEM eine solche "Interruptserviceroutine", die in eine irgendwie vom OS verwaltete Adresstabelle eingetragen wird?

In 00_ZWDongle.pm gibt es ab Zeile 769 folgende Zeilen:

#####################################
# called from the global loop, when the select for hash->{FD} reports data
sub
ZWDongle_Read($@)
{
. . . .

Dies lässt eher darauf deuten, dass es ein Pollingverfahren ist.
3. Ich vermute mal, dass die "global loop" unterschiedlich lange dauern kann, je nachdem, was zu erledigen ist. Ist der ungünstigste Fall kurz genug, um die Anforderung von ZWAVE noch bedienen zu können (siehe 1.) ?
Mein "Systemumbau" hat sicherlich dazu beigetragen, die "global loop" zu verkürzen. Dies würde auch erklären, dass das Auftreten des "Totzustandes" deutlich seltener geworden ist. Aber komplett auszuschliessen, ist er wohl nicht ? ? !

In der Perl-Dokumentation findet man einiges, was die Verbindung zum OS erkennen lässt.

The IO::Select package implements an object approach to the system select function call. It allows the user to see what IO handles, see IO::Handle, are ready for reading, writing or have an exception pending.

Wie lange bleibt folglich die "exception pending".
Sind das Überlegungen, die der Realität nahe kommen, oder in diesem Zusammenhang gegenstandslos ?
Wenn meine Schlussfolgerungen richtig sind, dann könnte man mit FHEM kein wirkliches, verlässliches Alarmsystem aufbauen.
Wie auch immer, dieser Tatbestand hat jedenfalls dazu geführt, dass wir im vergangenen Sommer Abends auf der Terrasse "ausgesperrt" wurden, da der Rolladen herunterfuhr, obwohl die Terrassentür geöffnet war; nur war dieser Zustandswechsel (Tür geöffnet) nicht gemeldet worden. Ich hatte zwar das Mobiltelefon mit und konnte das Hochfahrkommando geben, aber der WAF hat gelitten !!
Peter
Raspi 4B + RaZberry2 (Deb 10), FritzBox 7490;
AEOTec: KeyFobGen5: 1x;
Danfoss: Living Connect 2.51: 3x;
Fibaro: FGK: 10x: 3x; FGBS: 001: 8x, 222: 1x; FGMS001: 2x; FGR: 222: 3x, 223: 2x; FGRGBWM-441: 1x; FGBS: 222: 2x, 223: 2x,224: 1x;
Philio: PAN06-1A: 3x;

rudolfkoenig

ZitatDafür gibt es die bekannten Lösungsansätze, die alle darin bestehen, ein laufendes Programm zu unterbrechen, den Interrupt zu bedienen und dann das unterbrochene Programm wieder fortzusetzen.
Im Prinzip hast du recht, aber mit einem Betriebsystem wird sowas im Kernel erledigt, und fuer Benutzerprozesse anders dargestellt.

Die in FHEM verwendete Variante (grob vereinfacht!):
- mit dem "Aussenwelt" wird ueber Filedeskriptoren kommuniziert, z.Bsp. indem man /dev/ttyACM1 oeffnet, um mit dem ZWave-Controller zu reden.
- fhem.pl meldet alle Filedeskriptoren (FD) mit dem select Systemcall dem Kernel.
- der Kernel legt fhem.pl schlafen, solange auf keinem der FD Daten anstehen. Ob was zu lesen gibt, kriegt der Kernel selbst per Interrupt oder Pollen  oder "mir doch egal wie" mit.
- wenn Daten anstehen, wird fhem.pl aufgeweckt, und im Rueckgabewert vom select werden alle FD aufgezaehlt, wo fhem.pl was lesen darf, ohne sich zu blockieren, weil der Kernel fuer diese schon Daten in seinen internen Puffer gesammelt hat.
- fhem.pl entscheidet anhand dieser Rueckgabe, welches Modul zustaendig ist, und ruft dessen ReadFn auf. ReadFn darf genau einmal Daten lesen (sonst besteht Gefahr des Blockierens), und auf diese direkt reagieren oder die Daten zwischenpuffern, bis sie nochmal aufgerufen wird.

Select wird unter Linux und OSX fuer alle Arten von FD unterstuetzt, hier ist es also mit deiner Nomenklatur eher ein Interruptverfahren.
Unter Windows bedient select nur Netzwerk-Filedeskriptoren (da Windows den TCP/IP Stack vom BSD geklaut hat), die anderen (wie COM1:) muessen gepollt werden, weil das "urspruengliche Windows" kein select kennt. Deswegen ruft FHEM unter Windows das Modul eigene ReadyFn 10-mal die Sekunde auf.

Aber in beiden Faellen passiert das eigentliche Interrupt im Kernel, das OS bedient den USB Stack, und liest die Daten in seinen eigenen Puffer, unabhaengig davon, ob der Benutzerprozess das liest oder nicht. Hoechstens wenn die Kernel-Puffer vollaufen, werden keine Daten abgenommen. Es koennte sein, dass in diesem Fall der ZWave-Controller sich verklemmt. Das ist aber nur eine Theorie, die nachzuweisen waere. Eine Andere ist, dass der ZWave Controller unter Telegramm-Last sich verklemmt.

laserrichi

Sehr interessant,  da bei mir das Thema momentan wirklich gänzlich verschwunden ist.

Es hat sich an den Z-Wave Geräten nichts geändert.
Eventuell auch ein Zusammenhang mit der Perl Version und den installierten Patches ?

Folgende Version ist bei mir aktiv:
This is perl 5, version 24, subversion 1 (v5.24.1) built for arm-linux-gnueabihf-thread-multi-64int
(with 85 registered patches,
RaspberryPi 4 Bullseye,Homematic,Z-Wave,Rademacher Duofern,Signalduino,Fritz7590,ESPEasy,Tasmota,Robonect,Kameras,1-Wire,Modbus,Solar,Maranz,VU+,ulanzi tc001 mit awtrix light