Für Elsner Wetterstationen mit RS485-Schnittstelle ist nun ein neues Modul ElsnerWS fertig. Der Sensor sendet unidirektional Datentelegramme im Sekundentakt. Falls der Sensor über den RS485-USB-Transceiver betriebsbereit ist und permanent sendet, das device aber noch nicht definiert ist, blockiert Fhem beim Start in der autocreate-Routine sobald die entsprechende Schnittstelle getestet wird.
Also war die erste Idee einen Zusatzeintrag in der autocreate usbtable mit den hoffentlich passenden Einträgen anzuhängen:
{ NAME => "ElsnerWS",
matchList => ["cu.usbserial(.*)", "cu.usbmodem(.*)",
"ttyUSB(.*)", "ttyACM(.*)", "ttyAMA(.*)"],
DeviceName=> "DEVICE\@19200",
flush => "\n",
timeout => 2.0,
request => "\x00", # SOH NUL STX NUL ENQ ETX EOT
response => "^(W\+|W\-|G\+|G\-)(.*)",
define => "WS_PARAM ElsnerWS comtype=rs485 devicename=DEVICE\@19200", },
Der request-Eintrag wäre ja grundsätzlich nicht notwendig, da das Gerät ja ohnehin permanent periodisch sendet.
...
2019.04.28 20:31:46 2: TCM TCM310_0 initialized
2019.04.28 20:31:46 1: usb create starting
2019.04.28 20:31:47 3: Probing ZWDongle device /dev/serial0
2019.04.28 20:31:47 3: Probing CUL device /dev/ttyAMA0
2019.04.28 20:31:47 3: Probing TCM_ESP3 device /dev/ttyAMA0
2019.04.28 20:31:47 3: Probing ZWDongle device /dev/ttyAMA0
2019.04.28 20:31:48 3: Probing SIGNALDuino device /dev/ttyAMA0
2019.04.28 20:31:48 3: Probing MYSENSORS device /dev/ttyAMA0
2019.04.28 20:31:48 3: Probing ArduCounter device /dev/ttyAMA0
2019.04.28 20:31:48 3: Probing FRM device /dev/ttyAMA0
2019.04.28 20:31:53 3: Probing ElsnerWS device /dev/ttyAMA0
2019.04.28 20:31:54 3: Probing TCM_ESP3 device /dev/ttyUSB1
2019.04.28 20:31:54 3: Probing TCM_ESP2 device /dev/ttyUSB1
2019.04.28 20:31:54 3: Probing FHZ device /dev/ttyUSB1
2019.04.28 20:31:55 3: Probing TRX device /dev/ttyUSB1
2019.04.28 20:31:56 3: Probing ZWDongle device /dev/ttyUSB1
2019.04.28 20:31:56 3: Probing SIGNALDuino device /dev/ttyUSB1
2019.04.28 20:31:56 3: Probing MYSENSORS device /dev/ttyUSB1
2019.04.28 20:31:56 3: Probing ArduCounter device /dev/ttyUSB1
2019.04.28 20:31:57 3: Probing FRM device /dev/ttyUSB1
2019.04.28 20:39:24 3: Probing ElsnerWS device /dev/ttyUSB1
Dennoch blockiert Fhem weiterhin. Steckt man das Gerät ab, startet Fhem. Dann kann man das Gerät einstecken und das Modul mit define problemlos manuell starten. Gibt es da einen Trick?
Kannst Du bitte ein "attr global verbose 5 log" hier zeigen? Die letzten Zeilen vor dem Haengen reichen.
autocreate scheint nur in dem FRM-Profil ein Problem mit den Sensortelegrammen zu haben:
2019.04.29 20:18:03 1: usb create starting
2019.04.29 20:18:03 3: Probing ZWDongle device /dev/serial0
2019.04.29 20:18:03 5: SW: 01030020dc06
2019.04.29 20:18:03 5: answer:
2019.04.29 20:18:03 4: wrong answer
2019.04.29 20:18:04 3: Probing CUL device /dev/ttyAMA0
2019.04.29 20:18:04 5: SW: 0a
2019.04.29 20:18:04 5: SW: 560a
2019.04.29 20:18:04 5: answer:
2019.04.29 20:18:04 4: wrong answer
2019.04.29 20:18:04 3: Probing TCM_ESP3 device /dev/ttyAMA0
2019.04.29 20:18:04 5: SW: 5500010005700838
2019.04.29 20:18:04 5: answer:
2019.04.29 20:18:04 4: wrong answer
2019.04.29 20:18:04 3: Probing ZWDongle device /dev/ttyAMA0
2019.04.29 20:18:04 5: SW: 01030020dc06
2019.04.29 20:18:04 5: answer:
2019.04.29 20:18:04 4: wrong answer
2019.04.29 20:18:04 3: Probing SIGNALDuino device /dev/ttyAMA0
2019.04.29 20:18:04 5: SW: 0a
2019.04.29 20:18:04 5: SW: 560a
2019.04.29 20:18:04 5: answer:
2019.04.29 20:18:05 4: wrong answer
2019.04.29 20:18:05 3: Probing MYSENSORS device /dev/ttyAMA0
2019.04.29 20:18:05 5: SW: 0a
2019.04.29 20:18:05 5: SW: 303b3235353b333b303b31380a
2019.04.29 20:18:05 5: answer:
2019.04.29 20:18:05 4: wrong answer
2019.04.29 20:18:05 3: Probing ArduCounter device /dev/ttyAMA0
2019.04.29 20:18:05 5: SW: 0a
2019.04.29 20:18:05 5: SW: 680a
2019.04.29 20:18:05 5: answer:
2019.04.29 20:18:05 4: wrong answer
2019.04.29 20:18:05 3: Probing FRM device /dev/ttyAMA0
2019.04.29 20:18:05 5: SW: f9
2019.04.29 20:18:10 5: SW: f079f7
2019.04.29 20:18:10 5: answer:
2019.04.29 20:18:10 4: wrong answer
2019.04.29 20:18:10 3: Probing ElsnerWS device /dev/ttyAMA0
2019.04.29 20:18:10 5: SW: 0a
2019.04.29 20:18:10 5: SW: 00
2019.04.29 20:18:10 5: answer:
2019.04.29 20:18:10 4: wrong answer
2019.04.29 20:18:10 4: ttyUSB0 is already used by the fhem device TCM310_0
2019.04.29 20:18:10 3: Probing TCM_ESP3 device /dev/ttyUSB1
2019.04.29 20:18:11 5: SW: 5500010005700838
2019.04.29 20:18:11 5: answer:
2019.04.29 20:18:11 4: wrong answer
2019.04.29 20:18:11 3: Probing TCM_ESP2 device /dev/ttyUSB1
2019.04.29 20:18:11 5: SW: a55aab5800000000000000000003
2019.04.29 20:18:11 5: answer:
2019.04.29 20:18:11 4: wrong answer
2019.04.29 20:18:11 3: Probing FHZ device /dev/ttyUSB1
2019.04.29 20:18:11 5: SW: 8105044fc90185
2019.04.29 20:18:11 5: answer:
2019.04.29 20:18:11 4: wrong answer
2019.04.29 20:18:11 3: Probing TRX device /dev/ttyUSB1
2019.04.29 20:18:11 5: SW: 0d00000000000000000000000000
2019.04.29 20:18:12 5: SW: 0d00000102000000000000000000
2019.04.29 20:18:12 5: answer:
2019.04.29 20:18:12 4: wrong answer
2019.04.29 20:18:12 3: Probing ZWDongle device /dev/ttyUSB1
2019.04.29 20:18:12 5: SW: 01030020dc06
2019.04.29 20:18:12 5: answer:
2019.04.29 20:18:12 4: wrong answer
2019.04.29 20:18:12 3: Probing SIGNALDuino device /dev/ttyUSB1
2019.04.29 20:18:12 5: SW: 0a
2019.04.29 20:18:13 5: SW: 560a
2019.04.29 20:18:13 5: answer:
2019.04.29 20:18:13 4: wrong answer
2019.04.29 20:18:13 3: Probing MYSENSORS device /dev/ttyUSB1
2019.04.29 20:18:13 5: SW: 0a
2019.04.29 20:18:13 5: SW: 303b3235353b333b303b31380a
2019.04.29 20:18:13 5: answer:
2019.04.29 20:18:13 4: wrong answer
2019.04.29 20:18:13 3: Probing ArduCounter device /dev/ttyUSB1
2019.04.29 20:18:13 5: SW: 0a
2019.04.29 20:18:13 5: SW: 680a
2019.04.29 20:18:13 5: answer:
2019.04.29 20:18:13 4: wrong answer
2019.04.29 20:18:13 3: Probing FRM device /dev/ttyUSB1
2019.04.29 20:18:13 5: SW: f9
##### Fhem blockiert ohne device Defintion
##### und weiter nach ausstecken des Sensors
2019.04.29 20:24:59 5: SW: f079f7
2019.04.29 20:24:59 5: answer:
2019.04.29 20:24:59 4: wrong answer
2019.04.29 20:24:59 3: Probing ElsnerWS device /dev/ttyUSB1
2019.04.29 20:24:59 5: SW: 0a
2019.04.29 20:24:59 5: SW: 00
2019.04.29 20:24:59 5: answer:
2019.04.29 20:24:59 4: wrong answer
2019.04.29 20:24:59 1: usb create end
Ich habe deshalb die Definitioen für das ElsnserWS-Modul
{ NAME => "ElsnerWS",
matchList => ["cu.usbserial(.*)", "cu.usbmodem(.*)",
"ttyUSB(.*)", "ttyACM(.*)", "ttyAMA(.*)"],
DeviceName=> "DEVICE\@19200",
flush => "\x03", # ETX end of telegram
timeout => 2.0,
request => "\x00", # no request needed
response => "^(W\+|W\-|G\+|G\-)(.*)",
define => "WS_PARAM ElsnerWS comtype=rs485 devicename=DEVICE\@19200", },
vor die FRM-Definition gestellt. Damit ist es mir einmal gelungen, ein Devise automatisch anzulegen. Wahrscheinlich müsste autocreate zuerst auf das Ende eines periodisch gesendeten Telegramms warten und dann den Beginn des nächsten Telegramms auswerten.
Die Diagramme beginnen mit G+, G-, W+ oder W- und enden mit ETX (0x03). regex für die response-Auswertung passet wohl grundsätzlich. ETX (0x03) in flush dagegen scheint ein Leeren des Eingangspuffers nach dessen Empfang und das warten auf das nächste Telegramm nicht zu bewirken. Gibt es einen andere Lösung dafür?
Ich habe FRM erstmal aus der autocreate/usbtable entfernt, da es auch in anderen Faellen zu einem lockup gefuehrt hat.
Erklaeren kann ich es nicht, da es spaetestens nach 5s weitergehen sollte.
Koenntest du bitte (mit aktivierten FRM in autocreate) ein strace Log des Haengens hier anhaengen?
Ich habe autocreate modifiziert, sodass der Sensor jetzt bei Fhem-Start bisher ohne Probleme zuverlässig erkannt und eingerichtet wird. Die geänderte Datei sende ich mit. Die beiden geänderten Bereiche sind mit ##### abgegrenzt.
Falls request in der Profildefinition nicht gesetzt ist, wird DevIo_TimeoutRead mit einem timeout = x unmittelbar aufgerufen und auf das komplette Empfangspaket (W\+|W\-|G\+|G\-)(.*)\x03 geprüft.
Da die Pakete im Sekundentakt gesendet werden und damit sichergestellt ist, dass ein komplettes Paket in dieser Zeit empfangen wird, wollte ich ein timeout von 1.1 s bis 1.2 s vorgeben. Dabei blockierte Fhem wie bei dem FRM-Profil. Dies aber erst, nachdem ich für den Test das an letzter Stelle im hash stehende FRM-Profil herauskommentiert hatte. Nachdem ich den timeout auf 0.9 s gesetzt habe, war der Fehler weg. Ergebnis: timeout muss beim letzten Profil im hash < 1 sein.
Ich hoffe das hilft etwas bei der Fehlersuche. Falls ein strace log noch benötigt wird, bitte nochmals melden.
Ich würde mich freuen, falls die Änderungen übernommen würden. Nach Beseitigung des Fehlers würde ich dann gerne noch den timeout mit 1.1 s bis 1.2 s testen. Das neue Modul ElsnerWS sende ich zur Info mit.
Ich uebernehme gerne die Aenderungen, ich wuerde aber gerne das Problem fixen.Kennst Du einen Weg, das Problem auch ohne dein Hardware nachzustellen?
Zitat von: rudolfkoenig am 29 April 2019, 23:10:32
Ich habe FRM erstmal aus der autocreate/usbtable entfernt, da es auch in anderen Faellen zu einem lockup gefuehrt hat.
Der autocreate-Ablauf für FRM verwendet ein Firmata-Reset für
init. Wenn tatsächlich ein Firmata-Device an der USB-Schnittstelle hängt, kann das in (eher seltenen) Einzelfällen ein Hängen der USB-Schnittstelle verursachen, so dass man z.B. das Firmata-Device abziehen muss oder sogar ein Boot erforderlich wird. Selbst wenn der Firmata-Reset erfolgreich ist, kann es aber je nach Firmata-Device auch mal länger als 5 Sekunden dauern, bis das Device wieder über USB ready ist.
Im Normalfall dürfte der
request bei einem Firmata-Device auch ohne vorherigen Reset erfolgreich sein. Andererseits ist schwer vorherzusagen, in welchem Zustand sich das Firmata-Device nach den vorherigen autocreate Telegrammen für anderen Devices befindet, so dass der Firmata-Reset an sich eine gute Idee ist. Es ist wahrscheinlich auch möglich, ein Firmata-Telegramm zu definieren, dass jedes vorherige Telegramm abschließt ohne einen Reset auszulösen.
Der 5-Sekunden-Timeout müsste aber all diese kleinen Abgründe überbrücken. Vor allem hat das nichts mit dem FRM-Modul zu tun, wenn eigentlich ein anderes Device angeschlossen ist, denn wenn ich autocreate richtig verstehe, wird ein Device erst mit define angelegt, wenn der Test erfolgreich war. Wenn der Test aber hängen bleibt, ist die Blockade wahrscheinlich in Richtung OS-USB-Treiber zu suchen.
Wenn gewünscht könnte ich prüfen, ob es ein alternatives init-Telegramm für FRM gibt.
Zitat von: rudolfkoenig am 30 April 2019, 20:19:16
Ich uebernehme gerne die Aenderungen, ich wuerde aber gerne das Problem fixen.Kennst Du einen Weg, das Problem auch ohne dein Hardware nachzustellen?
Mir fällt da leider keine Alternative ein. Ich mache aber natürlich traces, wenn es hilft.
ZitatIch mache aber natürlich traces, wenn es hilft.
Gerne. Am besten mit zusaetzlichen Angaben wie Zeitstempel und Pid
Bei strace bin ich nicht wirklich fit. Eine Standardabfrage wie
strace -p PIDvonFHEM -ttT -o strace.log
bringt hier wegen dess notwendigen Fhem restart nichts, da sich die PID dabei ändert. Wie kann ich einen trace über den Fhem restart hinaus laufen lassen?
Ich meine -f (fuer follow-fork) sollte helfen.
Alternativ fhem unter strace starten: "strace -f -t -o /tmp/xy perl fhem.pl fhem.cfg"
Hier die Ergebnisse mit der -f Option:
LOG autocreate_frm_error mit PID 12304 bis Blockade
LOG autocreate_frm_continue.log mit PID 12446 zum Weiterlauf nach Abstecken des RS485-Gerätes
Das verwendete autocreate-Modul hänge ich auch an.
Danke.
Ich brauche scheinbar solche Logs, damit ich das Offensichtliche sehe: DevIo_TimeoutRead zu verwenden, um maximal 5 Sekunden zu warten ist Nonsens.
Ich habe jetzt diese Zeile gegen:
DevIo_SimpleReadWithTimeout($hash, $thash->{timeout} ? $thash->{timeout}:0.5);ausgetauscht, was evtl. immer noch nicht perfekt ist, aber hoffentlich weniger Nonsens als bisher.
Gut damit ist jetzt das Problem bei "init" gelöst.
Leider bleibt aber noch ein Fehler, da für ein Abfrageinterval >= 1 bei der ElsnerWS Prüfung im "request/reponse" Block Fhem weiterhin blockiert. Warum auch immer 1 s scheinbar die Grenze ist.
Versuchsweise habe ich daher "DevIo_SimpleReadWithTimeout" auch dafür einsetzen wollen. Die Funktion liefert aber immer "undef" zurück, obwohl im Abfrageinterval mindestens ein Datenpaket angekommen sein muss. Die Änderungen habe ich im Quelltext mit ## markiert, siehe Anlage.
Vielleicht gibt es auch dafür eine Lösung. Falls augenblicklich eine zündende Idee fehlt, könnte man für die ElsnerWS Prüfung auch mit einem timeout von 0.9 an den Start gehen. Die Wahrscheinlichkeit, dass in dieser Zeit keine Daten angekommen sind ist eher gering. Sauberer wäre natürlich ein Zeitraum von > 1 s.
ZitatLeider bleibt aber noch ein Fehler, da für ein Abfrageinterval >= 1 bei der ElsnerWS Prüfung im "request/reponse" Block Fhem weiterhin blockiert.
Kannst du mir bitte dafuer auch ein strace Log liefern?
# strace für die Konstellation:
- Profil ElsnerWS mit timeout 1.9 s
- Einlesen der Daten mit $answer = DevIo_SimpleReadWithTimeout($hash, $thash->{timeout} ? $thash->{timeout} : 0.5);
# Fhem-LOG:
- 2019.05.07 15:06:39 1: PERL WARNING: Use of uninitialized value $answer in pattern match (m//) at ./FHEM/98_autocreate.pm line 663.
# Ergebnis: Fhem blockiert nicht, legt aber auch kein Device an, da der Empfangsstring nicht zurückgegeben wird und ausgewertet werden kann.
# verwendete autocreate-Datei siehe Anlage
DevIo_TimoutRead wartet solange, bis timeout lang _nichts_ gesendet wird.
DevIo_SimpleReadWithTimeout wartet entweder bis zum timeout, oder bis _etwas_ (mind 1 Byte) zurueckgeliefert wird.
Ich meine in deinem Fall muss man entweder bis zum timeout von 1.1Sekunden warten oder bis ein komplettes Telegramm angekommen ist.
Ich habe DevIo_TimeoutRead erweitert, damit es beim Emfang von bestimmten Datenmenge auch terminiert, und ElsnerWS mit einem maxLen von 32 eingebaut.
Wg. dem .* war ich beim maxLen nicht sicher, deswegen bitte ich Dich es zu kontrollieren.
Mit folgenden Parametern geht's:
timeout => 0.9,
maxLen => 64,
Bei
timeout => 1.1,
maxLen => 32,
wird Datensatz nicht erkannt, da Datensatz <= 61 Byte ist. autocreate blockiert dabei aber weiterhin. Das Abbruchkriterium maxLen scheint nicht zu greifen.
Bei timeout = 1.1 müsste maxLen >= 122 sein, da in dem Zeitraum zwei Datensätze empfangen werden. Einer der beiden Datensätze kann auch unvollständig sein, falls eine Sendeperiode am Ende oder zu Beginn der Empfangsperiode liegt. Leider blockiert aber auch die Variante
timeout => 1.1,
maxLen => 128,
0.9/64 klappt, wenn autocreate nicht gerade ein Teilpaket am Anfang erwischt. Die Wahrscheinlichkeit dafuer liegt bei 1-61*9/19200 also ca 97%.
Dass 1.1/128 blockiert, finde ich merkwuerdig, da nach 2-3 Sekunden die 128 Bytes gelesen werden sollten.
Kannst Du bitte fuer den Fall mir ein strace output schicken?
Ich habe jetzt eine neue Variante mit 1.0 und 127 eingecheckt.
Weiterhin hat DevIo_TimeoutRead einen optionalen vierten Parameter (regexp) bekommen, mit dem die Daten geprueft, und evtl. frueher als maxlen zurueckgeliefert werden.
Den Wahrscheinlichkeitswert glaube ich gerne. Die Praxis bestätigt dies. Bisher hatte ich während der ganzen Tests nur einen Fall, bei dem der Sensor nicht erkannt wurde. Andererseits liegt meine ernsthafte Beschäftigung mit statistischen Berechnungen im Studium Jahrzehnte zurück.
Mit den Parametern 1.1/128 zeigt sich jetzt ein neuer Effekt. Fhem blockiert wie bisher beim shutdown. Ziehe ich dann aber während der Blockade das Gerät von der Schnittstelle ab, löst sich die Blockade und nach dem erneuten Stecken des Gerätes wird es sofort erkannt und eingerichtet. Bisher wurde es beim Einstecken nicht eingerichtet.
2019.05.11 21:14:50 1: usb create starting
2019.05.11 21:14:50 3: Probing ZWDongle device /dev/serial0
2019.05.11 21:14:51 3: Probing CUL device /dev/ttyAMA0
2019.05.11 21:14:51 3: Probing TCM_ESP3 device /dev/ttyAMA0
2019.05.11 21:14:51 3: Probing ZWDongle device /dev/ttyAMA0
2019.05.11 21:14:51 3: Probing SIGNALDuino device /dev/ttyAMA0
2019.05.11 21:14:51 3: Probing MYSENSORS device /dev/ttyAMA0
2019.05.11 21:14:52 3: Probing ArduCounter device /dev/ttyAMA0
2019.05.11 21:14:52 3: Probing ElsnerWS device /dev/ttyAMA0
2019.05.11 21:14:53 3: Probing FRM device /dev/ttyAMA0
2019.05.11 21:14:58 3: Probing TCM_ESP3 device /dev/ttyUSB1
2019.05.11 21:14:58 3: Probing TCM_ESP2 device /dev/ttyUSB1
2019.05.11 21:14:58 3: Probing FHZ device /dev/ttyUSB1
2019.05.11 21:14:59 3: Probing TRX device /dev/ttyUSB1
2019.05.11 21:14:59 3: Probing ZWDongle device /dev/ttyUSB1
2019.05.11 21:14:59 3: Probing SIGNALDuino device /dev/ttyUSB1
2019.05.11 21:15:00 3: Probing MYSENSORS device /dev/ttyUSB1
2019.05.11 21:15:00 3: Probing ArduCounter device /dev/ttyUSB1
2019.05.11 21:15:00 3: Probing ElsnerWS device /dev/ttyUSB1
...
Aus- und einstecken des Gerätes an der seriellen Schnittstelle
...
2019.05.11 21:16:52 1: define ElsnerWS_1 ElsnerWS comtype=rs485 devicename=/dev/ttyUSB1@19200
2019.05.11 21:16:52 3: Opening ElsnerWS_1 device /dev/ttyUSB1
2019.05.11 21:16:52 3: Setting ElsnerWS_1 serial parameters to 19200,8,N,1
2019.05.11 21:16:52 3: ElsnerWS_1 device opened
2019.05.11 21:16:52 2: ElsnerWS define ElsnerWS_1 ElsnerWS
2019.05.11 21:16:52 2: ElsnerWS define FileLog_ElsnerWS_1 FileLog ./log/ElsnerWS_1-%Y.log ElsnerWS_1
2019.05.11 21:16:52 2: ElsnerWS define SVG_ElsnerWS_1 SVG FileLog_ElsnerWS_1:ElsnerWS:CURRENT
2019.05.11 21:16:52 2: ElsnerWS define SVG_ElsnerWS_1_2 SVG FileLog_ElsnerWS_1:ElsnerWS_2:CURRENT
2019.05.11 21:16:52 2: ElsnerWS define SVG_ElsnerWS_1_3 SVG FileLog_ElsnerWS_1:ElsnerWS_3:CURRENT
2019.05.11 21:16:52 1: usb create end
Zitat von: rudolfkoenig am 11 Mai 2019, 17:21:08
Weiterhin hat DevIo_TimeoutRead einen optionalen vierten Parameter (regexp) bekommen, mit dem die Daten geprueft, und evtl. frueher als maxlen zurueckgeliefert werden.
Das hilft. M. E. könnten wir damit starten. An ElsnerWS und ModbusElsnerWS stehen noch ein paar Schönheitskorrekturen an, danach würde ich die Module unmittelbar einchecken.