OWX asynchron überarbeitet

ntruchsess · 21 Mai 2014, 21:43:27

Zitat von: det. am 21 Mai 2014, 18:37:59
FHEM läuft leider bei mir seit der Umstellung auf Async OWX nicht stabil durch[...]. Da ich am Wochenende in Urlaub will und meine Mieter ohne WW Zirkulation wären bei abgestürztem FHEM, was soll ich tun?

Das mit der Systemlast gefällt mir nicht, das ist bei mir nicht so... Du hast doch die ganzen LCD-aufrufe auf 'set XYZ...' umgebaut, ist das oft drin, bzw. wird das (oder andere 'set XYZ...'-kommandos an OW-Frontendmodulen) oft aufgerufen? Die 'set'-kommandos der Frontendmodule laufen ja synchron - da wird der aktuelle Protothread so lange aufgerufen bis er durch ist, das macht in dem Moment nahezu 100% Systemlast. Das ist auch ein Punkt, der noch mal überarbeitet gehört, aber da habe ich angenommen, dass das im Regelbetrieb nicht oft passiert, sondern nur, wenn jemand am Webinterface rumspielt (und eben die Ergebnisse seines Handelns auch sofort sehen will - sonst könnte man 'set' auch genausogut asynchron laufen lassen, dann gäbe es halt keine unmittelbar sichtbare Änderung, weil die ja asynchron später käme).

Läuft es mit synchronem OWX (gleiche config, die Frontendmodule sind ja abwärtskompatibel) stabil? Wenn nein, dann spiel den letzten Stand wieder ein, der bei Dir stabil lief und teste nach dem Urlaub weiter. Vieleicht ist bis dahin ja schon alles in Butter

Gruß,

Norbert

ntruchsess · 21 Mai 2014, 22:50:48

Zitat von: cwagner am 21 Mai 2014, 21:42:20
habe nun den Debug-Modus eingeschaltet und mit Verbose=5 aufgezeichnet. Mir scheint, dass das Ereignis in dem Log-Auszug mehrfach vorkommt und hoffe, dass es Dir hilft.

danke Dir, ich seh nur grad, dass die gewünschte Logzeile in OWX_DS2480.pm erst mit $owx_async_debug=3; aktiv geworden wäre. Hab grade das Debug-logging in der OWX_DS2480.pm ein bischen dafür angepasst. $owx_async_debug kann wieder auf 0, verbose des OWX_ASYNC-devices auf 5 reicht. Ist ins SVN committed.

Damit sollten die Logmeldungen etwa so aussehen:

Code Auswählen


2014.05.21 22:47:37 5: OWX_Executor: item ProtoThreads=HASH(0x31ff4c8) for 26.BE5E7B010000.D5 eligible to run
2014.05.21 22:47:37 5: OWX_DS2480.query sending out: e3c5
2014.05.21 22:47:37 5: OWX_DS2480.query sending out: e15526be5e7b010000d5b800
2014.05.21 22:47:37 5: OWX_DS2480 read: After loop no. 77 received: cd5526be5e7b010000d5b800
2014.05.21 22:47:37 5: AfterExecute: context: ProtoThreads=HASH(0x31ff4c8), success: 1, reset: 1, owx_dev: 26.BE5E7B010000.D5, writedata: b800, numread: 0, readdata:

(das 'query' und 'read' ist das, was ich bei dem Fehler gerne sehen würde...)

Gruß,

Norbert

P.S. Logausgaben am besten in als

Code Auswählen

[code] einfügen oder (wenn sehr lang) ggf als Datei anhängen

cwagner · 21 Mai 2014, 23:11:45

Norbert, zu query-Zeilen kommt es bei mir anscheinend nicht. Folgendes mit der

_OWX_ASYNC.pm aus dem SVN von heute (r5922):

Code Auswählen

2014.05.21 23:02:09 5: OWX_Executor: command 1 eligible to run
2014.05.21 23:02:09 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.21 23:02:09 5: OWX_Executor: command 2 eligible to run
2014.05.21 23:02:09 5: OWX_SER::Search: new alarm device found 29.68980C000000.DA
2014.05.21 23:02:09 3: OWX_DS2480: Search 2nd return has wrong parameter with length = 17
2014.05.21 23:02:09 5: OWX_Executor: item ProtoThreads=HASH(0x18485b0) for --- eligible to run
2014.05.21 23:02:09 5: AfterExecute: context: ProtoThreads=HASH(0x18485b0), success: 1, reset: 1, owx_dev: undef, writedata: 44, numread: 0, readdata: 
2014.05.21 23:02:10 5: OWX_Executor: item ProtoThreads=HASH(0x1b49080) for 28.1307AC040000.68 eligible to run
2014.05.21 23:02:10 5: AfterExecute: context: ProtoThreads=HASH(0x1b49080), success: 1, reset: 1, owx_dev: 28.1307AC040000.68, writedata: be, numread: 9, readdata: 47011e0a7fff09109e
2014.05.21 23:02:10 5: OWX_Executor: item ProtoThreads=HASH(0x1b33d10) for 28.CA0FAC040000.04 eligible to run
2014.05.21 23:02:10 5: AfterExecute: context: ProtoThreads=HASH(0x1b33d10), success: 1, reset: 1, owx_dev: 28.CA0FAC040000.04, writedata: be, numread: 9, readdata: ec001e0a7fff0410ff
2014.05.21 23:02:10 5: OWX_Executor: item ProtoThreads=HASH(0x184d938) for 10.541E0B000800.35 eligible to run
2014.05.21 23:02:10 5: AfterExecute: context: ProtoThreads=HASH(0x184d938), success: 1, reset: 1, owx_dev: 10.541E0B000800.35, writedata: be, numread: 9, readdata: 77004619ffff0810ff
2014.05.21 23:02:10 5: OWX_Executor: item ProtoThreads=HASH(0x1846258) for 10.787E83020800.65 eligible to run
2014.05.21 23:02:10 5: AfterExecute: context: ProtoThreads=HASH(0x1846258), success: 1, reset: 1, owx_dev: 10.787E83020800.65, writedata: be, numread: 9, readdata: 48003809ffff0a109f
2014.05.21 23:02:10 5: OWX_Executor: item ProtoThreads=HASH(0x1b459c8) for 28.810671010000.D3 eligible to run
2014.05.21 23:02:10 5: AfterExecute: context: ProtoThreads=HASH(0x1b459c8), success: 1, reset: 1, owx_dev: 28.810671010000.D3, writedata: be, numread: 9, readdata: 6b0346087fff051032
2014.05.21 23:02:11 5: OWX_Executor: item ProtoThreads=HASH(0x1b51918) for 28.905F9B010000.8B eligible to run
2014.05.21 23:02:11 5: AfterExecute: context: ProtoThreads=HASH(0x1b51918), success: 1, reset: 1, owx_dev: 28.905F9B010000.8B, writedata: be, numread: 9, readdata: d1001e057fff0f1033
2014.05.21 23:02:11 5: OWX_Executor: item ProtoThreads=HASH(0x1b49020) for 28.0E37AC040000.FD eligible to run
2014.05.21 23:02:11 5: AfterExecute: context: ProtoThreads=HASH(0x1b49020), success: 1, reset: 1, owx_dev: 28.0E37AC040000.FD, writedata: be, numread: 9, readdata: 59011e0a7fff0710af
2014.05.21 23:02:11 5: OWX_Executor: item ProtoThreads=HASH(0x1b42130) for 28.AEE870010000.B6 eligible to run
2014.05.21 23:02:11 5: AfterExecute: context: ProtoThreads=HASH(0x1b42130), success: 1, reset: 1, owx_dev: 28.AEE870010000.B6, writedata: be, numread: 9, readdata: 7b0137037fff0510c3
2014.05.21 23:02:11 5: OWX_Executor: item ProtoThreads=HASH(0x1b9dad0) for 28.A8A49B010000.11 eligible to run
2014.05.21 23:02:11 5: AfterExecute: context: ProtoThreads=HASH(0x1b9dad0), success: 1, reset: 1, owx_dev: 28.A8A49B010000.11, writedata: be, numread: 9, readdata: 27055a087fff0910a1
2014.05.21 23:02:11 5: OWX_Executor: item ProtoThreads=HASH(0x1b77bd8) for 10.0576A8020800.6D eligible to run
2014.05.21 23:02:11 5: AfterExecute: context: ProtoThreads=HASH(0x1b77bd8), success: 1, reset: 1, owx_dev: 10.0576A8020800.6D, writedata: be, numread: 9, readdata: 87005a08ffff08104f
2014.05.21 23:02:36 5: OWX_Executor: item ProtoThreads=HASH(0x1b8a158) for 29.68980C000000.da eligible to run
2014.05.21 23:02:36 5: AfterExecute: context: ProtoThreads=HASH(0x1b8a158), success: 1, reset: 1, owx_dev: 29.68980C000000.da, writedata: f08800, numread: 10, readdata: f7f7ff000088ffff2706
2014.05.21 23:02:37 5: OWX_Executor: item ProtoThreads=HASH(0x1848bc0) for 20.0C2C0C000000.59 eligible to run
2014.05.21 23:02:37 5: AfterExecute: context: ProtoThreads=HASH(0x1848bc0), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: 3c0f00ffff, numread: 0, readdata: 
2014.05.21 23:02:37 5: OWX_Executor: item ProtoThreads=HASH(0x1848bc0) for 20.0C2C0C000000.59 eligible to run
2014.05.21 23:02:37 5: AfterExecute: context: ProtoThreads=HASH(0x1848bc0), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0000, numread: 10, readdata: a9fa6f02af029ae65759
2014.05.21 23:02:37 5: OWX_Executor: item ProtoThreads=HASH(0x1b9dd30) for 20.0C2C0C000000.59 eligible to run
2014.05.21 23:02:37 5: AfterExecute: context: ProtoThreads=HASH(0x1b9dd30), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa1000, numread: 10, readdata: f5ff00b900b900ff11ba
2014.05.21 23:02:37 5: OWX_Executor: item ProtoThreads=HASH(0x1b1d778) for 20.0C2C0C000000.59 eligible to run
2014.05.21 23:02:37 5: AfterExecute: context: ProtoThreads=HASH(0x1b1d778), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0800, numread: 10, readdata: 0001000100010001e0cf
2014.05.21 23:02:39 5: OWX_Executor: command 1 eligible to run
2014.05.21 23:02:39 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.21 23:02:39 5: OWX_Executor: command 2 eligible to run
2014.05.21 23:02:39 5: OWX_SER::Search: new alarm device found 29.68980C000000.DA
2014.05.21 23:02:39 5:  Alarms = 29.68980C000000.DA
2014.05.21 23:02:39 5: OWX_Executor: item ProtoThreads=HASH(0x1b96bc8) for --- eligible to run
2014.05.21 23:02:39 5: AfterExecute: context: ProtoThreads=HASH(0x1b96bc8), success: 1, reset: 1, owx_dev: undef, writedata: 44, numread: 0, readdata: 
2014.05.21 23:02:40 5: OWX_Executor: item ProtoThreads=HASH(0x1852630) for 28.1307AC040000.68 eligible to run
2014.05.21 23:02:40 5: AfterExecute: context: ProtoThreads=HASH(0x1852630), success: 1, reset: 1, owx_dev: 28.1307AC040000.68, writedata: be, numread: 9, readdata: 47011e0a7fff09109e
2014.05.21 23:02:40 5: OWX_Executor: item ProtoThreads=HASH(0x1a6e020) for 28.CA0FAC040000.04 eligible to run
2014.05.21 23:02:40 5: AfterExecute: context: ProtoThreads=HASH(0x1a6e020), success: 1, reset: 1, owx_dev: 28.CA0FAC040000.04, writedata: be, numread: 9, readdata: ec001e0a7fff0410ff
2014.05.21 23:02:40 5: OWX_Executor: item ProtoThreads=HASH(0x1b1a1e0) for 10.541E0B000800.35 eligible to run
2014.05.21 23:02:40 5: AfterExecute: context: ProtoThreads=HASH(0x1b1a1e0), success: 1, reset: 1, owx_dev: 10.541E0B000800.35, writedata: be, numread: 9, readdata: 77004619ffff0810ff
2014.05.21 23:02:40 5: OWX_Executor: item ProtoThreads=HASH(0x1ccc078) for 10.787E83020800.65 eligible to run
2014.05.21 23:02:40 5: AfterExecute: context: ProtoThreads=HASH(0x1ccc078), success: 1, reset: 1, owx_dev: 10.787E83020800.65, writedata: be, numread: 9, readdata: 48003809ffff0910ca
2014.05.21 23:02:40 5: OWX_Executor: item ProtoThreads=HASH(0x1b2bc00) for 28.810671010000.D3 eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x1b2bc00), success: 1, reset: 1, owx_dev: 28.810671010000.D3, writedata: be, numread: 9, readdata: 6b0346087fff051032
2014.05.21 23:02:41 5: OWX_Executor: item ProtoThreads=HASH(0x184d948) for 28.905F9B010000.8B eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x184d948), success: 1, reset: 1, owx_dev: 28.905F9B010000.8B, writedata: be, numread: 9, readdata: d1001e057fff0f1033
2014.05.21 23:02:41 5: OWX_Executor: item ProtoThreads=HASH(0x1b390c8) for 28.0E37AC040000.FD eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x1b390c8), success: 1, reset: 1, owx_dev: 28.0E37AC040000.FD, writedata: be, numread: 9, readdata: 59011e0a7fff0710af
2014.05.21 23:02:41 5: OWX_Executor: item ProtoThreads=HASH(0x1b7a280) for 28.AEE870010000.B6 eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x1b7a280), success: 1, reset: 1, owx_dev: 28.AEE870010000.B6, writedata: be, numread: 9, readdata: 7b0137037fff0510c3
2014.05.21 23:02:41 5: OWX_Executor: item ProtoThreads=HASH(0x1b8f230) for 28.A8A49B010000.11 eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x1b8f230), success: 1, reset: 1, owx_dev: 28.A8A49B010000.11, writedata: be, numread: 9, readdata: 27055a087fff0910a1
2014.05.21 23:02:41 5: OWX_Executor: item ProtoThreads=HASH(0x1b94670) for 10.0576A8020800.6D eligible to run
2014.05.21 23:02:41 5: AfterExecute: context: ProtoThreads=HASH(0x1b94670), success: 1, reset: 1, owx_dev: 10.0576A8020800.6D, writedata: be, numread: 9, readdata: 86005a08ffff0910c8
2014.05.21 23:03:06 5: OWX_Executor: item ProtoThreads=HASH(0x1b7f478) for 29.68980C000000.da eligible to run
2014.05.21 23:03:06 5: AfterExecute: context: ProtoThreads=HASH(0x1b7f478), success: 1, reset: 1, owx_dev: 29.68980C000000.da, writedata: f08800, numread: 10, readdata: f7f7ff000088ffff2706
2014.05.21 23:03:08 5: OWX_ASYNC_Set request OWio1 FF ?
2014.05.21 23:03:16 5: OWX_Executor: command 1 eligible to run

Hoffe, ich habe da einen Abschnitt erwischt, der nützlich ist. Lasse jetzt Verbose=5 die Nacht laufen bzw. so lange laufen, bis FHEM abschmiert... Im Moment kann man sich das ja erlauben, geheizt wird ja von außen.

Christian

ntruchsess · 21 Mai 2014, 23:37:07

das logging habe ich in der OWX_DS2480 (r5926) geändert.

cwagner · 22 Mai 2014, 07:52:38

Guten Morgen,

jo, jetzt habe ich query-Zeilen im Angebot

Hier ein Stück:

Code Auswählen

2014.05.22 07:36:30 5: OWX_Executor: command 1 eligible to run
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e1f0e3b5
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:36:30 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.22 07:36:30 5: OWX_DS2480 read: After loop no. 7 received: cdf04109a000a008a0000000000000008222
2014.05.22 07:36:30 5: OWX_Executor: command 2 eligible to run
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:36:30 5: OWX_DS2480 read: After loop no. 4 received: cdec6800000000000000000000000000000000
2014.05.22 07:36:30 3: OWX_DS2480: Search 2nd return has wrong parameter with length = 17
2014.05.22 07:36:30 5: OWX_Executor: item ProtoThreads=HASH(0x185e718) for --- eligible to run
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e1cc44
2014.05.22 07:36:30 5: OWX_DS2480 read: After loop no. 4 received: cdcc44
2014.05.22 07:36:30 5: AfterExecute: context: ProtoThreads=HASH(0x185e718), success: 1, reset: 1, owx_dev: undef, writedata: 44, numread: 0, readdata: 
2014.05.22 07:36:31 5: OWX_Executor: item ProtoThreads=HASH(0x1b2c0a0) for 28.1307AC040000.68 eligible to run
2014.05.22 07:36:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:31 5: OWX_DS2480.query sending out: e155281307ac04000068beffffffffffffffffff
2014.05.22 07:36:31 5: OWX_DS2480 read: After loop no. 17 received: cd55281307ac04000068be44011e0a7fff0c10a4
2014.05.22 07:36:31 5: AfterExecute: context: ProtoThreads=HASH(0x1b2c0a0), success: 1, reset: 1, owx_dev: 28.1307AC040000.68, writedata: be, numread: 9, readdata: 44011e0a7fff0c10a4
2014.05.22 07:36:31 5: OWX_Executor: item ProtoThreads=HASH(0x1b29678) for 28.CA0FAC040000.04 eligible to run
2014.05.22 07:36:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:31 5: OWX_DS2480.query sending out: e15528ca0fac04000004beffffffffffffffffff
2014.05.22 07:36:31 5: OWX_DS2480 read: After loop no. 14 received: cd5528ca0fac04000004beea001e0a7fff0610fd
2014.05.22 07:36:31 5: AfterExecute: context: ProtoThreads=HASH(0x1b29678), success: 1, reset: 1, owx_dev: 28.CA0FAC040000.04, writedata: be, numread: 9, readdata: ea001e0a7fff0610fd
2014.05.22 07:36:31 5: OWX_Executor: item ProtoThreads=HASH(0x1b29598) for 10.541E0B000800.35 eligible to run
2014.05.22 07:36:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e15510541e0b00080035beffffffffffffffffff
2014.05.22 07:36:32 5: OWX_DS2480 read: After loop no. 13 received: cd5510541e0b00080035be74004619ffff0d10c5
2014.05.22 07:36:32 5: AfterExecute: context: ProtoThreads=HASH(0x1b29598), success: 1, reset: 1, owx_dev: 10.541E0B000800.35, writedata: be, numread: 9, readdata: 74004619ffff0d10c5
2014.05.22 07:36:32 5: OWX_Executor: item ProtoThreads=HASH(0x1b294b8) for 10.787E83020800.65 eligible to run
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e15510787e8302080065beffffffffffffffffff
2014.05.22 07:36:32 5: OWX_DS2480 read: After loop no. 15 received: cd5510787e8302080065be37003809ffff06109d
2014.05.22 07:36:32 5: AfterExecute: context: ProtoThreads=HASH(0x1b294b8), success: 1, reset: 1, owx_dev: 10.787E83020800.65, writedata: be, numread: 9, readdata: 37003809ffff06109d
2014.05.22 07:36:32 5: OWX_Executor: item ProtoThreads=HASH(0x1aeab10) for 28.810671010000.D3 eligible to run
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e15528810671010000d3beffffffffffffffffff
2014.05.22 07:36:32 5: OWX_DS2480 read: After loop no. 5 received: cd5528810671010000d3bedc0146087fff041032
2014.05.22 07:36:32 5: AfterExecute: context: ProtoThreads=HASH(0x1aeab10), success: 1, reset: 1, owx_dev: 28.810671010000.D3, writedata: be, numread: 9, readdata: dc0146087fff041032
2014.05.22 07:36:32 5: OWX_Executor: item ProtoThreads=HASH(0xc92da0) for 28.905F9B010000.8B eligible to run
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e15528905f9b0100008bbeffffffffffffffffff
2014.05.22 07:36:32 5: OWX_DS2480 read: After loop no. 15 received: cd5528905f9b0100008bbed0001e057fff101084
2014.05.22 07:36:32 5: AfterExecute: context: ProtoThreads=HASH(0xc92da0), success: 1, reset: 1, owx_dev: 28.905F9B010000.8B, writedata: be, numread: 9, readdata: d0001e057fff101084
2014.05.22 07:36:32 5: OWX_Executor: item ProtoThreads=HASH(0x1864780) for 28.0E37AC040000.FD eligible to run
2014.05.22 07:36:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e155280e37ac040000fdbeffffffffffffffffff
2014.05.22 07:36:33 5: OWX_DS2480 read: After loop no. 7 received: cd55280e37ac040000fdbe54011e0a7fff0c10f0
2014.05.22 07:36:33 5: AfterExecute: context: ProtoThreads=HASH(0x1864780), success: 1, reset: 1, owx_dev: 28.0E37AC040000.FD, writedata: be, numread: 9, readdata: 54011e0a7fff0c10f0
2014.05.22 07:36:33 5: OWX_Executor: item ProtoThreads=HASH(0x1b2bf80) for 28.AEE870010000.B6 eligible to run
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e15528aee870010000b6beffffffffffffffffff
2014.05.22 07:36:33 5: OWX_DS2480 read: After loop no. 11 received: cd5528aee870010000b6be9f0137037fff01109e
2014.05.22 07:36:33 5: AfterExecute: context: ProtoThreads=HASH(0x1b2bf80), success: 1, reset: 1, owx_dev: 28.AEE870010000.B6, writedata: be, numread: 9, readdata: 9f0137037fff01109e
2014.05.22 07:36:33 5: OWX_Executor: item ProtoThreads=HASH(0x1b0d6c8) for 28.A8A49B010000.11 eligible to run
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e15528a8a49b01000011beffffffffffffffffff
2014.05.22 07:36:33 5: OWX_DS2480 read: After loop no. 1 received: cd5528a8a49b01000011beed045a087fff03100c
2014.05.22 07:36:33 5: AfterExecute: context: ProtoThreads=HASH(0x1b0d6c8), success: 1, reset: 1, owx_dev: 28.A8A49B010000.11, writedata: be, numread: 9, readdata: ed045a087fff03100c
2014.05.22 07:36:33 5: OWX_Executor: item ProtoThreads=HASH(0x1b29358) for 10.0576A8020800.6D eligible to run
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:33 5: OWX_DS2480.query sending out: e155100576a80208006dbeffffffffffffffffff
2014.05.22 07:36:33 5: OWX_DS2480 read: After loop no. 6 received: cd55100576a80208006dbe47005a08ffff021073
2014.05.22 07:36:33 5: AfterExecute: context: ProtoThreads=HASH(0x1b29358), success: 1, reset: 1, owx_dev: 10.0576A8020800.6D, writedata: be, numread: 9, readdata: 47005a08ffff021073
2014.05.22 07:36:35 5: OWX_Executor: item ProtoThreads=HASH(0x1b0d748) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:36:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:35 5: OWX_DS2480.query sending out: e155200c2c0c000000593c0f00ffff
2014.05.22 07:36:35 5: OWX_DS2480 read: After loop no. 10 received: cd55200c2c0c000000593c0f003a03
2014.05.22 07:36:35 5: AfterExecute: context: ProtoThreads=HASH(0x1b0d748), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: 3c0f00ffff, numread: 0, readdata: 
2014.05.22 07:36:35 5: OWX_Executor: item ProtoThreads=HASH(0x1b0d748) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:36:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:35 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa0000ffffffffffffffffffff
2014.05.22 07:36:36 5: OWX_DS2480 read: After loop no. 6 received: cd55200c2c0c00000059aa00009ffacb087d08a6e51d39
2014.05.22 07:36:36 5: AfterExecute: context: ProtoThreads=HASH(0x1b0d748), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0000, numread: 10, readdata: 9ffacb087d08a6e51d39
2014.05.22 07:36:36 5: OWX_Executor: item ProtoThreads=HASH(0x1b29438) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:36:36 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:36 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa1000ffffffffffffffffffff
2014.05.22 07:36:36 5: OWX_DS2480 read: After loop no. 9 received: cd55200c2c0c00000059aa1000f5ff00b900b900ff11ba
2014.05.22 07:36:36 5: AfterExecute: context: ProtoThreads=HASH(0x1b29438), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa1000, numread: 10, readdata: f5ff00b900b900ff11ba
2014.05.22 07:36:36 5: OWX_Executor: item ProtoThreads=HASH(0x1b2ba20) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:36:36 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:36 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa0800ffffffffffffffffffff
2014.05.22 07:36:36 5: OWX_DS2480 read: After loop no. 5 received: cd55200c2c0c00000059aa08000001000100010001e0cf
2014.05.22 07:36:36 5: AfterExecute: context: ProtoThreads=HASH(0x1b2ba20), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0800, numread: 10, readdata: 0001000100010001e0cf
2014.05.22 07:36:42 5: OWX_Executor: item ProtoThreads=HASH(0x185e638) for 29.68980C000000.DA eligible to run
2014.05.22 07:36:42 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:36:42 5: OWX_DS2480.query sending out: e1552968980c000000daf08800ffffffffffffffffffff
2014.05.22 07:36:42 5: OWX_DS2480 read: After loop no. 9 received: cd552968980c000000daf08800f7f7ff000088ffff2706
2014.05.22 07:36:42 5: AfterExecute: context: ProtoThreads=HASH(0x185e638), success: 1, reset: 1, owx_dev: 29.68980C000000.DA, writedata: f08800, numread: 10, readdata: f7f7ff000088ffff2706
2014.05.22 07:37:00 5: OWX_Executor: command 1 eligible to run
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e1f0e3b5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:00 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.22 07:37:00 5: OWX_DS2480 read: After loop no. 7 received: cdf04109a000a008a0000000000000008222
2014.05.22 07:37:00 5: OWX_Executor: command 2 eligible to run
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:00 5: OWX_DS2480 read: After loop no. 4 received: cdec820880288082a00000000000000088a2
2014.05.22 07:37:00 5: OWX_SER::Search: new alarm device found 29.68980C000000.DA
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:00 5: OWX_DS2480 read: After loop no. 6 received: cdec820880288082a00000000000000088a2
2014.05.22 07:37:00 5:  Alarms = 29.68980C000000.DA
2014.05.22 07:37:00 5: OWX_Executor: item ProtoThreads=HASH(0x185a108) for --- eligible to run
2014.05.22 07:37:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e1cc44
2014.05.22 07:37:01 5: OWX_DS2480 read: After loop no. 4 received: cdcc44
2014.05.22 07:37:01 5: AfterExecute: context: ProtoThreads=HASH(0x185a108), success: 1, reset: 1, owx_dev: undef, writedata: 44, numread: 0, readdata: 
2014.05.22 07:37:01 5: OWX_Executor: item ProtoThreads=HASH(0x1a56408) for 28.1307AC040000.68 eligible to run
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e155281307ac04000068beffffffffffffffffff
2014.05.22 07:37:01 5: OWX_DS2480 read: After loop no. 15 received: cd55281307ac04000068be44011e0a7fff0c10a4
2014.05.22 07:37:01 5: AfterExecute: context: ProtoThreads=HASH(0x1a56408), success: 1, reset: 1, owx_dev: 28.1307AC040000.68, writedata: be, numread: 9, readdata: 44011e0a7fff0c10a4
2014.05.22 07:37:01 5: OWX_Executor: item ProtoThreads=HASH(0x18677b8) for 28.CA0FAC040000.04 eligible to run
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e15528ca0fac04000004beffffffffffffffffff
2014.05.22 07:37:01 5: OWX_DS2480 read: After loop no. 17 received: cd5528ca0fac04000004beea001e0a7fff0610fd
2014.05.22 07:37:01 5: AfterExecute: context: ProtoThreads=HASH(0x18677b8), success: 1, reset: 1, owx_dev: 28.CA0FAC040000.04, writedata: be, numread: 9, readdata: ea001e0a7fff0610fd
2014.05.22 07:37:01 5: OWX_Executor: item ProtoThreads=HASH(0x1865170) for 10.541E0B000800.35 eligible to run
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:01 5: OWX_DS2480.query sending out: e15510541e0b00080035beffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 17 received: cd5510541e0b00080035be74004619ffff0d10c5
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1865170), success: 1, reset: 1, owx_dev: 10.541E0B000800.35, writedata: be, numread: 9, readdata: 74004619ffff0d10c5
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x1857798) for 10.787E83020800.65 eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e15510787e8302080065beffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 17 received: cd5510787e8302080065be37003809ffff071059
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1857798), success: 1, reset: 1, owx_dev: 10.787E83020800.65, writedata: be, numread: 9, readdata: 37003809ffff071059
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x1866d28) for 28.810671010000.D3 eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e15528810671010000d3beffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 14 received: cd5528810671010000d3bedc0146087fff041032
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1866d28), success: 1, reset: 1, owx_dev: 28.810671010000.D3, writedata: be, numread: 9, readdata: dc0146087fff041032
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x1b047b8) for 28.905F9B010000.8B eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e15528905f9b0100008bbeffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 14 received: cd5528905f9b0100008bbed0001e057fff101084
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1b047b8), success: 1, reset: 1, owx_dev: 28.905F9B010000.8B, writedata: be, numread: 9, readdata: d0001e057fff101084
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x1861b88) for 28.0E37AC040000.FD eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e155280e37ac040000fdbeffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 17 received: cd55280e37ac040000fdbe54011e0a7fff0c10f0
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1861b88), success: 1, reset: 1, owx_dev: 28.0E37AC040000.FD, writedata: be, numread: 9, readdata: 54011e0a7fff0c10f0
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x1856790) for 28.AEE870010000.B6 eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e15528aee870010000b6beffffffffffffffffff
2014.05.22 07:37:02 5: OWX_DS2480 read: After loop no. 16 received: cd5528aee870010000b6be9f0137037fff01109e
2014.05.22 07:37:02 5: AfterExecute: context: ProtoThreads=HASH(0x1856790), success: 1, reset: 1, owx_dev: 28.AEE870010000.B6, writedata: be, numread: 9, readdata: 9f0137037fff01109e
2014.05.22 07:37:02 5: OWX_Executor: item ProtoThreads=HASH(0x185e388) for 28.A8A49B010000.11 eligible to run
2014.05.22 07:37:02 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:03 5: OWX_DS2480.query sending out: e15528a8a49b01000011beffffffffffffffffff
2014.05.22 07:37:03 5: OWX_DS2480 read: After loop no. 16 received: cd5528a8a49b01000011beed045a087fff03100c
2014.05.22 07:37:03 5: AfterExecute: context: ProtoThreads=HASH(0x185e388), success: 1, reset: 1, owx_dev: 28.A8A49B010000.11, writedata: be, numread: 9, readdata: ed045a087fff03100c
2014.05.22 07:37:03 5: OWX_Executor: item ProtoThreads=HASH(0x1856510) for 10.0576A8020800.6D eligible to run
2014.05.22 07:37:03 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:03 5: OWX_DS2480.query sending out: e155100576a80208006dbeffffffffffffffffff
2014.05.22 07:37:03 5: OWX_DS2480 read: After loop no. 9 received: cd55100576a80208006dbe47005a08ffff021073
2014.05.22 07:37:03 5: AfterExecute: context: ProtoThreads=HASH(0x1856510), success: 1, reset: 1, owx_dev: 10.0576A8020800.6D, writedata: be, numread: 9, readdata: 47005a08ffff021073
2014.05.22 07:37:12 5: OWX_Executor: item ProtoThreads=HASH(0x1b0d5c8) for 29.68980C000000.DA eligible to run
2014.05.22 07:37:12 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:12 5: OWX_DS2480.query sending out: e1552968980c000000daf08800ffffffffffffffffffff
2014.05.22 07:37:12 5: OWX_DS2480 read: After loop no. 5 received: cd552968980c000000daf08800f7f7ff000088ffff2706
2014.05.22 07:37:12 5: AfterExecute: context: ProtoThreads=HASH(0x1b0d5c8), success: 1, reset: 1, owx_dev: 29.68980C000000.DA, writedata: f08800, numread: 10, readdata: f7f7ff000088ffff2706
2014.05.22 07:37:30 5: OWX_Executor: command 1 eligible to run
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e1f0e3b5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:30 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.22 07:37:30 5: OWX_DS2480 read: After loop no. 7 received: cdf04109a000a008a0000000000000008222
2014.05.22 07:37:30 5: OWX_Executor: command 2 eligible to run
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:30 5: OWX_DS2480 read: After loop no. 5 received: cdec820880288082a00000000000000088a2
2014.05.22 07:37:30 5: OWX_SER::Search: new alarm device found 29.68980C000000.DA
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:37:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:37:30 5: OWX_DS2480 read: After loop no. 7 received: cdec820880288082a00000000000000088a2
2014.05.22 07:37:30 5:  Alarms = 29.68980C000000.DA
2014.05.22 07:37:30 5: OWX_Executor: item ProtoThreads=HASH(0x1857378) for --- eligible to run
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e1cc44
2014.05.22 07:37:31 5: OWX_DS2480 read: After loop no. 3 received: cdcc44
2014.05.22 07:37:31 5: AfterExecute: context: ProtoThreads=HASH(0x1857378), success: 1, reset: 1, owx_dev: undef, writedata: 44, numread: 0, readdata: 
2014.05.22 07:37:31 5: OWX_Executor: item ProtoThreads=HASH(0x185a3e8) for 28.1307AC040000.68 eligible to run
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e155281307ac04000068beffffffffffffffffff
2014.05.22 07:37:31 5: OWX_DS2480 read: After loop no. 17 received: cd55281307ac04000068be44011e0a7fff0c10a4
2014.05.22 07:37:31 5: AfterExecute: context: ProtoThreads=HASH(0x185a3e8), success: 1, reset: 1, owx_dev: 28.1307AC040000.68, writedata: be, numread: 9, readdata: 44011e0a7fff0c10a4
2014.05.22 07:37:31 5: OWX_Executor: item ProtoThreads=HASH(0x1867668) for 28.CA0FAC040000.04 eligible to run
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e15528ca0fac04000004beffffffffffffffffff
2014.05.22 07:37:31 5: OWX_DS2480 read: After loop no. 18 received: cd5528ca0fac04000004beea001e0a7fff0610fd
2014.05.22 07:37:31 5: AfterExecute: context: ProtoThreads=HASH(0x1867668), success: 1, reset: 1, owx_dev: 28.CA0FAC040000.04, writedata: be, numread: 9, readdata: ea001e0a7fff0610fd
2014.05.22 07:37:31 5: OWX_Executor: item ProtoThreads=HASH(0x1b2bc50) for 10.541E0B000800.35 eligible to run
2014.05.22 07:37:31 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e15510541e0b00080035beffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 18 received: cd5510541e0b00080035be74004619ffff0d10c5
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1b2bc50), success: 1, reset: 1, owx_dev: 10.541E0B000800.35, writedata: be, numread: 9, readdata: 74004619ffff0d10c5
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x1b25000) for 10.787E83020800.65 eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e15510787e8302080065beffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 17 received: cd5510787e8302080065be37003809ffff06109d
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1b25000), success: 1, reset: 1, owx_dev: 10.787E83020800.65, writedata: be, numread: 9, readdata: 37003809ffff06109d
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x1856a30) for 28.810671010000.D3 eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e15528810671010000d3beffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 2 received: cd5528810671010000d3bedc0146087fff041032
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1856a30), success: 1, reset: 1, owx_dev: 28.810671010000.D3, writedata: be, numread: 9, readdata: dc0146087fff041032
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x1856bc0) for 28.905F9B010000.8B eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e15528905f9b0100008bbeffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 15 received: cd5528905f9b0100008bbed0001e057fff101084
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1856bc0), success: 1, reset: 1, owx_dev: 28.905F9B010000.8B, writedata: be, numread: 9, readdata: d0001e057fff101084
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x1861778) for 28.0E37AC040000.FD eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e155280e37ac040000fdbeffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 16 received: cd55280e37ac040000fdbe54011e0a7fff0c10f0
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1861778), success: 1, reset: 1, owx_dev: 28.0E37AC040000.FD, writedata: be, numread: 9, readdata: 54011e0a7fff0c10f0
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x1b045d8) for 28.AEE870010000.B6 eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e15528aee870010000b6beffffffffffffffffff
2014.05.22 07:37:32 5: OWX_DS2480 read: After loop no. 16 received: cd5528aee870010000b6bea00137037fff1010b0
2014.05.22 07:37:32 5: AfterExecute: context: ProtoThreads=HASH(0x1b045d8), success: 1, reset: 1, owx_dev: 28.AEE870010000.B6, writedata: be, numread: 9, readdata: a00137037fff1010b0
2014.05.22 07:37:32 5: OWX_Executor: item ProtoThreads=HASH(0x18649e0) for 28.A8A49B010000.11 eligible to run
2014.05.22 07:37:32 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:33 5: OWX_DS2480.query sending out: e15528a8a49b01000011beffffffffffffffffff
2014.05.22 07:37:33 5: OWX_DS2480 read: After loop no. 3 received: cd5528a8a49b01000011beed045a087fff03100c
2014.05.22 07:37:33 5: AfterExecute: context: ProtoThreads=HASH(0x18649e0), success: 1, reset: 1, owx_dev: 28.A8A49B010000.11, writedata: be, numread: 9, readdata: ed045a087fff03100c
2014.05.22 07:37:33 5: OWX_Executor: item ProtoThreads=HASH(0x185db18) for 10.0576A8020800.6D eligible to run
2014.05.22 07:37:33 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:33 5: OWX_DS2480.query sending out: e155100576a80208006dbeffffffffffffffffff
2014.05.22 07:37:33 5: OWX_DS2480 read: After loop no. 11 received: cd55100576a80208006dbe47005a08ffff0310b7
2014.05.22 07:37:33 5: AfterExecute: context: ProtoThreads=HASH(0x185db18), success: 1, reset: 1, owx_dev: 10.0576A8020800.6D, writedata: be, numread: 9, readdata: 47005a08ffff0310b7
2014.05.22 07:37:35 5: OWX_Executor: item ProtoThreads=HASH(0x1b28e38) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e155200c2c0c000000593c0f00ffff
2014.05.22 07:37:35 5: OWX_DS2480 read: After loop no. 7 received: cd55200c2c0c000000593c0f003a03
2014.05.22 07:37:35 5: AfterExecute: context: ProtoThreads=HASH(0x1b28e38), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: 3c0f00ffff, numread: 0, readdata: 
2014.05.22 07:37:35 5: OWX_Executor: item ProtoThreads=HASH(0x1b28e38) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa0000ffffffffffffffffffff
2014.05.22 07:37:35 5: OWX_DS2480 read: After loop no. 8 received: cd55200c2c0c00000059aa0000adfab408ba0812e69e4e
2014.05.22 07:37:35 5: AfterExecute: context: ProtoThreads=HASH(0x1b28e38), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0000, numread: 10, readdata: adfab408ba0812e69e4e
2014.05.22 07:37:35 5: OWX_Executor: item ProtoThreads=HASH(0x1b041e8) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa1000ffffffffffffffffffff
2014.05.22 07:37:35 5: OWX_DS2480 read: After loop no. 9 received: cd55200c2c0c00000059aa1000f5ff00b900b900ff11ba
2014.05.22 07:37:35 5: AfterExecute: context: ProtoThreads=HASH(0x1b041e8), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa1000, numread: 10, readdata: f5ff00b900b900ff11ba
2014.05.22 07:37:35 5: OWX_Executor: item ProtoThreads=HASH(0x185e4f8) for 20.0C2C0C000000.59 eligible to run
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:35 5: OWX_DS2480.query sending out: e155200c2c0c00000059aa0800ffffffffffffffffffff
2014.05.22 07:37:35 5: OWX_DS2480 read: After loop no. 9 received: cd55200c2c0c00000059aa08000001000100010001e0cf
2014.05.22 07:37:35 5: AfterExecute: context: ProtoThreads=HASH(0x185e4f8), success: 1, reset: 1, owx_dev: 20.0C2C0C000000.59, writedata: aa0800, numread: 10, readdata: 0001000100010001e0cf
2014.05.22 07:37:42 5: OWX_Executor: item ProtoThreads=HASH(0x1864df0) for 29.68980C000000.DA eligible to run
2014.05.22 07:37:42 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:37:42 5: OWX_DS2480.query sending out: e1552968980c000000daf08800ffffffffffffffffffff
2014.05.22 07:37:42 5: OWX_DS2480 read: After loop no. 6 received: cd552968980c000000daf08800f7f7ff000088ffff2706
2014.05.22 07:37:42 5: AfterExecute: context: ProtoThreads=HASH(0x1864df0), success: 1, reset: 1, owx_dev: 29.68980C000000.DA, writedata: f08800, numread: 10, readdata: f7f7ff000088ffff2706
2014.05.22 07:38:00 5: OWX_Executor: command 1 eligible to run
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e1f0e3b5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:38:00 5: OWX_ASYNC_PT_Kick: kicking DS14B20 temperature conversion
2014.05.22 07:38:00 5: OWX_DS2480 read: After loop no. 7 received: cdf04109a000a008a0000000000000008222
2014.05.22 07:38:00 5: OWX_Executor: command 2 eligible to run
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:38:00 5: OWX_DS2480 read: After loop no. 4 received: cdec820880288082a00000000000000088a2
2014.05.22 07:38:00 5: OWX_SER::Search: new alarm device found 29.68980C000000.DA
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e1ece3b5
2014.05.22 07:38:00 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5
2014.05.22 07:38:00 5: OWX_DS2480 read: After loop no. 4 received: cdec820880288082a00000000000000088a2
2014.05.22 07:38:00 5:  Alarms = 29.68980C000000.DA
2014.05.22 07:38:00 5: OWX_Executor: item ProtoThreads=HASH(0x18674e8) for --- eligible to run
2014.05.22 07:38:01 5: OWX_DS2480.query sending out: e3c5
2014.05.22 07:38:01 5: OWX_DS2480.query sending out: e1cc44
2014.05.22 07:38:01 5: OWX_DS2480 read: After loop no. 4 received: cdcc44
2014.0

Herzliche Grüße

Christian

det. · 22 Mai 2014, 09:56:45

Zitat von: ntruchsess am 21 Mai 2014, 21:43:27
Das mit der Systemlast gefällt mir nicht, das ist bei mir nicht so... Du hast doch die ganzen LCD-aufrufe auf 'set XYZ...' umgebaut, ist das oft drin, bzw. wird das (oder andere 'set XYZ...'-kommandos an OW-Frontendmodulen) oft aufgerufen? Die 'set'-kommandos der Frontendmodule laufen ja synchron - da wird der aktuelle Protothread so lange aufgerufen bis er durch ist, das macht in dem Moment nahezu 100% Systemlast. Das ist auch ein Punkt, der noch mal überarbeitet gehört, aber da habe ich angenommen, dass das im Regelbetrieb nicht oft passiert, sondern nur, wenn jemand am Webinterface rumspielt (und eben die Ergebnisse seines Handelns auch sofort sehen will - sonst könnte man 'set' auch genausogut asynchron laufen lassen, dann gäbe es halt keine unmittelbar sichtbare Änderung, weil die ja asynchron später käme).

Läuft es mit synchronem OWX (gleiche config, die Frontendmodule sind ja abwärtskompatibel) stabil? Wenn nein, dann spiel den letzten Stand wieder ein, der bei Dir stabil lief und teste nach dem Urlaub weiter. Vieleicht ist bis dahin ja schon alles in Butter

Gruß,

Norbert

Hallo Norbert,
ja das eine von zwei Displays stand z.b. gestern auf Außentemperatur 15°C, als ich Nachmittags von Arbeit kam. Das deutet nach dem Temperaturverlauf darauf hin, das es ab 8 Uhr früh nicht mehr ansprechbar war. Heute morgen habe ich ein shutdown restet gestartet, da die Systemlast wieder so hoch war. Mal sehen was heute abend da so los ist, ggf. kann ich so einen Zwangsneustart für die kommenden Urlaubswochen einfach fest einbauen. Da ist es ja auch egal, ob auf den Displays was zu lesen ist (wegen dem Initialisierungsfehler). Das synchrone OWX brachte mit Deinen überarbeiteten Modulen div. Fehler, die von anderen Mitstreitern hier im Beitrag schon gepostet wurden. Das ist also nicht die Lösung.

ntruchsess · 22 Mai 2014, 11:38:56

Zitat von: cwagner am 22 Mai 2014, 07:52:38
Code Auswählen Erweitern
2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e3c5 2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e1ece3b5 2014.05.22 07:36:30 5: OWX_DS2480.query sending out: e100000000000000000000000000000000e3a5 2014.05.22 07:36:30 5: OWX_DS2480 read: After loop no. 4 received: cdec6800000000000000000000000000000000 2014.05.22 07:36:30 3: OWX_DS2480: Search 2nd return has wrong parameter with length = 17

das ist ja echt merkwürdig, da hängt einfach ein 00-byte mehr dran, vorne sind die erwarteten 2 Bytes 'cdec' vorhanden, d.h. es kann kein Byte von einem vorherigen Befehl oder so noch im seriellen Buffer gewesen sein.
Die Frage ist ja, wie man damit umgehen soll, bzw. ob es eine bessere Alternative gibt, als die Bussuche hier einfach abzubrechen ohne zu riskieren, falsche Ergebnisse zu bekommen? Sollte man, wie im Datenblatt beispielhaft aufgeführt noch einen 1-Wire-Busreset hinterherschicken, oder einfach den gleichen Search-durchgang noch mal machen? Eigentlich sollte der gleiche Fehler beim Synchronen OWX genauso auftreten. Hast Du noch die Log-zeilen davor im Angebot, mich würde interessieren, mit welchem Device unmittelbar vorher geredet wurde, vieleicht gibt's da ja eine Korrelation, wenn das öfter auftritt.

Gruß,

Norbert

cwagner · 22 Mai 2014, 12:26:34

Gerne. Wegen der Größe als Anlage das, was ich vor dem Aufbruch nach dem letzten Neustart noch aufgezeichnet habe. Bei den letzten Zeilen stand verbose auf 0, weil ich nicht wollte, dass mir bei Abwesenheit die Kiste "platzt"

Herzliche Grüße

Christian

det. · 22 Mai 2014, 20:47:50

Hallo Norbert,
habe einmalig nach heutigem update eine Meldung bezüglich eines Louis Swart Displaycontrollers:

Code Auswählen

2014.05.22 20:39:44 2: OWX_ASYNC: Error running task for FF.C90700000100.9A: OWX_DS2480 read timeout, bytes read: 1, expected: 21

das ist nicht der, welcher die letzten Tage immer schlafen gegangen ist....

det. · 22 Mai 2014, 21:21:19

Bin wie vorgeschlagen wegen "drohender" Abwesenheit auf OWX synchron zurück gewechselt ( bei gleichem Modul Releasestand ) - ging erstaunlich unproblematisch, auch meine Änderungen in der Displayansteuerung wegen OWX_ASYNC konnten so bleiben. Nach Edit direkt in der fhem.cfg und anschließendem save - mein Eindruck: ohne OWX_ASYNC startet FHEM erheblich schneller... gefühlt Sekunden gegenüber 1 Min. vorher.
Leider habe ich die Fehlermeldungen wieder im LOG (die bei OWX_ASYNC weg waren, aber lieber Meldungen als täglich abstürzendes FHEM):

Code Auswählen

2014.05.22 20:51:40 3: OWX: Complex called with unknown interface serial on bus 1wire_1
2014.05.22 20:51:40 3: OWX: Reset called with unknown interface serial
2014.05.22 20:51:40 3: OWX: Complex called with unknown interface serial on bus 1wire_1 
2014.05.22 20:51:40 3: OWX: Reset called with unknown interface serial 
2014.05.22 20:51:40 3: OWX: Complex called with unknown interface serial on bus 1wire_1 
2014.05.22 20:51:40 3: OWX: Reset called with unknown interface serial
......
und 
2014.05.22 21:12:04 3: set OWSWITCHBoden output A ON : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 21:07:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 21:02:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 20:57:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC

Dabei funktionieren die DS2406 Schaltmodule wie gewünscht....

cwagner · 22 Mai 2014, 22:11:16

bei jedem FHEM-Absturz habe ich auf der Telnet-Konsole diese gleiche, letzte Fehlermeldung:

Code Auswählen

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

Herzliche Grüße

Christian

Prof. Dr. Peter Henning · 23 Mai 2014, 13:15:01

Danke Dir für die Arbeit.

LG

pah

cwagner · 23 Mai 2014, 16:21:05

Code Auswählen

[quote author=det. link=topic=13580.msg170970#msg170970 date=1400786479]
Bin wie vorgeschlagen wegen "drohender" Abwesenheit auf OWX synchron zurück gewechselt und 
2014.05.22 21:12:04 3: set OWSWITCHBoden output A ON : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 21:07:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 21:02:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC 
2014.05.22 20:57:04 3: set OWSWITCHBoden output A OFF : OWSWITCH: Could not set device OWSWITCHBoden, reason: invalid CRC

Dabei funktionieren die DS2406 Schaltmodule wie gewünscht....
[/quote]

Genau die gleiche Erfahrung hatte ich mit den synchronen Modulen in den jüngeren Versionen mit einem 8fach-Switch gemacht - nicht bei jedem Schaltvorgang aber doch recht häufig. Und in den allermeisten Fällen war der Schaltvorgang doch umgesetzt worden.

Christian

det. · 23 Mai 2014, 19:39:34

@all,
ich bin erst mal entspannt. Nach gestriger Umstellung von OWX_ASYNC zurück zu OWX läuft FHEM wieder so stabil wie gewohnt und die Systemlast bewegt sich im Bereich von 0-10%.
Die erwähnten Fehlermeldungen bei OWSWITCH lassen sich auch durch verbose 0 nicht unterdrücken, aber der fhemlog ist geduldig und zeichnet es eben auf. Solange das keine weiteren Probleme bereitet soll es mir egal sein.
Bin schon jetzt gespannt, was sich bis nach Pfingsten hier so alles entwickelt hat.

cwagner · 31 Mai 2014, 11:05:26

Auf der Suche nach den Ursachen für praktisch tägliche Abstürze des FHEM vermutlich aufgrund OWAD (Verdacht wegen der gheposteten TElnet-Meldung, die dann immer als letzte in der Sitzung steht) habe ich nochmal verbose=5 laufen lassen und mir fallen diese FHEM.log-Zeilen auf:

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.

Postitiv: Seitdem ich ASYNC einsetze habe ich bei den 10 Temp-Devices 99.99%ig gültige Werte. Vorher hatte ich mehrfach über den Tag verteilt immer wieder in den Messwerten 85.0 als Ausreißer (ungültige Messwerte).

Herzliche Grüße

Christian