OWX Next Generation

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

Vorheriges Thema - Nächstes Thema

Prof. Dr. Peter Henning

#150
Also erst einmal: Klar muss das in OWX behoben werden. Aber darüber hinaus müssen wir das auch verstehen, denn es sollte auch dann nicht auftreten, wenn ein Fehler in OWX auftritt.

Ich habe jetzt mal testweise den ganzen Startup-Code für OWX modifiziert - anderes Timing, andere Reihenfolge - und "Discover" erst nach einer ganzen Weile.

Es würde mich brennend interessieren, ob das Problem damit behoben ist, d.h., ob das wieder zum Verschwinden von Konfigurationsdaten führt.

LG

pah

det.

Hallo Peter,
Versuch macht klug - und durch - geht und zerschiesst die fhem.cfg nicht mehr!
Anbei das LOG seit Neustart:


Zitat2017.04.18 19:57:18 1: OWX: 1-Wire devices found on bus 1wire_4 (OWX_HZ_RAUM,OWCOUNT_STROM,OWCOUNT_WITT)
2017.04.18 19:57:16 1: =====================> Starting to discover on Bus 1wire_4
2017.04.18 19:57:16 1: OWX_SER::Detect 1-Wire bus 1wire_4: interface master DS2480 re-detected
2017.04.18 19:57:16 1: OWX_Init called for bus 1wire_4 with interface state opened, now going for detect
2017.04.18 19:57:16 1: OWX: 1-Wire devices found on bus 1wire_2 (OWX_Garten,Sauna_UG,Keller_UG,OWX_28_76B82A040000,OWSWITCH_WZLicht,OWSWITCH_Garten,OWCOUNT_KG)
2017.04.18 19:57:11 1: =====================> Starting to discover on Bus 1wire_2
2017.04.18 19:57:11 1: OWX_SER::Detect 1-Wire bus 1wire_2: interface master DS2480 re-detected
2017.04.18 19:57:11 1: OWX_Init called for bus 1wire_2 with interface state opened, now going for detect
2017.04.18 19:57:11 1: OWX: 1-Wire devices found on bus 1wire_0 (OWX_WW_ZIRK,OWX_HZ_VOR,OWX_WW_RUECK,OWX_WZ_Temp,OWX_WW_SP,OWX_HZ_RUECK,OWX_WW_VOR,OWSWITCHBoden,OWX_Vaillant,OWX_26_0A9116000000,OWX_WZ_Klima,Heizungsdruck,OWX_Wassermelder,Dachwetter,OWX_LCD1)
2017.04.18 19:57:01 1: =====================> Starting to discover on Bus 1wire_0
2017.04.18 19:57:01 1: OWX_SER::Detect 1-Wire bus 1wire_0: interface master DS2480 re-detected
2017.04.18 19:57:00 1: OWX_Init called for bus 1wire_0 with interface state opened, now going for detect
2017.04.18 19:57:00 1: OWX: 1-Wire devices found on bus 1wire_1 (BueroTemp_KG,Keller_KG,TKS_KG,Flur_KG,OWSWITCHB,OWX_LCD)
2017.04.18 19:57:00 1: OWX_SER::Search CRC failed on bus 1wire_1
2017.04.18 19:56:56 1: =====================> Starting to discover on Bus 1wire_1
2017.04.18 19:56:56 1: OWX_SER::Detect 1-Wire bus 1wire_1: interface master DS2480 detected for the first time
2017.04.18 19:56:56 1: OWX_Init called for bus 1wire_1 with interface state opened, now going for detect
2017.04.18 19:56:31 0: Server started with 448 defined entities (fhem.pl:14001/2017-04-15 perl:5.022001 os:linux user:fhem pid:31255)
2017.04.18 19:56:31 0: Featurelevel: 9.9
2017.04.18 19:56:28 1: usb create end
2017.04.18 19:56:27 1: usb create starting
2017.04.18 19:56:23 1: Including ./log/fhem.save
2017.04.18 19:56:18 1: PERL WARNING: "my" variable $host masks earlier declaration in same scope at ./FHEM/30_MilightBridge.pm line 72, <$fh> line 1226.
2017.04.18 19:56:17 1: PERL WARNING: "my" variable $value masks earlier declaration in same scope at ./FHEM/33_readingsGroup.pm line 1384, <$fh> line 1788.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 385, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 370, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 363, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 356, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 345, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 341, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: given is experimental at ./FHEM/98_PID20.pm line 339, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: when is experimental at ./FHEM/98_PID20.pm line 307, <$fh> line 1735.
2017.04.18 19:56:17 1: PERL WARNING: given is experimental at ./FHEM/98_PID20.pm line 305, <$fh> line 1735.
2017.04.18 19:56:17 1: OWID:     Device Tuer_Buero defined.
2017.04.18 19:55:56 1: HMLAN_Parse: HMLAN1 new condition init
2017.04.18 19:55:56 1: HMLAN_Parse: HMLAN1 new condition disconnected
2017.04.18 19:55:56 1: OWX_SER: opened serial device /dev/ttyUSB_OWX_eins: Illegal seek
2017.04.18 19:55:56 0: Strange call for nonexistent <undefined>: IOCloseFn
2017.04.18 19:55:56 1: OWX_SER::Init called on device /dev/ttyUSB_OWX_eins for bus 1wire_4, state is ???
2017.04.18 19:55:56 1: PERL WARNING: Use of uninitialized value in string ne at ./FHEM/11_OWX_SER.pm line 90, <$fh> line 142.
2017.04.18 19:55:56 1: OWX: Performing define and low level init of bus 1wire_4
2017.04.18 19:55:56 1: OWX_SER: opened serial device /dev/ttyUSB_OWX_zwei: Illegal seek
2017.04.18 19:55:56 0: Strange call for nonexistent <undefined>: IOCloseFn
2017.04.18 19:55:56 1: OWX_SER::Init called on device /dev/ttyUSB_OWX_zwei for bus 1wire_2, state is ???
2017.04.18 19:55:56 1: PERL WARNING: Use of uninitialized value in string ne at ./FHEM/11_OWX_SER.pm line 90, <$fh> line 135.
2017.04.18 19:55:56 1: OWX: Performing define and low level init of bus 1wire_2
2017.04.18 19:55:56 1: OWX_SER: opened serial device /dev/ttyUSB_OWX_oben: Illegal seek
2017.04.18 19:55:56 0: Strange call for nonexistent <undefined>: IOCloseFn
2017.04.18 19:55:56 1: OWX_SER::Init called on device /dev/ttyUSB_OWX_oben for bus 1wire_0, state is ???
2017.04.18 19:55:56 1: PERL WARNING: Use of uninitialized value in string ne at ./FHEM/11_OWX_SER.pm line 90, <$fh> line 128.
2017.04.18 19:55:56 1: OWX: Performing define and low level init of bus 1wire_0
2017.04.18 19:55:56 1: OWX_SER: opened serial device /dev/ttyUSB_OWX_unten: Illegal seek
2017.04.18 19:55:56 0: Strange call for nonexistent <undefined>: IOCloseFn
2017.04.18 19:55:56 1: OWX_SER::Init called on device /dev/ttyUSB_OWX_unten for bus 1wire_1, state is ???
2017.04.18 19:55:56 1: PERL WARNING: Use of uninitialized value in string ne at ./FHEM/11_OWX_SER.pm line 90, <$fh> line 121.
2017.04.18 19:55:56 1: OWX: Performing define and low level init of bus 1wire_1
2017.04.18 19:55:55 1: Including fhem.cfg
2017.04.18 19:55:55 1: PERL WARNING: main::mySonosStateAV() called too early to check prototype at ./FHEM/99_RpiUtils.pm line 51.
2017.04.18 19:55:53 1: Timeout for SIP_ListenStart reached, terminated process 28306
2017.04.18 19:55:51 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
2017.04.18 19:55:51 0: Server shutdown


LG det.
LG
det.

ext23

#152
Kann ich bestätigen, jetzt macht es keine Probleme mehr. (Async is noch aus, ich teste das die Tage mal)

/Daniel
HM, KNX, FS20, 1-Wire, PanStamp, AVR-NET-IO, EM1000EM, PCA301, EC3000, HM-LAN, CUL868, RFXtrx433, LGW, DMX @Ubuntu-Server (Hauptsystem) & Raspberry Pi (Satellit)

cwagner

Darf ich noch ein Thema (und möglicherweise damit einen Tropfen Essig) hinzufügen? Geht 00_OWX.pm mit CRC-Fehlern anders um als die Version vom 20.3.2016? Bin mir sehr sicher, dass all meine Probleme, nämlich nicht aktualisierte Readings meiner 25 Devices da den Ausgangspunkt haben. Bei allen Neustarts fällt ein initiales CRC-Check auf, wonach dann "Schluss" ist. Das wiederholt sich auch mit einem reopen.

2017.04.18 21:14:08 1: OWX_Init called for bus OWio1 with interface state opened, now going for detect
2017.04.18 21:14:08 1: OWX_SER::Detect 1-Wire bus OWio1: interface master DS2480 re-detected
2017.04.18 21:14:08 1: =====================> Starting to discover on Bus OWio1

2017.04.18 21:14:23 1: OWX_SER::Search CRC failed on bus OWio1

2017.04.18 21:14:29 1: PERL WARNING: Use of uninitialized value $sb in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 550.

auf.

Christian

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

Nach längerem Suchen ist die Ursache gefunden und in 00_OWX.pm behoben - das Problem liegt aber tiefer und sollte noch an anderer Stelle angegangen werden, sprich, in fhem.pl. Was ist nun die Ursache gewesen:

1. Auf Grund des vielschichtigen Initialisierungsprozesses in OWX (FHEM-Device, Hardware, Busmaster und Bus) gab es eine lokale Variable $init_done. Bei einer der Änderungen im Ende 2016 habe ich den Block auskommentiert, in dem "my $init_done;" deklariert wurde.

2. Damit griff das Modul auf die gloable Variable $init_done zu und setzte diese auf 1, sobald der 1-Wire Bus initialisiert war.

3. Unter FHEM 5.7 bewirkte das offensichtlich gar nichts, normaler Start.

4. Unter FHEM 5.8 sorgte das dafür, dass der Initialisierungsprozess auch an anderer Stelle gestoppt wurde, insbesondere, dass die "include"-Direktiven in der Konfigurationsdatei ignoriert wurden. Damit fehlten dann wesentliche Stücke von komplexeren Installationen, 1-Wire Devices waren aber auf Grund der Tatsache, dass der Bus schon gescannt war, unter ihrem generischen Namen vorhanden.

5. Weder bei Leuten mit einer einzigen Konfigurationsdatei, noch bei denjenigen, die configDB verwenden, zeigte sich diese Auswirkung. Sie ist offenbar auch abhängig von der allgemeinen Systemgeschwindigkeit, und davon, wie schnell die jeweilige Hardware initialisiert war.

LG

pah

ext23

Na das klingt ja gut. Dann haben wir das schonmal.

Eine andere Sache. Ich habe heute auf asyncron umgestellt, aber danach erkennt der alle paar Sekunden meine iButtons neu die gerade garnicht vorhanden sind. Ich polle diese alle 5 Sekunden. Manchmal beruhigt es sich, dann mache ich mal wieder was auf der FHEM Oberfläche dann geht das wieder los.

Im log sehe ich nur:
2017.04.19 08:31:04 1: OWX_SER::Search reset failed on bus MP00202
2017.04.19 08:31:07 1: OWX_SER::Search reset failed on bus MP00202
2017.04.19 08:31:09 1: OWX_SER::Search reset failed on bus MP00202


Auch ein reopen hilft nicht.

OWX: 1-Wire devices found on bus MP00202
01.xxxxxx160000      DS2401/DS1990A fl_iButton_blau
01.xxxxxx160000      DS2401/DS1990A fl_iButton_rot
01.xxxxxx140000      DS2401/DS1990A az_MP00202_Serial
FF.xxxx00000100      LCD            az_OW_LCD1
HM, KNX, FS20, 1-Wire, PanStamp, AVR-NET-IO, EM1000EM, PCA301, EC3000, HM-LAN, CUL868, RFXtrx433, LGW, DMX @Ubuntu-Server (Hauptsystem) & Raspberry Pi (Satellit)

det.

Zitat von: Prof. Dr. Peter Henning am 19 April 2017, 08:21:13
...
5. Weder bei Leuten mit einer einzigen Konfigurationsdatei, noch bei denjenigen, die configDB verwenden, zeigte sich diese Auswirkung. Sie ist offenbar auch abhängig von der allgemeinen Systemgeschwindigkeit, und davon, wie schnell die jeweilige Hardware initialisiert war.

LG

pah


leider Einspruch - ich habe nur eine fhem.cfg und einige Sachen in 99_myutils und der Effekt trat trotzdem auf
LG
det.

Prof. Dr. Peter Henning

Hm, Rudi König behauptet, das könne er nicht nachvollziehen.

Tatsache ist, dass $init_done unter FHEM 5.8 gefährliche Sachen macht, und zwar unterschiedlich für configDB und fhem.cfg.

LG

pah

pte

Sehe ich es richtig, dass OWX Next Generation nicht mit Firmata auf Arduino über Netzwerk arbeitet?
Lichtenstein/Sa. grüßt den Rest der Welt

Prof. Dr. Peter Henning


pte

Hm, dann kann ich noch nicht wechseln. Ich habe hält seit dem Update auf fhem 5.8 das Problem mit "Use of uninitialized value $outfnd in string eq at ./FHEM/21_OWSWITCH.pm line 1103" mit meinem DS2406


Gesendet von iPhone mit Tapatalk
Lichtenstein/Sa. grüßt den Rest der Welt

Prof. Dr. Peter Henning

Dann wäre es doch vielleicht sinnvoll, die exakte Versionsnummer des OWSWITCH anzugeben  ::)

pah

pte

Das hatte ich schon in einem separaten Thread "Fehlermeldung bei DS2406" angegeben. Konnto ich gestern vom Handy aus nur nicht einfügen.

siehe bitte unter: https://forum.fhem.de/index.php/topic,70641.0.html
Lichtenstein/Sa. grüßt den Rest der Welt

UweH

#163
Hallo pah,

die Version 6.3alpha11 tut sich schwer, einen Verbindungsabbruch zum LAN-Interface zu verdauen.
Bis die Interfaces auf "disconnect" gehen, dauert es über 20 min, in denen FEHM steht. Danach Stecker wieder rein und seitdem versucht OWX vergeblich, eine Verbindung aufzubauen. So sieht das Log seitdem aus:

2017.04.20 09:33:10 1: 192.168.178.37:26 disconnected, waiting to reappear (1wire_Test_2)
2017.04.20 09:48:39 1: 192.168.178.37:23 disconnected, waiting to reappear (1wire_Test)
2017.04.20 09:48:40 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:48:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:48:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:53:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:53:45 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:58:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 09:58:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:03:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:03:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:08:43 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:08:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:13:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:13:44 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:18:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:18:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:23:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:23:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:28:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:28:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:33:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:33:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:38:46 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:38:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:43:46 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:43:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:48:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:48:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:53:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:53:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:58:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 10:58:48 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 11:00:03 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 11:03:47 1: [OWX_PrQueue] removed garbage from queue top
2017.04.20 11:03:48 1: [OWX_PrQueue] removed garbage from queue top


Gruß
Uwe


EDIT: Ein manuelles "reopen" bringt die Interfaces sofort wieder...

Prof. Dr. Peter Henning

Tja, das hängt in dem Fall damit zusammen, dass ich jetzt die "DevIOSimpleReadWithTimeout" durch "DevIOSimpleRead" ersetzt habe - das mit den Timeouts ist extrem wackelig. Versuch doch mal, statt des 11_OWX_TCP.pm der Version 6.3alpha11 das aus Version 6.3alpha10 zu benutzen. Dann gibt es zwar irgendwo Gemecker, aber  vielleicht ist es dann eher stabil.

LG

pah