OWX Next Generation

Begonnen von Prof. Dr. Peter Henning, 09 November 2016, 20:48:30

Vorheriges Thema - Nächstes Thema

Prof. Dr. Peter Henning

#45
Nach langer Zeit habe ich mir gestern ein paar Ressourcen freigeschaufelt und endlich wieder am neuen, asynchronen OWX weitergearbeitet. Ich denke, dass ich gestern einen wesentlichen Mangel behoben habe. Also anbei die nötigen Dateien, um mal wieder ins Testen zu gehen.

Funktioniert bei mir problemlos mit allen aktuellen Gerätemodulen außer OWLCD, als Interfaces bisher nur USB/Seriell und TCP

LG

pah


UweH

Dankeschön  :) Funktioniert.
Nach dem Unterbrechen der Verbindung zu einem Interface macht FHEM brav weiter und setzt den Status auf "disconnected".  Keine Aussetzer, kein Abschmieren.
Stecker rein und kurze Zeit später ist der Status "opened". Hab ich mehrfach getestet und auch nach 20min Unterbrechung kein Problem beim Verbindungsaufbau.

Super Sache  :D

Gruß
Uwe

Prof. Dr. Peter Henning

Vorsicht, ein paar Wackler sind sicher noch drin.

Interessant ist, wie sich die Queue-Füllung im Laufe der Zeit verändert - siehe Reading "queue"

LG

pah

UweH

Bei einem LAN/1-Wire-Interface steht queue auf 16, bei drei anderen wird es nicht angezeigt. Was beinhaltet queue und was sagt mir das?

UweH

Eine Sache habe ich noch gefunden...nach einem erfolgreichen "reappeared" lassen sich 1-Wire-Aktoren (in dem Fall DS2413) nicht mehr schalten. Sind zwar present, reagieren nur nicht. DS1820 werden korrekt abgefragt. Nach einem Neustart von FHEM kann man wieder schalten.

Gruß
Uwe

Prof. Dr. Peter Henning

Das neue OWX hat eine eigene interne Queue, die asynchron abgearbeitet wird. Dabei wird heftigst an dieser Queue herummanipuliert - wenn Antworten von einem Device eintrudeln, müssen eventuell Folgeabfragen ganz vorne in der Queue einsortiert werden. Sie kann deshalb während komplizierter Abfragen heftig wachsen - und schrumpft dann wieder. Das Reading "queue" zeigt einfach die Anzahl der Einträge in dieser Warteschlange.

DS2413 schaue ich mir an.

LG

pah

cwagner

#51
Guten Morgen, habe die Beta05 ausprobiert und diese Beobachtungen gemacht:

1. FHEM startet und läuft durch, tendenziell auch "zackiger"
2. Ein Get devices zeigt sämtlich 23 Sensoren DS 2450, 18S20, 18B20, DS 2438, nicht aber DS 2408.
3. Der Switch DS 2408 funktioniert dennoch sehr gut.
4. Die Internals der Temp-Devices zeigen bei Asynchronous 0 und nicht wie erwartet 1
5. Nach dem ersten erfolgreichen Temperatur-Reading springt ein IO-Device auf "disconnected"
6. Danach wird FHEM extrem zäh, jeder Aufruf eines Raums o.ä. dauert im Minutenbereich, obwohl Systemlast laut TOP bei 5-15% CPU ist.
7. Im Log habe ich diese Meldungen: 2017.02.18 10:42:47 1: PERL WARNING: Use of uninitialized value $numexp in numeric eq (==) at ./FHEM/00_OWX.pm line 1112.
2017.02.18 10:44:49 5: Return from verify for device 10.0576A8020800.6D is 1
2017.02.18 10:45:27 1: PERL WARNING: Use of uninitialized value $numexp in numeric lt (<) at ./FHEM/00_OWX.pm line 1079.
2017.02.18 10:45:27 1: PERL WARNING: Use of uninitialized value $numexp in numeric ge (>=) at ./FHEM/00_OWX.pm line 1120.
2017.02.18 10:45:27 1: PERL WARNING: Use of uninitialized value $proc in bitwise and (&) at ./FHEM/00_OWX.pm line 1133.
2017.02.18 10:56:07 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:56:07 1: PERL WARNING: Use of uninitialized value in subroutine entry at /usr/lib/arm-linux-gnueabihf/perl5/5.20/Device/SerialPort.pm line 1732.
2017.02.18 10:56:07 1: PERL WARNING: Use of uninitialized value in vec at /usr/lib/arm-linux-gnueabihf/perl5/5.20/Device/SerialPort.pm line 1405.
2017.02.18 10:56:07 1: PERL WARNING: Use of uninitialized value in subroutine entry at /usr/lib/arm-linux-gnueabihf/perl5/5.20/Device/SerialPort.pm line 1417.
2017.02.18 10:56:07 1: PERL WARNING: Use of uninitialized value $string_part in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 733.
2017.02.18 10:56:07 1: PERL WARNING: Use of uninitialized value $m in addition (+) at ./FHEM/11_OWX_SER.pm line 731.
2017.02.18 10:56:09 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:56:14 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:56:23 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:56:27 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:56:31 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:56:36 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:56:44 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:56:49 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:57:11 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:57:15 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:57:24 1: /dev/ttyUSB0 reappeared (OWio1)
2017.02.18 10:57:28 1: /dev/ttyUSB0 disconnected, waiting to reappear (OWio1)
2017.02.18 10:57:28 5: OWX_Set request OWio1 FF ?
2017.02.18 10:57:32 5: OWX_Set request OWio1 FF ?
und in dieser Weise geht es dann beliebig weiter

8. LIsting meines IO-Devices:Internals:
   ALARMDEVS
   ALARMED    no
   ASYNCHRONOUS 1
   BUSY       1
   CFGFN
   DEBUG      0
   DEF        /dev/ttyUSB0
   DeviceName /dev/ttyUSB0
   INTERFACE  DS2480
   LASTSEND   1487412741.90792
   NAME       OWio1
   NR         107
   PARTIAL
   PRESENT    1
   ROM_ID     FF
   STATE      disconnected
   TYPE       OWX
   followAlarms off
   interval   30
   nextOpenDelay 5
   timeout    15
   DEVS:
     20....
     10.....
     28.....
     26.....
   QUEUE:
     HASH(0x38c3b08)
     HASH(0x14e8780)
     HASH(0x156f560)
     HASH(0x15562c0)
     HASH(0x14ed088)
     HASH(0x37d2cc8)
     HASH(0x14edaf0)
     HASH(0x14eb440)
     HASH(0x1571330)
     HASH(0x1747060)
     HASH(0x156aee8)
     HASH(0x3878f68)
     HASH(0x14e8480)
     HASH(0x17470a8)
     HASH(0x156c8e0)
     HASH(0x15482f8)
     HASH(0x1571f68)
     HASH(0x154d348)
     HASH(0x1576130)
     HASH(0x154d178)
     HASH(0x15482c8)
     HASH(0x1375340)
     HASH(0x15570f0)
     HASH(0x154d540)
     HASH(0x156f3e0)
     HASH(0x1576b68)
     HASH(0x14e99d0)
     HASH(0x1547fc8)
     HASH(0x154cc08)
     HASH(0x155a4d0)
     HASH(0x1556098)
     HASH(0x14eb908)
     HASH(0x154cab8)
     HASH(0x154d2e8)
     HASH(0x14e9490)
     HASH(0x14ecf50)
     HASH(0x156cc58)
     HASH(0x154cd28)
     HASH(0x15710d8)
     HASH(0x1555b88)
     HASH(0x14e75a8)
     HASH(0x1557048)
     HASH(0x1741d00)
     HASH(0x1551c48)
     HASH(0x14ed808)
     HASH(0x154d768)
     HASH(0x1576970)
     HASH(0x14e79f8)
     HASH(0x1556128)
     HASH(0x1571b00)
   Readings:
     2017-02-18 10:40:42   busstate        initialized
     2017-02-18 11:12:21   queue           51
     2017-02-18 11:12:17   state           disconnected
Attributes:
   asynchronous 1
   interval   30
   room       OWX
   timeout    15
   verbose    5

9. Das MOdul lauft im synchronen Modus bislang unauffällig.
Herzliche Grüße

Christian

PI 2B+/3B+ Raspbian 12, Perl 5.36.0, FHEM 6.3: 295 Module in ConfigDB: Steuerung Heizkessel, FBH, Solarthermie, kontr. Lüftung mit WRG. Smarthome u.a. HMCUL, 1-Wire (FT232RL ; DS2480B), EnOcean (TCM EPS3), MQTT2. DOIF, PID20, Threshold, OWX; Micropelt IRTV, Volkszähler, SolarForecast; MariaDB

Prof. Dr. Peter Henning

OK, sehe ich mir an.

Langsam nimmt das Teil Gestalt an...

Probleme bisher bei OWTHERM, OWSWITCH mit DS2408 und OWLCD.

LG

pah

UweH

Ich hatte vorgestern mal probeweise meine FHEM-Hauptinstanz mit den neuen Modulen bestückt...OWX ist nach einer halben Stunde "stehengeblieben", nach dem Neustart dann ein paar Minuten später wieder. FHEM an sich lief noch, aber keine Reaktion mehr von den 1-Wire-Devices. Keine Temperaturen, keine Meldungen von den DS1820, DS2408, DS2406 etc.  (insgesamt ca. 50 Stück auf 4 LAN/1-Wire-Interfaces verteilt). Ein "get...devices" hat aber alle jeweils angeschlossenen Devices angezeigt.
Meldungen im Log sahen so aus:

Zitat2017.02.16 18:04:09 1: PERL WARNING: Use of uninitialized value in string ne at ./FHEM/00_OWX.pm line 1292.
2017.02.16 18:07:01 1: OWX_Qomplex: Queue too long, dropping data
2017.02.16 18:07:01 1: OWX_Qomplex: Queue too long, dropping data
2017.02.16 18:07:01 1: OWX_Qomplex: Queue too long, dropping data

Zitat2017.02.16 18:21:33 1: OWX_TCP::Detect 1-Wire bus 1wire_Haus_2: interface not found, answer was 0x07 0x05 0x0b 0x0f 0x01
2017.02.16 18:21:33 1: OWX_TCP::Detect 1-Wire bus 1wire_Haus_2: interface not found, answer was 0x07 0x05 0x0b 0x0f 0x01
usw...

Zitat2017.02.16 18:22:30 1: OWX_TCP::Detect 1-Wire bus 1wire_Haus_3: interface not found, answer was 0x07 0x05 0x0b 0x0f 0x01
2017.02.16 18:22:31 1: OWX_TCP::Detect 1-Wire bus 1wire_Haus_3: interface not found, answer was 0x07 0x05 0x0b 0x0f 0x01
usw...

Zitat2017.02.16 18:23:27 1: OWX_TCP::Detect 1-Wire bus 1wire_GH: interface not found, answer was 0x16 0x04 0x1a 0x0e 0x10
2017.02.16 18:23:28 1: OWX_TCP::Detect 1-Wire bus 1wire_GH: interface not found, answer was 0x16 0x04 0x1a 0x0e 0x10
usw...

Gruß
Uwe

Prof. Dr. Peter Henning

Na, ist doch offensichtlich: Queue too long. Hat derzeit 50 Einträge, kann durch eine Änderung beliebig ausgebaut werden. Wieviele Sensoren hängen denn max. an einem Bus ?

@cwagner: Ich wüsste gerne nochgenau, bei welchem Temperatursensor das Problem aufgetaucht ist (Family-Id oder Chip-Typ).

LG

pah

cwagner

Zitat von: Prof. Dr. Peter Henning am 19 Februar 2017, 09:25:24

@cwagner: Ich wüsste gerne nochgenau, bei welchem Temperatursensor das Problem aufgetaucht ist (Family-Id oder Chip-Typ).


Die Family-ID des einen Sensors, nach dem dann die Schnittstelle disconnected ist 10 (DS1820)

Grüße

Christian Wagner
PI 2B+/3B+ Raspbian 12, Perl 5.36.0, FHEM 6.3: 295 Module in ConfigDB: Steuerung Heizkessel, FBH, Solarthermie, kontr. Lüftung mit WRG. Smarthome u.a. HMCUL, 1-Wire (FT232RL ; DS2480B), EnOcean (TCM EPS3), MQTT2. DOIF, PID20, Threshold, OWX; Micropelt IRTV, Volkszähler, SolarForecast; MariaDB

UweH

Zitat von: Prof. Dr. Peter Henning am 19 Februar 2017, 09:25:24
Wieviele Sensoren hängen denn max. an einem Bus ?
Es betrifft möglicherweise diesen, da hängen die meisten (20) dran:

Prof. Dr. Peter Henning

#57
OK, nächste Version. Ich habe da jetzt wirklich 3 Tage Arbeit hineingesteckt, und jetzt scheint es zu laufen.

00_OWX.pm
11_OWX_SER.pm
11_OWX_TCP.pm

in der Version 6.1alpha1

21_OWTHERM.pm
21_OWSWITCH.pm
21_OWVAR.pm
21_OWMULTI.pm

in der Version 6.1 hängen hier dran. Die Backendmodule können jetzt ganz wunderbar mit "disconnected" umgehen und machen nach einer einstellbaren Zeit das Interface neu auf. Die Frontendmodule habe ich massiv überarbeitet, Timingprobleme gelöst. OWSWITCH derzeit nur getestet mit DS2406, die anderen sollten aber kein Problem machen.

21_OWAD.pm und 21_OWID.pm sollte auch in der veröffentlichten Version keine Probleme bereiten. 21_OWCOUNT ist als Nächstes dran, dann 21_OWLCD.pm.

Für Testberichte bin ich dankbar. Und wer Spaß hat, sich die inneren Abläufe anzusehen, sollte mal das "debug"-Attribute auf alle drei verfügbaren Werte setzen.

LG

pah

UweH

Hallo pah,

Danke, bin am Testen.
Reconnect ohne Probleme, aber danach wieder tote DS2413. Lassen sich nicht mehr schalten. Beide DS2413 hängen am LAN-Interface. USB kann ich spätestens erst am Wochenende testen.
Die Schaltversuche mit den DS2413 hinterlassen keine Spuren im Log. Nach einem Neustart zwischendurch lassen sich die beiden auch wieder schalten. Ein neuerlicher Dis- und Reconnect bringt die gleichen Resultate.
Mit verbose 5 und den drei debug-Attributen sieht das so aus:

2017.03.08 19:38:29 1: OWX: Performing define and low level init of bus 1wire_Test
2017.03.08 19:38:29 1: OWX_TCP::Init called on device 192.168.178.37:23 for bus 1wire_Test, state is ???
2017.03.08 19:38:29 1: OWX_Init called for bus 1wire_Test with interface state opened, now going for detect
2017.03.08 19:38:29 1: OWX_TCP::Detect 1-Wire bus 1wire_Test: interface master DS2480 re-detected
2017.03.08 19:38:29 1: OWX: Performing define and low level init of bus 1wire_Test_2
2017.03.08 19:38:29 1: OWX_TCP::Init called on device 192.168.178.37:26 for bus 1wire_Test_2, state is ???
2017.03.08 19:38:29 1: OWX_Init called for bus 1wire_Test_2 with interface state opened, now going for detect
2017.03.08 19:38:29 1: OWX_TCP::Detect 1-Wire bus 1wire_Test_2: interface master DS2480 re-detected
2017.03.08 19:38:38 1: usb create starting
2017.03.08 19:38:38 1: usb create end
2017.03.08 19:38:38 0: Featurelevel: 5.8
2017.03.08 19:38:38 0: Server started with 46 defined entities (fhem.pl:13593/2017-03-04 perl:5.022001 os:linux user:fhem pid:10448)
2017.03.08 19:38:38 1: PERL WARNING: Use of uninitialized value $v in substitution (s///) at fhem.pl line 1019.
2017.03.08 19:38:38 1: PERL WARNING: Use of uninitialized value $v in concatenation (.) or string at fhem.pl line 1020.
2017.03.08 19:38:40 1: OWX: 1-Wire devices found on bus 1wire_Test (OWX_28_F09339050000)
2017.03.08 19:38:40 5: SW: e3c5
2017.03.08 19:38:41 5: SW: e1f0e3b5
2017.03.08 19:38:41 5: SW: e100000000000000000000000000000000e3a5
2017.03.08 19:38:41 5: SW: e3c5
2017.03.08 19:38:41 5: SW: e1f0e3b5
2017.03.08 19:38:41 5: SW: e120000000000000000000000000000000e3a5
2017.03.08 19:38:41 5: SW: e3c5
2017.03.08 19:38:42 5: SW: e1f0e3b5
2017.03.08 19:38:42 5: SW: e108000000000000000000000000000000e3a5
2017.03.08 19:38:42 5: SW: e3c5
2017.03.08 19:38:42 5: SW: e1f0e3b5
2017.03.08 19:38:42 5: SW: e188000000000000000000000000000000e3a5
2017.03.08 19:38:42 5: SW: e3c5
2017.03.08 19:38:43 5: SW: e1f0e3b5
2017.03.08 19:38:43 5: SW: e1880a0a00000000000000000000000000e3a5
2017.03.08 19:38:43 5: SW: e3c5
2017.03.08 19:38:43 5: SW: e1f0e3b5
2017.03.08 19:38:43 5: SW: e1880a0a00000000000000000000000000e3a5
2017.03.08 19:38:43 1: OWX: 1-Wire devices found on bus 1wire_Test_2 (Temp.AZ,Poti,DS2406,Aktor_2,Aktor_1)
2017.03.08 19:38:48 5: SW: e3c5
2017.03.08 19:38:48 5: SW: e3c5
2017.03.08 19:38:49 5: SW: e3c5
2017.03.08 19:38:49 5: SW: e3c5
2017.03.08 19:38:49 5: SW: e3c5
2017.03.08 19:38:50 5: SW: e3c5
2017.03.08 19:38:50 5: SW: e3c5
2017.03.08 19:38:51 5: SW: e3c5
2017.03.08 19:38:51 5: SW: e3c5
2017.03.08 19:39:10 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:24 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:26 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:26 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:34 5: SW: e3c5
2017.03.08 19:39:34 5: SW: e3c5
2017.03.08 19:39:41 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:43 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:43 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:39:48 5: SW: e3c5
2017.03.08 19:39:48 5: SW: e3c5
2017.03.08 19:39:54 5: SW: e3c5
2017.03.08 19:39:54 5: SW: e3c5
2017.03.08 19:39:58 5: SW: e3c5
2017.03.08 19:39:58 5: SW: e3c5
2017.03.08 19:40:01 5: SW: e3c5
2017.03.08 19:40:01 5: SW: e3c5
2017.03.08 19:40:05 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:40:10 5: SW: e3c5
2017.03.08 19:40:11 5: SW: e3c5
2017.03.08 19:40:13 5: SW: e3c5
2017.03.08 19:40:14 5: SW: e3c5
2017.03.08 19:40:17 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:40:20 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:40:31 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:40:38 5: SW: e3c5
2017.03.08 19:40:39 5: SW: e3c5
2017.03.08 19:40:44 5: SW: e3c5
2017.03.08 19:40:44 5: SW: e3c5
2017.03.08 19:41:44 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:41:46 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:41:55 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:42:01 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:43:42 5: SW: e3c5
2017.03.08 19:43:52 2: 1wire_Test_2: first attempt to read timed out, trying to close and open the device.
2017.03.08 19:43:52 3: Opening 1wire_Test_2 device 192.168.178.37:26
2017.03.08 19:43:54 3: Can't connect to 192.168.178.37:26: No route to host
2017.03.08 19:43:54 5: SW: e3c5
2017.03.08 19:43:54 2: 1wire_Test_2: second attempt to read timed out, this is an unrecoverable error.
2017.03.08 19:43:54 2: Attempt to write to disconnected device.
2017.03.08 19:43:54 2: Attempt to write to disconnected device.
2017.03.08 19:43:54 3: OWX: Failure in temperature conversion

2017.03.08 19:46:41 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:46:54 1: 192.168.178.37:26 reappeared (1wire_Test_2)
2017.03.08 19:47:42 1: 192.168.178.37:23 reappeared (1wire_Test)
2017.03.08 19:48:42 5: SW: e3c5
2017.03.08 19:48:42 5: SW: e1cc44
2017.03.08 19:51:42 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:53:42 5: SW: e3c5
2017.03.08 19:53:42 5: SW: e1cc44
2017.03.08 19:56:42 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 19:58:42 5: SW: e3c5
2017.03.08 19:58:42 5: SW: e1cc44
2017.03.08 20:01:43 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:03:42 5: SW: e3c5
2017.03.08 20:03:42 5: SW: e1cc44
2017.03.08 20:06:43 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:08:42 5: SW: e3c5
2017.03.08 20:08:42 5: SW: e1cc44
2017.03.08 20:11:44 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:13:42 5: SW: e3c5
2017.03.08 20:13:42 5: SW: e1cc44
2017.03.08 20:16:44 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:18:42 5: SW: e3c5
2017.03.08 20:18:42 5: SW: e1cc44
2017.03.08 20:21:45 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:23:42 5: SW: e3c5
2017.03.08 20:23:42 5: SW: e1cc44
2017.03.08 20:26:46 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:28:42 5: SW: e3c5
2017.03.08 20:28:42 5: SW: e1cc44
2017.03.08 20:31:46 5: OWX_Set request 1wire_Test_2 FF ?
2017.03.08 20:33:42 5: SW: e3c5
2017.03.08 20:33:42 5: SW: e1cc44
2017.03.08 20:35:14 5: OWX_Set request 1wire_Test_2 FF ?


Brauchst Du noch andere Daten?

Gruß
Uwe

Prof. Dr. Peter Henning

Hm, ich muss also erst noch einen DS2413 zum Testen irgendwo auflöten.

Das Log sieht mir noch etwas dünne aus - "asynchronous" ist sicher nicht gesetzt, sonst gäbe es dutzende von Queue-Einträgen.

LG

pah