Z-Wave nach heutigem Update unbrauchbar

[m8ichael]

Hallo Andreas!

Hi,

sag mal, was hast Du sonst noch in FHEM "am Laufen"? Welche Module nutzt Du? Tipp mal "version" in das Befehlsfeld und poste mal die Liste.

Hier mal die Liste:

Code Auswählen Erweitern


ile                  Rev   Last Change

fhem.pl               10769 2016-02-08 12:11:51Z rudolfkoenig
95_Alarm.pm           10664 2016-01-30 11:36:17Z pahenning
90_at.pm              10594 2016-01-22 13:27:34Z rudolfkoenig
98_autocreate.pm      10651 2016-01-28 16:18:49Z rudolfkoenig
57_Calendar.pm        10790 2016-02-10 18:33:42Z borisneubert
95_Dashboard.pm       10344 2016-01-03 11:29:48Z talkabout
98_dummy.pm           10530 2016-01-16 19:27:21Z rudolfkoenig
91_eventTypes.pm      10530 2016-01-16 19:27:21Z rudolfkoenig
01_FHEMWEB.pm         10747 2016-02-07 07:39:16Z rudolfkoenig
92_FileLog.pm         10530 2016-01-16 19:27:21Z rudolfkoenig
98_Heating_Control.pm 10429 2016-01-09 17:37:05Z dietmar63
95_holiday.pm         10530 2016-01-16 19:27:21Z rudolfkoenig
98_HTTPMOD.pm          9127 2015-08-24 18:43:31Z ststrobel
91_notify.pm          10694 2016-02-01 06:43:00Z rudolfkoenig
70_ONKYO_AVR.pm       10559 2016-01-17 15:51:02Z loredo
99_SUNRISE_EL.pm      10569 2016-01-19 06:30:28Z rudolfkoenig
98_SVG.pm             10792 2016-02-10 20:20:49Z rudolfkoenig
98_telnet.pm          10551 2016-01-17 11:03:44Z rudolfkoenig
59_Twilight.pm         8743 2015-06-14 12:14:57Z dietmar63
99_Utils.pm           10570 2016-01-19 06:39:23Z rudolfkoenig
98_version.pm         10658 2016-01-29 19:43:10Z markusbloch
59_Weather.pm         10403 2016-01-07 19:44:04Z borisneubert
98_weblink.pm         10530 2016-01-16 19:27:21Z rudolfkoenig
98_WeekdayTimer.pm    10691 2016-01-31 19:23:01Z dietmar63
70_XBMC.pm            10601 2016-01-22 20:49:44Z vbs2
10_ZWave.pm           10782 2016-02-09 20:44:59Z rudolfkoenig
00_ZWDongle.pm        10584 2016-01-21 11:07:44Z rudolfkoenig

Blocking.pm           10343 2016-01-03 10:55:45Z rudolfkoenig
DevIo.pm               8954 2015-07-13 16:01:48Z rudolfkoenig
HttpUtils.pm          10698 2016-02-02 18:36:14Z rudolfkoenig
ONKYOdb.pm             6992 2014-11-16 00:10:16Z loredo
RTypes.pm             10476 2016-01-12 21:03:33Z borisneubert
SetExtensions.pm       9413 2015-10-09 13:13:11Z rudolfkoenig
TcpServerUtils.pm     10346 2016-01-03 12:34:27Z rudolfkoenig
WinService.pm          5819 2014-05-11 14:17:21Z rudolfkoenig
ZWLib.pm              10786 2016-02-10 06:37:59Z rudolfkoenig


Habe jetzt mal gerade nen radikalen Test gemacht: Habe die Standard-5.7-Version eingespielt. Tja, und damit läuft's ohne Probleme (zumindest kommen die get's sauber durch und auch die nodeList sieht wieder gut aus). Ein paar getestete AT's funktionieren auch. Nehme ich per "update" ein Update vor (Versionsstand dann wie oben), so kommen wieder die Probleme. Insofern schließe ich echte "Empfangsprobleme" nun endgültig aus. Es scheint sich wohl irgendwo ein Bug eingeschlichen haben, der sich auf meinem System auswirkt... 

Gruß

Michael

[A.Harrenberg]

Hi,

ja, aber der Fehler deutet ja mehr auf eine Netzwerkverbindung hin, wie gesagt, ersetz mal die ZWave-Befehle durch Befehle an Dummies. Ich denke das wird funktionieren. Dann bleiben die anderen Module die etwas mit Netzwerk zu tun haben, z.B. Weather, Calendar, ....

Ich weiß nicht ob Du evtl. mehr hilfreiche Info bekommst wenn Du mal global verbose = 5 setzt, aber vorsicht, die Logfiles werden dann recht schnell groß...

Gruß,
Andreas.

[rudolfkoenig]

@m8ichael:

- ich habe gerade mit einem aktuellen FHEM nodeList geprueft, weiterhin ein ZWave get via at gestartet, beides funktioniert ohne Probleme.

- die Ausgabe von deinem nodeList zeigt, dass FHEM keine ZWave Instanzen/Definitionen findet. Eine moegliche Ursache ist das alte ZWave Dongle/Stick mit einem neuen/leeren FHEM Konfiguration zu verwenden, eine Andere ist eine korrupte 10_ZWave.pm Datei, was von FHEM gar nicht geladen wird. Einen Programmierfehler in der letzten ZWave.pm Version (so wie man es anhand des Betreffs danken koennte) kann ich mir als Ursache deiner nodeList Ausgabe nicht vorstellen. Falls ich auf der falschen Faehrte bin: bitte in fhem.cfg "attr global verbose 5" setzen, FHEM starten, als erstes "get ZWDongle nodeList" ausfuehren, und das Log hier anhaengen.

- IO::Socket::INET: connect: timeout bei get, wenn das get ueber at laeuft: Seit der Aenderung in ZWave.pm blockieren per at oder notify abgesetzte ZWave get Befehle FHEM nicht(!) mehr. Als Nebenwirkung kann in einem anderen Modul das erwaehnte Problem auftreten, auch wenn ich noch Schwierigkeiten habe vorzustellen, wie. Um dieses Problem zu debuggen brauche ich auch ein log mit "attr global verbose 5", bitte auch von FHEM-Neustart an, da ich andere Module als Ursache vermute.

[m8ichael]

Guten Morgen!

@m8ichael:

- ich habe gerade mit einem aktuellen FHEM nodeList geprueft, weiterhin ein ZWave get via at gestartet, beides funktioniert ohne Probleme.

- die Ausgabe von deinem nodeList zeigt, dass FHEM keine ZWave Instanzen/Definitionen findet. Eine moegliche Ursache ist das alte ZWave Dongle/Stick mit einem neuen/leeren FHEM Konfiguration zu verwenden, eine Andere ist eine korrupte 10_ZWave.pm Datei, was von FHEM gar nicht geladen wird. Einen Programmierfehler in der letzten ZWave.pm Version (so wie man es anhand des Betreffs danken koennte) kann ich mir als Ursache deiner nodeList Ausgabe nicht vorstellen. Falls ich auf der falschen Faehrte bin: bitte in fhem.cfg "attr global verbose 5" setzen, FHEM starten, als erstes "get ZWDongle nodeList" ausfuehren, und das Log hier anhaengen.

Hier dann mal das Log:

Code Auswählen Erweitern


2016.02.13 10:05:48.778 5: Cmd: >get ZWAVE1 nodeList<
2016.02.13 10:05:48.778 4: ZWDongle get ZWAVE1 nodeList
2016.02.13 10:05:48.778 5: ZWDongle_Write 0002 ()
2016.02.13 10:05:48.778 5: SW: 01030002fe
2016.02.13 10:05:48.782 4: ZWDongle_ReadAnswer arg:nodeList regexp:^0102
2016.02.13 10:05:48.782 5: ACK received, removing 01030002fe from dongle sendstack
2016.02.13 10:05:51.783 4: ZWDongle_Read ZWAVE1: sending ACK, processing 010205001dfffff1af0f0000000000000000000000000000000000000000000000000500
2016.02.13 10:05:51.783 5: SW: 06
2016.02.13 10:05:51.787 4: ZWDongle_ReadAnswer for nodeList: 010205001dfffff1af0f0000000000000000000000000000000000000000000000000500
2016.02.13 10:05:51.787 4: name: /fhem?detail=ZWAVE1&dev.getZWAVE1=ZWAVE1&cmd.getZWAVE1=get&arg.getZWAVE1=nodeList&val.getZWAVE1=&XHR=1&addLinks=1&fw_id=146 / RL:162 / text/plain; charset=UTF-8 / Content-Encoding: gzip


- IO::Socket::INET: connect: timeout bei get, wenn das get ueber at laeuft: Seit der Aenderung in ZWave.pm blockieren per at oder notify abgesetzte ZWave get Befehle FHEM nicht(!) mehr. Als Nebenwirkung kann in einem anderen Modul das erwaehnte Problem auftreten, auch wenn ich noch Schwierigkeiten habe vorzustellen, wie. Um dieses Problem zu debuggen brauche ich auch ein log mit "attr global verbose 5", bitte auch von FHEM-Neustart an, da ich andere Module als Ursache vermute.

Oh, da habe ich mich falsch ausgedrückt.  Der Fehler kommt entweder, wenn ein Befehl per AT ausgeführt wird, oder man manuell ein "get" absetzt. Log schicke ich!

Viele Grüße

Michael

[A.Harrenberg]

Hi Michael,

bitte das Log ab dem Neustart posten damit man sieht was vorher evtl. schon schief gegangen ist.

Gruß,
Andreas.

[m8ichael]

Hallo zusammen,

anbei das Log.

Könnt ihr da etwas erkennen?

Viele Grüße

Michael

[A.Harrenberg]

Hi, ich kann da nicht viel erkennen, aber da meckert irgendwas in Verbindung mit der Heizung das Klammern und auch Anführungszeichen nicht passen. Falls da wirklich was nicht passt dann kommt FHEM natürlich beim Einlesen der cfg Datei mächtig durcheinander. Schau mal ob Du den/die Fehler in der Konfiguration finden kannst...

Gruß,
Andreas.

[m8ichael]

Hallo Andreas,

Hi, ich kann da nicht viel erkennen, aber da meckert irgendwas in Verbindung mit der Heizung das Klammern und auch Anführungszeichen nicht passen. Falls da wirklich was nicht passt dann kommt FHEM natürlich beim Einlesen der cfg Datei mächtig durcheinander. Schau mal ob Du den/die Fehler in der Konfiguration finden kannst...

Ich habe jetzt mal das ganze Heizungsgerödel testweise aus der cfg herausgeschmissen - das Problem besteht jedoch weiterhin. Setze ich ein "get ZWDONGLE nodeList" ab, so erhalte ich bspw. weiterhin die UNKNOWN-Nodes (siehe oben). Und auch die übrigen Probleme bestehen weiterhin...Mist... 

Mir ist auch gerade aufgefallen, dass bei einigen Geräten das "Timeout" sofort beim klicken auf "get" kommt. Dabei zufällig wechselnd zwischen "Timeout" und "IO::Socket::INET: connect: timeout". Sehr strange...

Viele Grüße

Michael

[A.Harrenberg]

Hi,

mir scheint das da einiges an der cfg durcheinander/kaputt zu sein. Vielleicht hat Rudi noch eine Idee...

Gruß,
Andreas.

[rudolfkoenig]

anbei das Log.
Könnt ihr da etwas erkennen?

Ja: keiner der beschriebenen Probleme ist im Log protokolliert.
D.h. ich habe jetzt 10 Minuten lang umsonst FHEM-Logs gelesen.

[m8ichael]

Ja: keiner der beschriebenen Probleme ist im Log protokolliert.
D.h. ich habe jetzt 10 Minuten lang umsonst FHEM-Logs gelesen.

Sorry, hatte dich so verstanden, dass ich den Log des Systemstarts schicken sollte...  Hier dann noch mal einen Gesamtlog. Der erste Fehler tritt in Zeile 5568 auf (nodeList --> nur UNKNOWN-Nodes). Danach gibt es ein Problem beim Abfragen der neighborList (Zeile 5648 bzw. Zeile 5744).

mir scheint das da einiges an der cfg durcheinander/kaputt zu sein. Vielleicht hat Rudi noch eine Idee...

Macht es Sinn, die cfg nochmal neu zu sortieren? Oder macht das FHEM intern automatisch?

[rudolfkoenig]

nodeList bug: im letzten Log konnte das FHEM-ZWDongle-Modul den ZWave-Stick nicht initialisieren, im vorletzten log hat das funktioniert. Das Problem ist zu sehen als Fehlermeldung "ZWAVE1: SOF missing (got 67 instead of 01)"  auf Level 1 im FHEM-Log. Deswegen war das homeId des Sticks nicht bekannt, deswegen konnte nodeList die Nodes nicht finden und hat UNKNOWN gemeldet. Workaround1: "attr ZWAVE1 nodeId c0bcc8ab". Ich habe in 3 Minuten 9 solche Fehlermeldungen gezaehlt, d.h. die Kommunikation zwischen FHEM und ZWave Stick ist kaputt. Das kann entweder an dem Stick alleine, oder an der FHEM@Windows und Genau-Dieser-Stick Kombination liegen.

IO::Socket bzw Timeout Meldungen habe ich im Log nicht gefunden.

[rudolfkoenig]

Macht es Sinn, die cfg nochmal neu zu sortieren? Oder macht das FHEM intern automatisch?

Beim Sortieren muss man vorsichtig sein, da es Abhaengigkeiten gibt: z.Bsp. setzt ein ZWave Instanz das Vorhandensein des passenden ZWDongle voraus.
FHEM sortiert nicht, ich wuesste auch nicht, wozu das in diesem Fall gut sein sollte.

[m8ichael]

Hallo zusammen,

habe nun einmal verschiedenste Tests durchgeführt - auch dank deiner guten Hinweise, Rudi...  Das Problem scheint doch etwas vielschichtiger zu sein, als ursprünglich von mir angenommen. Einerseits scheint ein Routingproblem innerhalb des Z-Wave-Netzes vorgelegen zu haben. Dieses resultierte wohl aus Nodes, die nicht ordnungsgemäß exkludiert wurden, sodass es zu Fehlroutings und damit zu Timeouts kam. Vielleicht reagiert die neue Version hierauf etwas empfindlicher (geringere Timeout-Zeit?), sodass nach dem Update das Problem aufgetaucht ist, obwohl es ursächlich schon früher bestand. Insofern läuft hier jetzt vieles viel flüssiger und nack's treten so gut wie nicht mehr auf!

Andererseits ist seit dem Update mit dem Fehler "IO::Socket::INET..." ein Problem aufgetaucht, was laut Fhem-Log bei mir erst seit dem Update besteht. Ich habe daraufhin testweise die Version 5.7 eingespielt (ohne anschließende Updates), und bis jetzt ist der Fehler nicht wieder aufgetaucht. Das sagt nicht wirklich etwas, da der Fehler auch mit den Updates nur sporadisch aufgetreten ist (und da auch nur bei at's bzw. manuellen get's), aber ein Test ist es wert...

Ich werde daher weiter testen und berichten!

Gruß

Michael

[m8ichael]

Hallo zusammen,

das ist wirklich zum Haareherausraufen: wechsle ich zur 5.7-Ursprungsversion, so läuft alles glatt; spiele ich dann die Updates ein, so taucht wieder mein 'Lieblingsfehler' auf.     So dann gerade das für mich nichtssagende Errorlog erhalten:

Code Auswählen Erweitern


2016.02.15 22:45:00.031 5: exec at command ATEingangsbeleuchtungAus
2016.02.15 22:45:00.032 5: Cmd: >set eg.fl.Eingang.Stimmungsbeleuchtung,div.Schalter2 off<
2016.02.15 22:45:00.032 3: ATEingangsbeleuchtungAus: IO::Socket::INET: connect: timeout IO::Socket::INET: connect: timeout
2016.02.15 22:45:00.032 5: redefine at command ATEingangsbeleuchtungAus as *22:45 set eg.fl.Eingang.Stimmungsbeleuchtung,div.Schalter2 off


Oder heute auch bei einem notify:

Code Auswählen Erweitern


2016.02.15 19:20:30.751 5: Cmd: >set dm.og.sz.Hauptbeleuchtung 42<
2016.02.15 19:20:30.751 4: dummy set dm.og.sz.Hauptbeleuchtung 42
2016.02.15 19:20:30.751 5: Triggering dm.og.sz.Hauptbeleuchtung (1 changes)
2016.02.15 19:20:30.751 5: Notify loop for dm.og.sz.Hauptbeleuchtung 42
2016.02.15 19:20:30.752 5: Triggering dm.og.sz.Hauptbeleuchtung.notify
2016.02.15 19:20:30.752 4: dm.og.sz.Hauptbeleuchtung.notify exec set og.sz.Hauptbeleuchtung dim $EVENT
2016.02.15 19:20:30.752 5: Cmd: >set og.sz.Hauptbeleuchtung dim $EVENT<
2016.02.15 19:20:30.752 3: dm.og.sz.Hauptbeleuchtung.notify return value: IO::Socket::INET: connect: timeout
2016.02.15 19:20:30.754 4: name: /fhem?cmd=set%20dm.og.sz.Hauptbeleuchtung%2042&XHR=1&fw_id=144 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip /


Hat jemand dazu noch eine Idee? Oder muss ich auf der 5.7-Urversion bleiben?

Viele Grüße!

Michael