OWX asynchron überarbeitet

[hexenmeister]

Hallo!

Nach dem heutigen Update hatte ich probleme mit meiner 1wir Installation. FHEM fuhr erst nach mehrmaligen harten "töten" hoch.
Im Log waren laufend Meldungen in der Art:

Code Auswählen Erweitern

2014.08.10 13:37:53.083 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:37:55.700 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:37:58.324 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:00.971 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:03.588 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:06.198 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16 0x01
2014.08.10 13:38:08.816 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:11.434 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:14.060 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16 0x44
2014.08.10 13:38:16.692 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:19.304 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:21.949 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:24.592 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16 0x44
2014.08.10 13:38:27.222 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:29.833 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:32.444 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:35.056 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:37.670 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:40.300 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:42.922 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:45.570 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:48.216 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
2014.08.10 13:38:50.833 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x5a 0x00 0x93
2014.08.10 13:38:51.407 1: OWX: 1-Wire bus OWio1: interface master DS2480 detected for the first time
2014.08.10 13:38:51.573 1: OWX: 1-Wire bus OWio2: interface master DS2480 re-detected


Das ist das letzte Stück. Irgendwann ging es dann doch. Mit ASYNC ging es sofort besser. Leider war der Adapter nach ein Paar Stunden Betrieb wohl nicht mehr ansprechbar. Keine Fehlermeldungen, die Werte wurden einfach nicht mehr aktualisiert.

Kann jemand ein Reim daraus machen?

[det.]

Hallo Hexenmeister,
schau mal in meinen letzten Post. Kann Deine Beobachtung zum Teil bestätigen, wobei bei meinem System definitiv nur die Thermometer Device betroffen sind, alle LCD, Switch, DS2438 funktionieren bzw. liefern weiter Werte.
Da ich parallel auf 2 RPI teste, wo der Effekt nicht auftritt - ist es mglw. ein Timingproblem der schnelleren Hardware?
Bei mir konnte ich die Sache umgehen, indem ich die Adapter auf dokik 0 und die Thermometer auf onread gesetzt habe. Ganz schön viel Arbeit, da jedes einzeln umgestellt werden muß, aber damit läuft es jetzt seit gestern Mittag stabil durch.

[hexenmeister]

Hallo det.,

danke für den TIp, muss ich ausprobieren.
An Timing habe ich auch schon gedacht. Als ob der Antwort von dem COntroller nicht (lange genung) abgewartet wird. Darau deutet auch die unterschiedliche Anzahl der Zahlen hinter "... answer was". Mal steht da nichts, mal 0x16, manchmal 0x16 0x44. Aber wenn es einmal geht, dann geht es.

[ntruchsess]

Im Log waren laufend Meldungen in der Art:

Code Auswählen Erweitern

2014.08.10 13:37:53.083 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x16
...

Das ist das letzte Stück. Irgendwann ging es dann doch. Mit ASYNC ging es sofort besser.

Da hat der Busmaster wohl seine Synchronisation auf die Geschwindigkeit der seriellen Schnittstelle verloren. Ein Neustart des Interfaces (Abziehen und wieder anstecken hätte vermutlich sofort geholfen. Dass es mit OWX_ASYNC dann ging hat einen Grund: Da habe ich das forcieren eines Resets mit Neusynchronisation eingebaut (funktioniert nur bei DS2480 die nicht über Netzwerk angebunden sind, weil für den Reset die Baudrate umgeschaltet werden muss). Im normalen OWX ist dieser Reset bei der Initialisierung (noch) nicht drin.

Leider war der Adapter nach ein Paar Stunden Betrieb wohl nicht mehr ansprechbar. Keine Fehlermeldungen, die Werte wurden einfach nicht mehr aktualisiert.

Da ich parallel auf 2 RPI teste, wo der Effekt nicht auftritt - ist es mglw. ein Timingproblem der schnelleren Hardware?
Bei mir konnte ich die Sache umgehen, indem ich die Adapter auf dokik 0 und die Thermometer auf onread gesetzt habe.

Das ist eine interessante Info, ich vermute mal, dass die DS18B20 hin und wieder Schwierigkeiten mit der bei 'dokick=1' parallel zur Temperaturwandung laufenden  Bussuche haben. (Bei OWX läuft das ja streng seriell). Auf schnellen Rechnern ist es wahrschienlicher, dass das tatsächlich parallel läuft. Da kann ich mal was am Timing drehen und die dokick-bussuche zeitlich von der Temparaturwandlung abkoppeln. Vieleicht wird's dann besser.
Und den Fehlerzähler des OWTHERM werde ich am Besten auch mal umbauen. Nach 5 Fehlern seit FHEM-start die Sensoren einfach abzuschalten ist nicht wirklich zielführend

Gruß,

Norbert

[hexenmeister]

Hallo Norbert,

danke für die Erklärung.
Auf die Idee den Adapter abzuziehen bin ich auch gekommen. Leider hat das nichts gebracht. Nur (mehrfache) FHEM Neustart brachte Besserung.

Grüße,

Alexander

[det.]

Und den Fehlerzähler des OWTHERM werde ich am Besten auch mal umbauen. Nach 5 Fehlern seit FHEM-start die Sensoren einfach abzuschalten ist nicht wirklich zielführend
Gruß,
Norbert

Hallo Norbert,
Fehlerzähler bei meinen DS1820 war immer 0. Was bedeutet das Alarmevent 5 min vor Ende der Vorstellung? Auch bei Verbose 4 hatte ich keinerlei Meldungen im LOG.

[ntruchsess]

Fehlerzähler bei meinen DS1820 war immer 0. Was bedeutet das Alarmevent 5 min vor Ende der Vorstellung?

Das bedeutet, dass die Devices beim Alarm-search geantwortet haben. Warum? Keine Ahnung, da kann ich nur mutmaßen - die Alarm-trigger-register der DS18B20 sind eigentlich im EEPROM und dürften nicht einfach mal so Ihren Zustand verlieren. Aber offensichtlich hat irgendwas die Sensoren so durcheinandergebracht, dass sie meinten eine Alarm-condition zu haben. Dazu reicht es natürlich auch, dass die AD-Wandlung gestört war (dann kommt typischerweise der Wert für 85°C raus -> Alarm).

Gruß,

Norbert

[cwagner]

Moin Norbert,

leider muss ich berichten, dass die Stabilität sich in meiner Konstellation wieder verschlechtert hat. 5 Tage die neue Konstellation, 5mal Abschuss des FHEM ohne nutzbare Infos im Log im laufenden Galopp.
Auffällig: Das Timing ist offenbar wieder kritischer - es gibt mehr Log-Einträge wegen fehlerhafter Bytes (aber mit anderen Zeilen und Modulbnamen) und

-NEU- fehlerhafter Alarm-Meldungen:

Code Auswählen Erweitern

2014.08.12 06:57:57 4: OWX_ASYNC_PT_Kick: Failure in alarm-search: OWX_DS2480 read timeout, bytes read: 13, expected: 18 at ./FHEM/OWX_DS2480.pm line 224.

2014.08.11 11:45:12 4: OWX_ASYNC_PT_Kick: Failure in search: OWX_DS2480: Search 2nd return has wrong parameter with length = 17 at ./FHEM/OWX_DS2480.pm line 359.
2014.08.11 15:14:52 4: OWX_ASYNC_PT_Kick: Failure in alarm-search: OWX_DS2480 read timeout, bytes read: 14, expected: 18 at ./FHEM/OWX_DS2480.pm line 224.


Im Einsatz aus dem SVN:

Code Auswählen Erweitern

# $Id: 21_OWAD.pm 6378 2014-08-07 22:01:18Z ntruchsess $
# $Id: 21_OWMULTI.pm 6379 2014-08-07 22:31:34Z ntruchsess $
# $Id: 21_OWSWITCH.pm 6379 2014-08-07 22:31:34Z ntruchsess $
# $Id: 21_OWTHERM.pm 6379 2014-08-07 22:31:34Z ntruchsess $
# $Id: 00_OWX.pm 6362 2014-08-04 21:08:27Z ntruchsess $
# $Id: 00_OWX_ASYNC.pm 6378 2014-08-07 22:01:18Z ntruchsess $
#

Herzliche Grüße

Christian

[det.]

... Dazu reicht es natürlich auch, dass die AD-Wandlung gestört war (dann kommt typischerweise der Wert für 85°C raus -> Alarm).
Gruß,
Norbert

Ich habe aber keine 85°C Fehler in meinen LOG's - und ohne dokick läuft es mit OWX_ASYNC auf dem Cubie seit Wochenende stabil.

[ntruchsess]

-NEU- fehlerhafter Alarm-Meldungen:

Code Auswählen Erweitern

2014.08.12 06:57:57 4: OWX_ASYNC_PT_Kick: Failure in alarm-search: OWX_DS2480 read timeout, bytes read: 13, expected: 18 at ./FHEM/OWX_DS2480.pm line 224.

EDIT: hab gerade gesehen, dass genau an der Stelle im OWX_DS2480 ja noch ein Bruchstück vom 'alten' timeoutcheck drin war. Das ist jetzt entfernt. Der entsprechende aktuelle TimeoutCheck ist im Rahmen des Protothreads-refactoring längst in den zentralen Scheduler (OWX_ASYNC_RunTasks) umgezogen.

-> Bitte testen: OWX_DS2480.pm (noch nicht im SVN, weil ich hier wg. Firewall gerade nur ins Github committen kann, alle anderen Files müssen der letzte SVN-stand sein).

EDIT 2:

Auf die Idee den Adapter abzuziehen bin ich auch gekommen. Leider hat das nichts gebracht. Nur (mehrfache) FHEM Neustart brachte Besserung.

o.g. timeoutcheck hatte möglicherweise auch eine Auswirkung auf die Initialisierung im OWX_ASYNC.
-> hier die zum verlinkten OWX_DS2480.pm passende OWX_SER.pm

Beides kommt irgendwann heute abend, wenn ich es selber getestet habe ins SVN, also morgen wie üblich per update...

EDIT 3: link auf OWX_SER.pm aktualisiert...

Gruß,

Norbert

[det.]

Hallo Norbert,
es ist wie verhext, auf dem RPI gehts mit Deinen verlinkten geänderten Dateien, auf dem CUBIE kommt:

Code Auswählen Erweitern

OWX_ASYNC_Init failed: Not a SCALAR reference at ./FHEM/OWX_SER.pm line 238.mit der Version

Code Auswählen Erweitern

# $Id: OWX_SER.pm 6392 2014-08-11 15:25:00Z ntruchsess $ läufts auch da.

[ntruchsess]

sorry, ein Tippfehler. Die Perlversion auf dem Pi hat das wohl akzeptiert, die auf dem Cubie nicht.

-> OWX_SER.pm

Gruß,

Norbert

[det.]

na kein Problem, dazu testen wir ja mit. Ist heute eben freudiges FHEM Neustarten angesagt!
Danke, jetzt geht es. Sag bitte bescheid, wenn ich dokick wieder einschalten soll.
Übrigens funktioniert inzwischen der Türkontakt mit dem DS2401 wie gewünscht.


dokick ist an - ich beobachte und schreibe Morgen, ob noch Werte kommen oder nicht.

[ntruchsess]

na schalt dokick doch mal ein - ich weiß ehrlich nicht genau, ob der heutige Patch da wirklich was hilft, weil ich nicht weiß, ob der von Christian gemeldete Timeout sachlich richtig (es wären tatsächlich keine Daten mehr gekommen), oder falsch (hat viel zu früh zugeschlagen) war. Auf meinem Testsystem macht das Timing ja (auch mit dokick) praktisch keine Probleme - aber das sagt wenig, wenn es um quasiparallele Verarbeitung geht ist das Timing ja immer Plattformabhängig.

Gruß,

Norbert

[ntruchsess]

zur Info: der heutige patch von OWX_SER und OWX_DS2480 ist jetzt im SVN.

Gruß,

Norbert