OWX_ASYNC & OWTHERM Timing auf "schnellen Rechnern" problematisch

Begonnen von fhem-challenge, 19 Juni 2014, 14:06:15

Vorheriges Thema - Nächstes Thema
Drucken
Nach unten Seiten1
Benutzer-Aktionen

fhem-challenge

19 Juni 2014, 14:06:15 Letzte Bearbeitung: 19 Juni 2014, 15:24:45 von fhem-challenge
Hallo,

angelehnt ein mein posting: http://forum.fhem.de/index.php/topic,22307.0.html

... scheint es immer noch Timingprobleme zu geben.

Meine Config:

Arduino (mega 2560) mit ConfigurableFirmata  via Ethernet <--> CubieTruck (FHEM mit OWX_ASYNC)

Daran mehrere DS18B20.

Problem:

Ich bekomme nur und ausschließlich Werte von den DS18B20, wenn ich beim "FRM" verbose=5 setze. Stelle ich Verbose <=4, funktioniert es beliebig oft reproduzierbar nicht.

Bei "verbose = 5"

...wenn ich die conversion triggere:

Code Auswählen
fhem> get Temp_D8A957040000 temperature
OWTHERM: Temp_D8A957040000.temperature => 36

... läuft alles wunderbar:

Logfile:
Code Auswählen
>>>
2014.06.19 14:50:06 5: Cmd: >get Temp_D8A957040000 temperature<
2014.06.19 14:50:06 5: FRM:>f0732d2d2830273d450000007b12001001402ff7
2014.06.19 14:50:06 5: SW: f0732d2d2830273d450000007b12001001402ff7
2014.06.19 14:50:06 5: FRM:<f073
2014.06.19 14:50:06 5: FRM:<432d120028
2014.06.19 14:50:06 5: FRM:<1130
2014.06.19 14:50:06 5: FRM:<49513f
2014.06.19 14:50:06 5: FRM:<7f0d
2014.06.19 14:50:06 5: FRM:<400805
2014.06.19 14:50:06 5: FRM:<f7e05d02
2014.06.19 14:50:06 5: AfterExecute: context: ProtoThreads=HASH(0x2c0e588), success: 1, reset: 1, owx_dev: 28.D8A957040000.7B, writedata: be, numread: 9, readdata: 2a024b467fff061051
2014.06.19 14:50:06 5: FRM:<e16202
2014.06.19 14:50:06 5: Triggering Temp_D8A957040000 (2 changes)
2014.06.19 14:50:06 5: Notify loop for Temp_D8A957040000 temperature: 34.625
2014.06.19 14:50:06 5: T: 34.62 &deg;C ▾
<<<



bei "verbose = 3" funktioniert es nicht mehr:

Code Auswählen
fhem> get Temp_D8A957040000 temperature
OWTHERM: Could not get values from device Temp_D8A957040000, return was 28.D8A957040000.7B has returned invalid data

Logfile:
Code Auswählen
>>>
2014.06.19 14:49:27 5: Cmd: >get Temp_D8A957040000 temperature<
2014.06.19 14:49:27 5: SW: f0732d2d2830273d450000007b12000801402ff7
2014.06.19 14:49:27 5: AfterExecute: context: ProtoThreads=HASH(0x2c1d4e0), success: 1, reset: 1, owx_dev: 28.D8A957040000.7B, writedata: be, numread: 9, readdata: 2a928cfefe0d20a2
<<<


Den gleichen Effekt habe ich auch bei Nutzung des "alten" OWX (anstelle OWX_ASYNC).

Anbei das Logfile bei "verbose=3" und dem via intervall=300 gesetzten, automatischen "Lesen":

Code Auswählen
2014.06.19 14:53:16 5: OWX_ASYNC_RunTasks: master task not finished, next executetime: 1403182397.39304
2014.06.19 14:53:16 5: OWX_ASYNC_RunTasks: master schedule next at 1403182397.393039
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_3EDA57040000
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_696157040000
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_997F9D040000
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_D8A957040000
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_F2E39D040000
2014.06.19 14:53:17 5: OWX_ASYNC_PT_Kick: doing tempConv for Temp_F7DA9D040000
2014.06.19 14:53:17 5: SW: f073402df7
2014.06.19 14:53:17 5: SW: f073442df7
2014.06.19 14:53:17 5: OWX_ASYNC_RunTasks: master finished task
2014.06.19 14:53:17 5: OWX_ASYNC_RunTasks: 28.F2E39D040000.74 schedule next at 1403182397.395921
2014.06.19 14:53:17 5: SW: f0732d2d2852053b450000005712002801402ff7
2014.06.19 14:53:17 5: OWX_ASYNC_RunTasks: 28.696157040000.57 schedule for timeout at 1403182399.420481
2014.06.19 14:53:17 5: Triggering Temp_3EDA57040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_3EDA57040000 present: 1
2014.06.19 14:53:17 5: Triggering Temp_696157040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_696157040000 present: 1
2014.06.19 14:53:17 5: Triggering Temp_997F9D040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_997F9D040000 present: 1
2014.06.19 14:53:17 5: Triggering Temp_D8A957040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_D8A957040000 present: 1
2014.06.19 14:53:17 5: Triggering Temp_F2E39D040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_F2E39D040000 present: 1
2014.06.19 14:53:17 5: Triggering Temp_F7DA9D040000 (1 changes)
2014.06.19 14:53:17 5: Notify loop for Temp_F7DA9D040000 present: 1
2014.06.19 14:53:17 5: AfterExecute: context: ProtoThreads=HASH(0x2c2ea58), success: 1, reset: 1, owx_dev: 28.696157040000.57, writedata: be, numread: 9, readdata: 35928cfefe1720ec
2014.06.19 14:53:17 3: OWX_ASYNC_RunTasks: 28.696157040000.57 Error running task: invalid data length, 8 instead of 9 bytes
2014.06.19 14:53:17 5: SW: f0732d2d287c683e450000004313003001402ff7
2014.06.19 14:53:17 5: OWX_ASYNC_RunTasks: 28.3EDA57040000.C3 schedule for timeout at 1403182399.641232
2014.06.19 14:53:19 3: OWX_ASYNC_RunTasks: 28.3EDA57040000.C3 task timed out
2014.06.19 14:53:19 5: OWX_ASYNC_RunTasks: 28.3EDA57040000.C3 TimeoutTime: 1403182399.641232, now: 1403182399.646593
2014.06.19 14:53:19 5: SW: f0732d2d286e6b6e490000006813003801402ff7
2014.06.19 14:53:19 5: OWX_ASYNC_RunTasks: 28.F7DA9D040000.E8 schedule for timeout at 1403182401.648964
2014.06.19 14:53:19 5: AfterExecute: context: ProtoThreads=HASH(0x2c2f388), success: 1, reset: 1, owx_dev: 28.F7DA9D040000.E8, writedata: be, numread: 9, readdata: 5e928cfefe052094
2014.06.19 14:53:19 3: OWX_ASYNC_RunTasks: 28.F7DA9D040000.E8 Error running task: invalid data length, 8 instead of 9 bytes
2014.06.19 14:53:19 5: SW: f0732d2d2830273d450000007b12004001402ff7
2014.06.19 14:53:19 5: OWX_ASYNC_RunTasks: 28.D8A957040000.7B schedule for timeout at 1403182401.675606
2014.06.19 14:53:21 3: OWX_ASYNC_RunTasks: 28.D8A957040000.7B task timed out
2014.06.19 14:53:21 5: OWX_ASYNC_RunTasks: 28.D8A957040000.7B TimeoutTime: 1403182401.675606, now: 1403182401.763072
2014.06.19 14:53:21 5: SW: f0732d2d28327e6b490000005913004801402ff7
2014.06.19 14:53:21 5: OWX_ASYNC_RunTasks: 28.997F9D040000.D9 schedule for timeout at 1403182403.766839
2014.06.19 14:53:21 5: AfterExecute: context: ProtoThreads=HASH(0x2c1d4e0), success: 1, reset: 1, owx_dev: 28.997F9D040000.D9, writedata: be, numread: 9, readdata: 95928cfefe172098
2014.06.19 14:53:21 3: OWX_ASYNC_RunTasks: 28.997F9D040000.D9 Error running task: invalid data length, 8 instead of 9 bytes
2014.06.19 14:53:21 5: SW: f0732d2d28640f6f490000007412005001402ff7
2014.06.19 14:53:21 5: OWX_ASYNC_RunTasks: 28.F2E39D040000.74 schedule for timeout at 1403182403.793458
2014.06.19 14:53:23 3: OWX_ASYNC_RunTasks: 28.F2E39D040000.74 task timed out
2014.06.19 14:53:23 5: OWX_ASYNC_RunTasks: 28.F2E39D040000.74 TimeoutTime: 1403182403.793458, now: 1403182403.880870



Woran könnte ich noch "drehen" ? ... irgendwo in der 00_OWX_ASYNC.pm ein 'sleep(1);' einzubauen, damits langsamer wird ;-) und ich das Timingproblem damit umgehe ...

Natürlich wäre es eine "Interims"-Lösung , verbose auf 5 stehen zu lassen, oder meine OW Umgebung auf einem langsameren Rechner (RasPi) auszulagern und via FHEM2FHEm zu koppeln, aber es gibt ja vielleicht eine bessere Lösung.

Ich bin momentan ratlos und suche nun einen Lösung, produktiv (verlässlicher) meine OW Themp-Sensoren einzubinden.


Viele Grüße!

Andreas

Prof. Dr. Peter Henning

#1
20 Juni 2014, 11:16:46
Schon mal das "alte" synchrone OWX probiert ?

LG

pah

fhem-challenge

#2
20 Juni 2014, 11:27:50 Letzte Bearbeitung: 20 Juni 2014, 11:41:05 von fhem-challenge
Zitat von: Prof. Dr. Peter Henning am 20 Juni 2014, 11:16:46
Schon mal das "alte" synchrone OWX probiert ?

LG

pah

Ja, auch hier habe ich vergleichbare Probleme.

Den OW-Bus konnte ich als Problem ausschliessen (das Problem persistiert unabhängig davon, ob ich nun meine 6 DS18B20 via ca. 4 Meter Kabel anbinde, oder die DS18B20 direkt via Steckbrett an dem Arduino anschliesse). Auch ist das Problem unabhängig von parasitär- oder real-Power.


EDIT 1:

Eine weitere Beobachtung: Der Arduino stürzt auch nach einger Zeit (unspezifisch) ab, wenn FHEM diesen "anspricht". Hardware Problem ist aus zu schließen , zwei Arudinos (Mega 2560) (sogar mit unterschiedlichen Powersupplies) stürzen ab. Meist dann, wenn ich die Module OWX(_ASYNC) oder OWTHERM, oder FHEM komplett neu starte, und FHEM dann aufgrund der bereits in der Config definierten DS18B20 mehere requests an den Arduino gehäuft schickt. Nun muss ich auch noch ein Watchdog einbauen, damit diese Arudino Abstürze abefangen werden, was bei einem Mega 2560 softwareseitig leider wg. des "buggy" bootloaders nicht trivial ist. Mit dem neuesten "ConfigurableFirmata" Sketch schein das Arduino Absturz Problem deutlich häufiger aufzutrenen, als mit dem älteren Sketch (von 2013). Ob hier Norbert eine Idee hat ??

Viele Grüße!

Andreas

ntruchsess

#3
26 Juni 2014, 22:39:28
ich hab mich mal dran gemacht einen dazu passenden Modultest für die perl-firmata zu schreiben (quasi einen minimalen Arduino-simulator in perl). Damit kann ich einen Fehler im Parser reproduzieren, der auftritt, wenn die Message nicht in einem Rutsch sondern häppchenweise empfangen wird. Das wird wohl die Ursache Deines Problems sein. Führt vermutlich auch auf langsameren Rechnern zu sporadischen Fehlern.
Jetzt da ich das reproduzieren kann wird es in Kürze auch einen Fix dazu geben.

Gruß,

Norbert

P.S.: die perl-firmata gibt's jetzt auch auf CPAN
while (!asleep()) {sheep++};

ntruchsess

#4
27 Juni 2014, 00:03:46
Fehler gefunden und gefixt (und auch ins SVN committed, also morgen per fhem-update verfügbar).

Bitte testen!

Gruß,

Norbert
while (!asleep()) {sheep++};

mcmuller

#5
30 Juni 2014, 16:15:32
@Norbert: Das vom TS beschriebene Problem hatte ich hier auch sporadisch, hab es aber auf meine "DINo"-Arduinos geschoben - seit dem Fix läufts problemlos!

Gruß,
Gregor

ntruchsess

#6
30 Juni 2014, 19:51:25
Zitat von: mcmuller am 30 Juni 2014, 16:15:32seit dem Fix läufts problemlos!

na das freut mich  :). Den Fix habe ich ja basierend auf einem synthetischen Test gemacht, der eine recht spezielle Situation nachstellt. Da ist es schön zu hören, dass es 'in freier Wildbahn' funktioniert ;-)

Gruß,

Norbert
while (!asleep()) {sheep++};

mcmuller

#7
30 Juni 2014, 19:53:33
Developer's Brot ist das Lob :-)

Gesendet von meinem XT890 mit Tapatalk

fhem-challenge

#8
02 Juli 2014, 15:00:31
Zitat von: ntruchsess am 27 Juni 2014, 00:03:46
Fehler gefunden und gefixt (und auch ins SVN committed, also morgen per fhem-update verfügbar).

Bitte testen!

Gruß,

Norbert

Hi Norbert,

ich war unterwegs und erst jetzt dazu gekommen, die neue "firmata" in meiner Umgebung zu testen.

bzgl. der Timingproblematik hat sich Einiges verbessert. Mit der "alten" OWX bekomme ich nun (unabhängig von verbose=5) immer alle Daten ohne Aussetzer  (seit 3 Tagen) auch auf dem "schnellen" cubietruck.

Mit der OWX_ASYNC habe ich allerdings noch Aussetzer. Ich werde noch mal mit der OWX_ASYNC und "onkick" testen, inwieweit es einen wirklichen Einfluss hat.

Viele Grüße!

Andreas


fhem-challenge

#9
23 Juli 2014, 13:19:44
Zitat von: fhem-challenge am 02 Juli 2014, 15:00:31
Hi Norbert,

ich war unterwegs und erst jetzt dazu gekommen, die neue "firmata" in meiner Umgebung zu testen.

bzgl. der Timingproblematik hat sich Einiges verbessert. Mit der "alten" OWX bekomme ich nun (unabhängig von verbose=5) immer alle Daten ohne Aussetzer  (seit 3 Tagen) auch auf dem "schnellen" cubietruck.

Mit der OWX_ASYNC habe ich allerdings noch Aussetzer. Ich werde noch mal mit der OWX_ASYNC und "onkick" testen, inwieweit es einen wirklichen Einfluss hat.

Viele Grüße!

Andreas


Nachtrag zu meinem Posting:

Seit ca. 1 Woche (also dem letztem OWX_ASYNC aus dem SVN von ca. 19.7.2014 +/- 1-3 Tage) ist mein, seit Existenz von OWX sowie OWX_ASYNC, vorhandenes Problem mit den "Aussetzern" bei "schnellen" Rechnern spontan verschwunden. Also irgend etwas am "neuen"OWX_ASYNC" seit Mitte Juli behebt das Problem.

Prima!

Ein Rückgang auf OWX_ASYNC Versionen vor Mitte Juli auf meinen FHEM Server(n) bringt auch die Probleme wieder, sodass ziemlich eindeutig nun das Problem mit der neuen Version behoben ist.


Ich werde (zur Sicherheit) die derzeitige OWX_ASYNC Version getrennt sichern, da nun alle für mich und meine Umgebung relevanten Dinge seit 1 Woche stabil laufen.

Viele Grüße!

Andreas
Drucken
Nach oben Seiten1
Benutzer-Aktionen