[gelöst] ECMD, spontane Daten stören expect in classdef

[Mike73]

Hallo zusammen,

ich hoffe, mir kann jemand bei folgendem Problem helfen.
Die Hinweise von Dr. Neubert habe ich gelesen und versuche sie hier bestmöglich zu berücksichtigen.

Das Problem kurz umrissen: 
Ich verwende ECMD-Devices basierend auf der ethersex-Firmware . An diesen Devices ( ich nenne die "Inseln" ) sind z.B. Taster, Schalter und 1wire-Sensoren. Diese erzeugen bei Ereignissen , z.B. ein Taster wird gedrückt, eine Nachricht an den FHEM-Server, der die über die 'reading / match' in der classdef in Readings schreibt. Das funktioniert auch an sich ganz prima.
ABER: Probleme gibt es, wenn zB das Drücken des Tasters ein notify triggert, das einen Ausgang an demselben physischen ECMD-Device schalten soll.

Denn folgendes passiert:

• FHEM empfängt "upd B0 1\n" und gleich danach "upd B0 0\n"  , denn der Taster erzeugt je ein Ereignis bei Drücken und beim Loslassen.
• FHEM erkennt den "spontanen Empfang" von "upd B0 1\n" , matcht und setzt das Reading "buttonstate" auf 1
• Das erzeugt ein Event, das triggert ein Notify, welches die Aktion auf das Drücken des Tasters auslöst
• das Kommando "io set port x 0x.. 0x.." wird an dasselbe physische Device gesendet . Darauf wird "OK\n" als Antwort erwartet.

Und hier knackt es, denn bevor FHEM das "OK\n" zu lesen bekommt, ist ja noch "upd B0 0\n" im Puffer, was als Antwort interpretiert wird und zum Fehlschlagen der Aktion führt.
Wie kann ich das denn ausknoten ? 

Bisher habe ich mit den Attributen split und partial herumexperimentiert, ohne Erfolg .


Beste Grüße

Mike



Versions

Code Auswählen Erweitern


fhem> version 66_ECMD.pm
File       Rev   Last Change

66_ECMD.pm 14495 2017-06-11 05:47:17Z neubert
67_ECMDDevice.pm 12877 2016-12-26 09:15:55Z neubert


define:

Code Auswählen Erweitern



defmod myECMD ECMD telnet 192.168.5.1:2701
attr myECMD classdefs PORTIO=./PortIO.classdef:BUTTON=./insel_button.classdef:1W-TEMP=./1wire.classdef
attr myECMD logTraffic 5
attr myECMD partial 2
attr myECMD split \n
attr myECMD verbose 5

defmod button ECMDDevice
attr button IODev myECMD
attr button class BUTTON 0

defmod Relais1 ECMDDevice
attr Relais1 IODev myECMD
attr Relais1 class PORTIO 1 0x01



insel_button.classdef

Code Auswählen Erweitern


# Uebergabeparameter Button-ID
params buttonID

reading buttonstate match "upd B%buttonID.*\n"
reading buttonstate postproc { s/^upd\sB\d\s+(\d).*$/$1/;; $_ }


PortIO.classdef

Code Auswählen Erweitern


# Uebergabeparameter HEX Adresse Port
params RelaisPort RelaisPin

set on cmd {"io set port %RelaisPort %RelaisPin %RelaisPin\n"}
set on expect "OK\n"
set on postproc {s/([OK\n|;]*)/success/; "$_" eq "success" ? "ok" : "error";}
set off cmd {"io set port %RelaisPort 0 %RelaisPin\n"}
set off expect "OK\n"
set off postproc {s/([OK\n|;]*)/success/; "$_" eq "success" ? "ok" : "error";}

get io cmd {"io get port %RelaisPort\n"}
get io expect "port\s\d:.*\n"
get io postproc { \
      s/^port.*(0x..).*$/$1/ ;\
      my $hash  = $defs{%NAME};\
      my $portval = hex($1) & %RelaisPin;\
      my $state = ($portval == %RelaisPin)?"on":"off";\
      readingsSingleUpdate($hash, "state", $state, 1);\
      \
      }



Log-Ausschnitt:

Code Auswählen Erweitern


2018.01.20 21:22:51 5 : myECMD: read upd B0 1 \n (\165\160\144\040\102\060\040\061\040\012)
2018.01.20 21:22:51 5 : myECMD: Spontaneously received upd B0 1 \n (\165\160\144\040\102\060\040\061\040\012)
2018.01.20 21:22:51 5 : myECMD: dispatch upd B0 1 \n
2018.01.20 21:22:51 5 : myECMD: trying to match message upd B0 1 \n (\165\160\144\040\102\060\040\061\040\012)
2018.01.20 21:22:51 5 : myECMD: upd B0 1 \n (\165\160\144\040\102\060\040\061\040\012) matches regex upd B0.*\n for reading buttonstate of device button with class BUTTON
2018.01.20 21:22:51 5 : Postprocessing "upd B0 1 \n (\165\160\144\040\102\060\040\061\040\012)" with perl command { s/^upd\sB\d\s+(\d).*$/$1/;; $_ }.
2018.01.20 21:22:51 5 : Postprocessed value is "1\n (\061\012)".
2018.01.20 21:22:51 5 : Starting notify loop for button, 2 event(s), first is buttonstate: 1\n
2018.01.20 21:22:51 5 : Triggering button_notify_1
2018.01.20 21:22:51 4 : button_notify_1 exec set Relais1 off
2018.01.20 21:22:51 5 : Cmd: >set Relais1 off<
2018.01.20 21:22:51 5 : ECMDDevice: Analyze command >{"io set port 1 0 0x01\n"}<
2018.01.20 21:22:51 5 : myECMD: sending command io set port 1 0 0x01\n (\151\157\040\163\145\164\040\160\157\162\164\040\061\040\060\040\060\170\060\061\012)
2018.01.20 21:22:51 5 : myECMD: write io set port 1 0 0x01\n (\151\157\040\163\145\164\040\160\157\162\164\040\061\040\060\040\060\170\060\061\012), expect .*OK\n
2018.01.20 21:22:51 5 : SW: 696f2073657420706f72742031203020307830310a
2018.01.20 21:22:54 5 : myECMD: read upd B0 0 \n (\165\160\144\040\102\060\040\060\040\012)
2018.01.20 21:22:54 1 : myECMD: unexpected answer upd B0 0 \n (\165\160\144\040\102\060\040\060\040\012) received (wrote io set port 1 0 0x01\n (\151\157\040\163\145\164\040\160\157\162\164\040\061\040\060\040\060\170\060\061\012), expected .*OK\n)
2018.01.20 21:22:54 5 : myECMD: received answer upd B0 0 \n (\165\160\144\040\102\060\040\060\040\012)
2018.01.20 21:22:54 5 : Postprocessing "upd B0 0 \n (\165\160\144\040\102\060\040\060\040\012)" with perl command {s/([OK\n|;]*)/success/; "$_" eq "success" ? "ok" : "error";}.
2018.01.20 21:22:54 5 : Postprocessed value is "error (\145\162\162\157\162)".
2018.01.20 21:22:54 5 : Starting notify loop for Relais1, 2 event(s), first is off: error
2018-01-20 21:22:54 ECMDDevice Relais1 off: error
2018-01-20 21:22:54 ECMDDevice Relais1 off error
2018.01.20 21:22:54 5 : End notify loop for Relais1
2018-01-20 21:22:54 ECMDDevice button buttonstate: 1
2018-01-20 21:22:54 ECMDDevice button buttonstate 1
2018.01.20 21:22:54 5 : End notify loop for button
2018.01.20 21:22:55 5 : myECMD: read OK\n (\117\113\012)
2018.01.20 21:22:55 5 : myECMD: Spontaneously received OK\n (\117\113\012)
2018.01.20 21:22:55 5 : myECMD: dispatch OK\n
2018.01.20 21:22:55 5 : myECMD: trying to match message OK\n (\117\113\012)
2018.01.20 21:22:55 5 : myECMD: partial message OK\n (\117\113\012) kept


[rudolfkoenig]

Im notify vor dem set ein FHEM-sleep von 0.01s einbauen?

[Mike73]

Hallo Rudolf,

Danke für den Tipp !  Ich hätte nicht erwartet, dass das was bringt   

Jetzt funktioniert es Hurra.   Das hatte mich echt Nerven gekostet.


Danke  !

Gruß

Mike

[Mike73]

Hallo nochmal ,

leider etwas zu früh gefreut. Der sleep ist wohl eher ein Workaround denn eine Lösung ... und er funktioniert leider nur manchmal.

Ich denke, das Problem ist grundsätzlicher. Warum wird denn die schon vorhandene Nachricht nicht ( für den expect zumindest ) ignoriert und danach weiter bearbeitet?  Seitens ethersex habe ich verhindert, dass spontan Ereignisse an den FHEM-Server übermittelt werden, während ein ECMD-Kommando abgearbeitet wird.
Wo müsste man denn ansetzen, um das Verhalten im Modul zu korrigieren, also nur NEUE Daten vom IODev für den expect auswerten .. ? 

[rudolfkoenig]

Vermutlich ist das zuviel fuer ECMD, und man muesste dafuer ein "richtiges" FHEM-Modul bauen.

Ich wuerde im Protokoll das "OK" weglassen, macht vieles einfacher, vorausgesetzt die Hardware ist verlaesslich. Alternativ muss man anhand dem Inhalt erkennen, ob das ein low-level Protokollbestandteil ist wie ACK/NAK oder was auf der hoeheren Ebene wie upd, das ist mWn nichts fuer ECMD, deswegen eigenes Modul. Fuer Theoretiker/Perfektionisten/professionelle Loesungen gibts das ISO-Modell, mit entsprechend mehr Aufwand.

Mein Vorschlag war nur ein triviales Workaround, was bei einem gut gewaehlten Dauer in den meisten Faellen funktioniert. Ich wollte keine Abhandlung ueber das ISO-Modell halten.

[Mike73]

So, ich habs .

Ich hab in der 66_ECMD.pm die Funktion ECMD_SimpleExpect etwas erweitert. Sie liest und speichert bereits empfangene spontane Nachrichten und leitet sie nach dem der Befehl abgesetzt und die Antwort abgeholt ist an die Dispatch-Funktion weiter. So geht nix verloren.