OWX asynchron überarbeitet

det. · 31 Mai 2014, 17:48:19

@all,
Gruß aus dem sonnigen Süden Europas. Dank überall free WIFI kann ich die Feuchte und Kälte in der Heimat von Ferne betrachten. Dank der Zurückumstellung von OWX_ASYNC auf OWX (sync) läuft mein FHEM ohne Abstürze mit dem Releasestand der Module von vor 8 Tagen stabil.

ntruchsess · 02 Juni 2014, 09:31:48

Zitat von: cwagner am 31 Mai 2014, 11:05:26
Code Auswählen Erweitern
2014.05.31 10:56:34 5: OWX_ASYNC_PT_Kick: doing tempConv for OWAD, tempConv: -
In AWAD habe ich gar keine Chance, doKick oder onKick zu setzen, oder übersehe ich da etwas? Ich bin dem Ratschlag gefolgt, alle Temperaturdevices grundsätzlich auf Kick zu stellen.

diese Logmeldung ist wohl etwas irreführend, da wollte ich nur sehen, welche Werte im 'tempConv'-attribut stehen (ist loglevel 5, also für debugging....). Das Außlesen der Temperaturwerte wird anschließend nur für die OWTHERM-devices mit tempConv 'onkick' durchgeführt, alle anderen Devices werden übersprungen.

EDIT: hab's grade so geändert, dass nur noch die auf 'onkick' konfigurierten OWTHERM-devices logged...

Gruß,

Norbert

cwagner · 02 Juni 2014, 11:14:38

Vielen Dank Norbert,

das hatte ich auch nur gemeldet, weil ich den Hintergrund der Logging-Einträge nicht kannte und sie nur offensichtlich unsinnig waren. Zugleich hatte ich die Hoffnung, vielleicht etwas zu finden, was hilft, die praktisch täglich stattfindenden Abstürze von FHEM bei Benutzung von OWX-ASYNC einzugrenzen. Irgendwann kommt halt die Zeile vom OWAD auf der Telnet-Konsole:

Code Auswählen

OWX_DS2480 read timeout, bytes read: 3, expected: 18 at ./FHEM/OWX_DS2480.pm line 153

und zack, weg ist es das FHEM. Der WAF ist jetzt im Sommer diesbezüglich nicht in Gefahr

Mir scheint, es gibt einen Zusammenhang mit rechenintensiven anderen Modulen wie update, PID20, STATISTICS oder STELLMOTOR, mit denen ich die Quote "einmal am Tage" locker auf "in der nächsten Stunde" treiben kann

Dabei sind Speicher und CPU-Auslastung (außer bei update) laut free oder top nicht unbedingt durchgängig auf Anschlag... Daraus leite ich das "Gefühl" ab, dass die asynchrone Verarbeitung (bei OWAD) etwas labil gegen Zeitverzögerungen sein könnte. Mein OWAD verarbeitet 4 Digitaleingänge (Spannung auf dem 1-Wire-Bus, Luftdruck, Infrarot-Strahlung, Helligkeit). Ich benutze für drei der vier Ports function zum Umrechnen der Werte. Er steht auf Interval 60 - sollte also den Bus nicht wirklich belasten.

Herzliche Grüße

Christian

Prof. Dr. Peter Henning · 05 Juni 2014, 18:56:32

Die asynchrone Version läuft (im Großen und Ganzen), doch die nächsten Dinge sind gerade um die Ecke gekommen. Die asynchrone Programmierung ist eines der aktuellen Themen in verschiedenen Sprachen. Getrieben wird das durch den derzeitigen Erfolg der Sprache Scala - und seit kurzer Zeit gibt es auch ein erstes Framework, das die Konzepte von "Futures" bzw. "Promises" in Perl abbildet.

https://metacpan.org/pod/Promises

Unter Verwendung von Promises sollte auch das asynchrone OWX sogar einfacher zu realisieren sein.

LG

pah

hexenmeister · 07 Juni 2014, 23:02:25

Moin!

Seit zwei Tage (seit update am 6.05.) habe ich kein funktionierendes 1wire mehr. Dafür eine Menge Meldungen im Log.
Jemand eine Idee, was hier falsch läuft und was man dagegen tun könnte?

Code Auswählen

2014.06.07 22:43:19.404 3: OWX_DS2480: Search 2nd return has wrong parameter with length = 17
2014.06.07 22:43:20.769 2: OWX_ASYNC: Error running task for 28.4B318B040000.09: invalid CRC
2014.06.07 22:43:20.780 2: OWX_ASYNC: Error running task for 28.DDDA7E040000.50: invalid CRC
2014.06.07 22:43:20.784 2: OWX_ASYNC: Error running task for 28.4C20BE040000.F4: invalid CRC
2014.06.07 22:43:20.868 2: OWX_ASYNC: Error running task for 28.B0F2BD040000.AE: invalid CRC
2014.06.07 22:43:20.992 2: OWX_ASYNC: Error running task for 28.E9018B040000.BF: invalid CRC
2014.06.07 22:43:21.111 2: OWX_ASYNC: Error running task for 28.3F6F5C040000.FD: invalid CRC
2014.06.07 22:43:21.115 2: OWX_ASYNC: Error running task for 28.1B285D040000.A0: invalid CRC
2014.06.07 22:43:21.306 2: OWX_ASYNC: Error running task for 28.7BAFBD040000.B0: invalid CRC
2014.06.07 22:43:21.417 2: OWX_ASYNC: Error running task for 28.B77C8A040000.8C: invalid CRC
2014.06.07 22:43:21.529 2: OWX_ASYNC: Error running task for 28.B5DCBD040000.1F: invalid CRC
2014.06.07 22:43:21.634 2: OWX_ASYNC: Error running task for 28.BFF391040000.25: invalid CRC
2014.06.07 22:43:21.738 2: OWX_ASYNC: Error running task for 28.D7EA91040000.C8: invalid CRC
2014.06.07 22:43:21.763 2: OWX_ASYNC: Error running task for 28.B6A25C040000.4F: invalid CRC
2014.06.07 22:43:21.874 2: OWX_ASYNC: Error running task for 28.F58B8A040000.60: invalid CRC
2014.06.07 22:43:22.067 2: OWX_ASYNC: Error running task for 28.45128B040000.AC: invalid CRC
2014.06.07 22:43:22.092 2: OWX_ASYNC: Error running task for 28.5D4BBE040000.F9: invalid CRC
2014.06.07 22:43:22.213 2: OWX_ASYNC: Error running task for 28.19065D040000.94: invalid CRC
2014.06.07 22:43:22.302 1: Perfmon: possible freeze starting at 22:43:21, delay is 1.301
2014.06.07 22:43:22.326 2: OWX_ASYNC: Error running task for 28.4A838A040000.7D: invalid CRC

Edit:
Nach der Änderung auf synchron habe ich

Code Auswählen


2014.06.07 23:18:01.514 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:02.091 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:02.668 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:03.244 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:03.822 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:04.399 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:04.976 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:05.553 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:06.130 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:06.706 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:07.283 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:07.860 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:08.441 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:09.018 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:09.595 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91
2014.06.07 23:18:10.172 1: OWX: 1-Wire bus OWio1: interface not found, answer was 0x17 0x8b 0x5b 0xad 0x91

Ich gehe also meine Hardware checken

*grrr*

Edit2:
Abziehen, einstecken, geht alles wieder... Sorry für die verfrühte Meldung... und danke!
Trotzdem wäre es spannend zu wissen, was das war. So hat sich bei mir der 2480 noch nie verschlückt

Grüße,

Alexander

ntruchsess · 14 Juni 2014, 00:45:21

hab endlich mal etwas Zeit gefunden am OWX_ASYNC zu arbeiten. Hab das Scheduling der Protothreads etwas refactored. Braucht jetzt weniger CPU, weil es die Protothreads nicht mehr sinnlos pollt, sondern nur wenn tatsächlich Daten kommen (oder ein Timer abgelaufen ist). Ist ins SVN committed und damit per update beziehbar.

Wirkt sich allerdings erst mal nur mit einem DS2480-Busmaster spürbar aus. Die 'freezes', in Verbindung mit FRM sind leider immer noch da, da muss ich noch ran. Leider komme ich vorraussichtlich aber erst in einer Woche dazu daran weiter zu machen.

Gruß,

Norbert

det. · 15 Juni 2014, 13:16:37

Hallo Norbert,
Danke für die Weiterentwicklung. Gestern produktiv wieder auf ASYNC umgestellt (und inzwischen leider wieder zurück). Das Problem, dass nach Tageswechsel die Serverlast auf 100% steigt und FHEM danach abschmiert ist weg. Von den 2 DS2480 Busmastern lieferte der ohne OWCOUNT Device heute noch regelmäßig Werte, der andere bis Mitternacht - danach nicht mehr. Allerdings ohne FHEM Absturz. Da ich das Loglevel wegen der OWSWITCH auf verbose 0 stehen habe, kann ich leider mit keinerlei weitergehenden Infos dienen.

cwagner · 15 Juni 2014, 19:02:35

Hi Norbert,
auch von mir vor allem Danke für die viele Arbeit, die Du in das Projekt steckst. Ein Status nach dem Update: Einen Tag lang habe ich OWX_ASYNC eingesetzt mit 12 Temperaturfühlern, 8 Switchen, und zwei AD-Wandlern - die zuvor beschriebenen Vorteile (weniger Systemlast, damit schnellere Reaktion ist definitiv hilfreich vor allem für Steuerungsaufgaben) sind sofort bemerkbar.

Leider wurde wieder rund ein Dutzend Mal FHEM beendet auf meiner Fritzbox! Letzte Meldung auf Telnet war immer wieder das Modul OWX_DS2480
OWX_DS2480 read timeout, bytes read: 13, expected: 14 at ./FHEM/OWX_DS2480.pm line 157.

Diese Zeile beginnt ja mit dem bezeichnenden Befehl die!

Mal stirbt FHEM schon nach wenigen Minuten, mal erst nach Stunden. Aber mehr als 5,6 Stunden kriege ich nur mit OWX statt OWX_ASNC hin.

Wenn ich irgendetwas tun kann, um bessere Informationen zur Fehlersuche zu liefern, lass' es mich bitte wissen.

Grüße Christian

hexenmeister · 16 Juni 2014, 22:52:41

Hallo!

Grundsätzlich läuft ASYNC-Modul in meiner Installation seit Tagen ganz gut.
Was mir jetzt aufgefallen ist: das Modul mag es nicht, wenn man im Betrieb den Adapter abzieht:

Code Auswählen

OWX_ASYNC_RunTasks: master Error running task: OWX_DS2480: Write incomplete undefined not equal 2
Danach ist FHEM weg.

Meine Installation: DS2480b (mit einem PL2303 USB-UART) und 18 Stück DS18b20 Sensoren.

Grüße,

Alexander

Starkstrombastler · 17 Juni 2014, 00:15:48

Hallo,

OWX_ASYNC läuft immer besser, inzwischen mit ca. 30 Devices bei ca. 100m Buslänge. Das hatte ich mit der synchronen Version bei Weitem nicht geschafft. Mein Kompliment an Norbert.

Allerdings stören schon seit geraumer Zeit SEHR LANGE Startzeiten von fhem. Jetzt ist mir aufgefallen, dass bei dem erstmaligen Laden der diversen OWX-Module ca. 1-2 Minuten "tatenlos" verstreichen. Hier ein Auszug aus dem Logfile:

2014.06.16 23:16:07.781 1: Including ./FHEM/myOW.cfg
2014.06.16 23:18:07.638 3: OWTHERM: Device TaE defined.
2014.06.16 23:18:07.674 3: OWTHERM: Device TaGH defined.
2014.06.16 23:18:07.706 3: OWTHERM: Device TaTo defined.
2014.06.16 23:18:07.743 3: OWTHERM: Device TaTu defined.
2014.06.16 23:18:07.777 3: OWTHERM: Device TiAR defined.
2014.06.16 23:18:07.811 3: OWTHERM: Device THLab defined.
2014.06.16 23:18:07.853 3: OWTHERM: Device THWW defined.
2014.06.16 23:18:07.888 3: OWTHERM: Device THWWSpS defined.
2014.06.16 23:18:07.922 3: OWTHERM: Device THWWSpO defined.
2014.06.16 23:18:07.958 3: OWTHERM: Device THWWZirkRL defined.
2014.06.16 23:18:07.992 3: OWTHERM: Device THVL defined.
2014.06.16 23:18:08.026 3: OWTHERM: Device THRL defined.
2014.06.16 23:18:08.062 3: OWTHERM: Device THR41 defined.
2014.06.16 23:18:08.096 3: OWTHERM: Device THR42 defined.
2014.06.16 23:18:08.134 3: OWTHERM: Device THR43 defined.
2014.06.16 23:18:08.171 3: OWTHERM: Device THR44 defined.
2014.06.16 23:18:08.205 3: OWTHERM: Device THR45 defined.
2014.06.16 23:18:08.238 3: OWTHERM: Device THR46 defined.
2014.06.16 23:18:08.273 3: OWTHERM: Device TKRL defined.
2014.06.16 23:18:08.306 3: OWTHERM: Device TKVL defined.
2014.06.16 23:18:08.336 3: OWTHERM: Device TLm defined.
2014.06.16 23:18:08.369 3: OWTHERM: Device TWi defined.
2014.06.16 23:18:08.398 3: OWTHERM: Device TWo defined.
2014.06.16 23:18:08.428 3: OWTHERM: Device _T_D4142c defined.
2014.06.16 23:18:08.463 3: OWTHERM: Device _TCnt4 defined.
2014.06.16 23:18:08.491 3: OWTHERM: Device _TUmwS defined.
2014.06.16 23:18:08.519 3: OWTHERM: Device _Txxx defined.
2014.06.16 23:19:27.360 3: OWAD: Device OWX_Analog_1 defined.
2014.06.16 23:19:27.402 3: OWAD: Device OWX_Analog_2 defined.
2014.06.16 23:20:39.870 3: OWSWITCH: Device CounterGasSwM defined.
2014.06.16 23:20:39.896 3: OWSWITCH: Device Counter4Switch defined.
2014.06.16 23:22:27.390 3: OWCOUNT: Device CounterGas defined.
2014.06.16 23:22:27.438 3: OWCOUNT: Device Counter4 defined.
2014.06.16 23:22:30.770 2: eventTypes: loaded 3369 events from log/eventTypes.txt

An den Definitionen habe ich nicht herumgefummelt, nur der Übersichtlichkeit wegen in eine Include-cfg verschoben.

Das Starten dauert so insgesamt ca. 7 Minuten, was ist da los?

hexenmeister · 17 Juni 2014, 01:09:21

ZitatAllerdings stören schon seit geraumer Zeit SEHR LANGE Startzeiten von fhem.

Hm, bei mir auch so...

cwagner · 17 Juni 2014, 06:05:56

Zitat von: Starkstrombastler am 17 Juni 2014, 00:15:48

Allerdings stören schon seit geraumer Zeit SEHR LANGE Startzeiten von fhem. Jetzt ist mir aufgefallen, dass bei dem erstmaligen Laden der diversen OWX-Module ca. 1-2 Minuten

Das kann ich bestätigen: Bei mir sind es OWAD, OWSWITCH und OWMULTI, die übrigens auch im synchronen Modus - da sind es jeweils 70+ Sekunden für jedes der drei Module "Wartezeit". Also mehr als 2 Intervalle (bei mir aktuell 30 Sekunden).
OWTHERM liegt bei etwa 50 Sekunden - was in Summe bei 4 Modulen (ziemlich unabhängig, wie viele Devices die betreuen, bei mir sind es derzeit 14) eine Verlängerung der Startzeit von rund 5 Minuten bedeutet.

Christian

Prof. Dr. Peter Henning · 19 Juni 2014, 13:09:04

Gibt es diese lange Startzeit auch, wenn die Devices vorher nicht definiert sind ? OWX sucht alles, was er auf dem Bus finden kann und legt es automatisch an. Würde bei der Fehlersuche helfen, das mal zu testen.

LG

pah

cwagner · 19 Juni 2014, 23:48:36

Zitat von: Prof. Dr. Peter Henning am 19 Juni 2014, 13:09:04
Gibt es diese lange Startzeit auch, wenn die Devices vorher nicht definiert sind ? OWX sucht alles, was er auf dem Bus finden kann und legt es automatisch an. Würde bei der Fehlersuche helfen, das mal zu testen.

Habe es mit OWAD, OWTHERM, OWSWITCH ausprobiert: Die Startzeit ist auch dann gleich lang, wenn die Devices angelegt werden. Sie entsteht bei dfer Initialisierung des Devices, die einzelnen Fühler werden dann zack,zack erkannt.

Herzliche Grüße

Christian

Starkstrombastler · 20 Juni 2014, 06:34:27

Zitat von: Prof. Dr. Peter Henning am 19 Juni 2014, 13:09:04
Gibt es diese lange Startzeit auch, wenn die Devices vorher nicht definiert sind ?

Ja, ich kann dies bestätigen. Die Zeiten beim Start mit definierten Devices und ohne Definition variieren zwar um einige Sekunden, die Größenordnung bleibt aber gleich und beträgt beim erstmaligen Aufruf von...
DS2480 ca. 80 Sekunden
OWAD ca. 85 Sek.
OWTHERM ca. 55 Sek.
OWSWITCH ca. 75 Sek.
OWCOUNT ca. 110 Sek.

Zitat von: Prof. Dr. Peter Henning am 19 Juni 2014, 13:09:04
OWX sucht alles, was er auf dem Bus finden kann und legt es automatisch an.

Nachdem alle Devices aus der .CFG definiert sind, findet OWX angeblich noch ein Device

Code Auswählen

2014.06.20 00:22:37.650 3: OWTHERM: Device OWX_28_E2C0E0040000 defined.
Dies dauert ca. 6 Sekunden. Dieses Device existiert aber nicht wirklich.