ESPEasy: gleichzeitiges setzen mehrerer Dummy-Werte fehlerhaft

Omega · 18 März 2018, 11:43:20

Ich habe in einem ESP-Device einen Dummy mit 4 Variablen definiert. Die Werte möchte ich aus 99_myUtils setzen. Das funktioniert aber nicht richtig. In der Regel hat nur der letzte Befehl Erfolg. Manchmal auch noch zusätzlich ein 2. Wert. Bei meinen Tests hatte ich bisher noch kein Ergebnis, bei dem alle 4 Werte gesetzt wurden.
Setze ich die Befehle einzeln in der FHEM-Kommandozeile ab, funktionieren sie einwandfrei – die Befehlssyntax als solches passt.

Im Syslog des ESP finde ich immer nur Meldungen zu den (wenigen) erfolgreichen Setzen der Variablen.

Ich hoffe, alles aufgeführt zu haben, was zur Lösung beitragen kann.
LG
Holger

Mein Device:

Code Auswählen


Internals:
   DEF        192.168.0.50 80 espBridge ESP_G01
   ESP_BUILD  20000
   ESP_BUILD_GIT v2.0-20180311
   ESP_BUILD_NOTES  - Mega
   ESP_NODE_TYPE_ID 17: ESP Easy Mega
   ESP_SLEEP  0
   ESP_UNIT   1
   ESP_VERSION 2
   HOST       192.168.0.50
   IDENT      ESP_G01
   INTERVAL   300
   IODev      espBridge
   LASTInputDev espBridge
   MSGCNT     15154
   NAME       ESPEasy_ESP_G01
   NOTIFYDEV  global
   NR         961
   NTFY_ORDER 50-ESPEasy_ESP_G01
   PORT       80
   STATE      RSSI: -73 Uptime: 5.00 humidity: 35 temperature: 22.40 temperature2_:  temperature_1: 25.31 z.Hzg_Tag:  z.WW_Tag:  z.Zaehlerstan:  z.total_Tag:  z.var1: 0 z.var2: 0 z.var3: 557 z.var4: 81
   SUBTYPE    device
   TYPE       ESPEasy
   VERSION    1.38
   espBridge_MSGCNT 15154
   espBridge_TIME 2018-03-18 11:17:11
   Helper:
     DBLOG:
       Uptime:
         myFHEMdb:
           TIME       1521368202.32719
           VALUE      5.00
       dewpoint:
         myFHEMdb:
           TIME       1521368227.5808
           VALUE      6.2
         myFHEMdb_LT:
           TIME       1521368227.60432
           VALUE      6.2
       humidity:
         myFHEMdb:
           TIME       1521368227.5808
           VALUE      35
         myFHEMdb_LT:
           TIME       1521368227.60432
           VALUE      35
       presence:
         myFHEMdb:
           TIME       1521368029.51474
           VALUE      present
       temperature:
         myFHEMdb:
           TIME       1521368227.5808
           VALUE      22.40
         myFHEMdb_LT:
           TIME       1521368227.60432
           VALUE      22.40
       temperature2_1W:
         myFHEMdb:
           TIME       1521299373.01687
           VALUE      0.00
         myFHEMdb_LT:
           TIME       1521299373.04003
           VALUE      0.00
       temperature_1W:
         myFHEMdb:
           TIME       1521368230.97827
           VALUE      25.31
         myFHEMdb_LT:
           TIME       1521368231.00075
           VALUE      25.31
       z.Hzg_Tag:
         myFHEMdb:
           TIME       1521301593.50561
           VALUE      42
       z.WW_Tag:
         myFHEMdb:
           TIME       1521301593.50561
           VALUE      20
       z.Zaehlerstand:
         myFHEMdb:
           TIME       1521301593.50561
           VALUE      1
       z.total_Tag:
         myFHEMdb:
           TIME       1521301593.50561
           VALUE      20
   OLDREADINGS:
   READINGS:
     2018-03-18 11:16:40   RSSI            -73
     2018-03-18 11:16:42   Uptime          5.00
     2018-03-18 11:17:07   dewpoint        6.2
     2018-03-18 11:17:07   humidity        35
     2018-03-18 11:13:49   presence        present
     2018-03-18 11:17:11   state           RSSI: -73 Uptime: 5.00 humidity: 35 temperature: 22.40 temperature2_:  temperature_1: 25.31 z.Hzg_Tag:  z.WW_Tag:  z.Zaehlerstan:  z.total_Tag:  z.var1: 0 z.var2: 0 z.var3: 557 z.var4: 81
     2018-03-18 11:17:07   temperature     22.40
     2018-03-18 11:17:10   temperature_1W  25.31
     2018-03-18 11:17:11   z.var1          0
     2018-03-18 11:17:11   z.var2          0
     2018-03-18 11:17:11   z.var3          557
     2018-03-18 11:17:11   z.var4          81
   helper:
     fpc        1520850332.10101
     pm:
       Encode     1
       JSON       1
     received:
       RSSI       1521368200.70647
       Uptime     1521368202.29926
       humidity   1521368227.55938
       temperature 1521368227.55943
       temperature2_1W 1521299372.99514
       temperature_1W 1521368230.95724
       z.Hzg_Tag  1521364521.91618
       z.WW_Tag   1521364521.91609
       z.Zaehlerstand 1521364521.91623
       z.total_Tag 1521364521.91614
       z.var1     1521368231.76128
       z.var2     1521368231.76133
       z.var3     1521368231.76124
       z.var4     1521368231.76119
Attributes:
   DbLogExclude state, Uptime,RSSI,z..*
   IODev      espBridge
   Interval   300
   comment    z.Zt. Arbeitszimmer: Testaufbau
   group      ESPEasy Device
   presenceCheck 1
   readingSwitchText 1
   room       ESPEasy
   setState   13

Die sub aus 99_myUtils (getestet entweder mit den ersten 4 Befehlen oder dem zweiten 4-er-Set):

Code Auswählen


sub
Set_Test()
{
#	{ HttpUtils_NonblockingGet( { url=>"http://192.168.0.50:80/control?cmd=event,set_z.var1=".ReadingsVal("ESPEasy_ESP_G19", "z.Zaehlerstand", "0"), callback=>sub() { } }) };
#	{ HttpUtils_NonblockingGet( { url=>"http://192.168.0.50:80/control?cmd=event,set_z.var2=".ReadingsVal("ESPEasy_ESP_G19", "z.total_Tag", "0"), callback=>sub() { } }) };	
#	{ HttpUtils_NonblockingGet( { url=>"http://192.168.0.50:80/control?cmd=event,set_z.var3=".ReadingsVal("ESPEasy_ESP_G19", "z.Hzg_Tag", "0"), callback=>sub() { } }) };
#	{ HttpUtils_NonblockingGet( { url=>"http://192.168.0.50:80/control?cmd=event,set_z.var4=".ReadingsVal("ESPEasy_ESP_G19", "z.WW_Tag", "0"), callback=>sub() { } }) };	
	{fhem ("set ESPEasy_ESP_G01 raw event,set_z.var1=".ReadingsVal("ESPEasy_ESP_G19", "z.Zaehlerstand", "0"))};
	{fhem ("set ESPEasy_ESP_G01 raw event,set_z.var2=".ReadingsVal("ESPEasy_ESP_G19", "z.total_Tag", "0"))};
	{fhem ("set ESPEasy_ESP_G01 raw event,set_z.var3=".ReadingsVal("ESPEasy_ESP_G19", "z.Hzg_Tag", "0"))};
	{fhem ("set ESPEasy_ESP_G01 raw event,set_z.var4=".ReadingsVal("ESPEasy_ESP_G19", "z.WW_Tag", "0"))};
}

Die Rules aus dem ESP-Device:

Code Auswählen


on System#Boot do
  TaskValueSet 5,1,0 // default value at boot (5 ist Edit-Nr, 1 die 1. Variable)
  TaskValueSet 5,2,0
  TaskValueSet 5,3,0
  TaskValueSet 5,4,0
endon

on Clock#Time=All,00:00 do //will run once a day at midnight: Tageszaehler auf 0 setzen
  TaskValueSet 5,2,0
  TaskValueSet 5,3,0
  TaskValueSet 5,4,0
endon

on set_z.var1 do
  TaskValueSet 5,1,%eventvalue%   // externes Setzen des Dummywertes ermöglichen
endon
on set_z.var2 do
  TaskValueSet 5,2,%eventvalue% 
endon
on set_z.var3 do
  TaskValueSet 5,3,%eventvalue% 
endon
on set_z.var4 do
  TaskValueSet 5,4,%eventvalue% 
endon

Auszug aus dem Syslog zur letzen Aktion (um 10:47:20 wird die 3. Variable gefüllt):

Code Auswählen


Sun Mar 18 10:47:07 2018;192.168.0.50; <7>ESP_G01 EspEasy: FILE : Saved config.dat
Sun Mar 18 10:47:07 2018;192.168.0.50; <7>ESP_G01 EspEasy: FILE : Saved security.dat
Sun Mar 18 10:47:13 2018;192.168.0.50; <7>ESP_G01 EspEasy: DHT  : Temperature: 20.80
Sun Mar 18 10:47:13 2018;192.168.0.50; <7>ESP_G01 EspEasy: DHT  : Humidity: 36.60
Sun Mar 18 10:47:13 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: DHT22#temperature=20.80
Sun Mar 18 10:47:13 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: DHT22#humidity=36.60
Sun Mar 18 10:47:15 2018;192.168.0.50; <7>ESP_G01 EspEasy: DS   : Temperature: 22.37 (28-ff-67-48-54-14-1-98)
Sun Mar 18 10:47:15 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: 1Wire#temperature_1W=22.37
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 1: 0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 2: 0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 3: 0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 4: 0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var1=0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var2=0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var3=0.00
Sun Mar 18 10:47:16 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var4=0.00
Sun Mar 18 10:47:18 2018;192.168.0.50; <7>ESP_G01 EspEasy: WD   : Uptime 9 ConnectFailures 0 FreeMem 17496
Sun Mar 18 10:47:20 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: set_z.var3=530
Sun Mar 18 10:47:20 2018;192.168.0.50; <7>ESP_G01 EspEasy: ACT  : TaskValueSet 5,3,530
Sun Mar 18 10:47:21 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: set_z.var4=81
Sun Mar 18 10:47:21 2018;192.168.0.50; <7>ESP_G01 EspEasy: ACT  : TaskValueSet 5,4,81
Sun Mar 18 10:47:33 2018;192.168.0.50; <7>ESP_G01 EspEasy: DHT  : Temperature: 20.80
Sun Mar 18 10:47:33 2018;192.168.0.50; <7>ESP_G01 EspEasy: DHT  : Humidity: 36.40
Sun Mar 18 10:47:33 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: DHT22#temperature=20.80
Sun Mar 18 10:47:33 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: DHT22#humidity=36.40
Sun Mar 18 10:47:35 2018;192.168.0.50; <7>ESP_G01 EspEasy: DS   : Temperature: 22.50 (28-ff-67-48-54-14-1-98)
Sun Mar 18 10:47:35 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: 1Wire#temperature_1W=22.50
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 1: 0.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 2: 0.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 3: 530.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: Dummy: value 4: 81.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var1=0.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var2=0.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var3=530.00
Sun Mar 18 10:47:36 2018;192.168.0.50; <7>ESP_G01 EspEasy: EVENT: d.dummy#z.var4=81.00

dev0 · 18 März 2018, 17:30:14

Falls die Ursache darin liegt, dass die ESPEasy Firmware nicht mehrere event Befehle parallel (bzw. zu schnell hintereinander) verarbeiten kann, dann hilft es vielleicht das Bridge Attribut maxHttpSessions auf 1 zu setzen.

Omega · 18 März 2018, 18:37:29

Danke für die Unterstützung.
Das maxHttpSessions hat leider keine Änderung bewirkt. Wieder nur 1 Wert gesetzt.

Parallel bin ich auch dabei, die Befehlsausführung zu verzögern (auch ich vermute ein Timing-Problem zwischen FHEM und dem ESP).

Code Auswählen


	{fhem ("set ESPEasy_ESP_G01 raw event,set_z.var1=".ReadingsVal("ESPEasy_ESP_G19", "z.Zaehlerstand", "0"))};
	{fhem ("sleep 3;set ESPEasy_ESP_G01 raw event,set_z.var2=".ReadingsVal("ESPEasy_ESP_G19", "z.total_Tag", "0"))};
	{fhem ("sleep 3;set ESPEasy_ESP_G01 raw event,set_z.var3=".ReadingsVal("ESPEasy_ESP_G19", "z.Hzg_Tag", "0"))};
	{fhem ("sleep 3;set ESPEasy_ESP_G01 raw event,set_z.var4=".ReadingsVal("ESPEasy_ESP_G19", "z.WW_Tag", "0"))};

Die Verzögerung funktioniert allerdings nur zwischen dem 1. und dem 2. Befehl. Aber damit habe ich immerhin Werte in der 1., 2. und 4. Variablen (zumindest bei 3 maligem Test immer das gleiche Ergebnis). Neee: beim 4. Test nur Update von 1 und 4

Auszug aus Log:

Code Auswählen


2018.03.18 18:23:08 3: ESPEasy: set ESPEasy_ESP_G01 raw event,set_z.var1=4277880
2018.03.18 18:23:11 3: ESPEasy: set ESPEasy_ESP_G01 raw event,set_z.var2=1144
2018.03.18 18:23:11 3: ESPEasy: set ESPEasy_ESP_G01 raw event,set_z.var3=1011
2018.03.18 18:23:11 3: ESPEasy: set ESPEasy_ESP_G01 raw event,set_z.var4=133

Warum der sleep bei Befehl 3 und 4 nicht zieht, verstehe ich nicht. Wichtig ist mir natürlich, dass ich mein FHEM nicht blockiere (mit apptime kontrolliert, scheint ok zu sein)

dev0 · 18 März 2018, 18:43:11

Pack alle 4 set Befehle in ein fhem() Statement getrennt mit sleeps, dann sollte es gehen oder erhöhne jedes einzelne sleep um 3s. Das FHEM sleep ist intern en Timer...

Omega · 18 März 2018, 21:38:14

Mit der Syntax bin ich am kämpfen (und verzweifeln - entweder hatte ich Syntaxfehler oder FHEM hat blockiert).
Ich bin auf DOIF umgestiegen (mit dem "wait"-Attribut).

Mit dieser Variante

Code Auswählen


([ESPEasy_ESP_G01:z.boot] == 1) 
((set ESPEasy_ESP_G01 raw event,set_z.var1=[ESPEasy_ESP_G19:z.Zaehlerstand]))
((set ESPEasy_ESP_G01 raw event,set_z.var2=[ESPEasy_ESP_G19:z.total_Tag]))
((set ESPEasy_ESP_G01 raw event,set_z.var3=[ESPEasy_ESP_G19:z.Hzg_Tag]))
((set ESPEasy_ESP_G01 raw event,set_z.var4=[ESPEasy_ESP_G19:z.WW_Tag]))
((set ESPEasy_ESP_G01 raw event,set_z.boot=0))

und dem attr <> wait 0,3,3,3,3
funktioniert die Verzögerung und vor allem: alle Werte werden geschrieben.

dev0 · 18 März 2018, 23:03:12

Das Problem scheint am Event Handling der ESP Easy Firemware zu liegen. Vielleicht hast Du ja noch Lust das den ESP Easy Entwicklern auf Github mitzuteilen, sprich einen Issue zu eröffnen...

Omega · 21 März 2018, 11:55:18

Lust nicht

aber getan hab ich's