BUG in fhem ? - Reading powerOn für HM-ES-PMSw1-Pi und HM-ES-PMSw1-DR kommt nich

pwlr · 29 April 2017, 20:21:05

Moin,

ich habe gerade gemerkt, dass bei den Devices mit Messfunktion das Reading powerOn nicht mehr gesetzt wird. Ging früher mal, da stehen alte Daten von 2016 drin. Ich habe mehrere der Devices im Einsatz und alle zeigen das gleiche Verhalten. In Folge davon werden auch die notify natürlich nicht mehr getriggert.
Löschen in fhem, Werkseinstellung und neu pairen hat auch keinen Erfolg gebracht. Alle Devices haben die Firmware 2.5 drin und mein fhem hat aktuellen Stand von gestern.

Logauszug mit verbose=5 siehe Anhang. Es geht um das Device mit der ID 36D06A

Zitat2017.04.29 19:57:09 5: HMLAN/RAW: /E36D06A,0000,000494F2,FF,FFD2,03A45F36D06A123ABC8000000000000000075FFD

2017.04.29 19:57:09 5: HMLAN_Parse: HMLAN1 R:E36D06A stat:0000 t:000494F2 d:FF r:FFD2 m:03 A45F 36D06A 123ABC 8000000000000000075FFD
2017.04.29 19:57:09 5: HMLAN1: dispatch A1403A45F36D06A123ABC8000000000000000075FFD::-46:HMLAN1
2017.04.29 19:57:09 5: HMLAN: Skip ACK
2017.04.29 19:57:09 5: CUL_HM HM_36D06A protEvent:CMDs_done
2017.04.29 19:57:09 5: CUL_HM HM_36D06A sent ACK:2
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A, 1 event(s), first is CMDs_done
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 1 for device: HM_36D06A
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A , Event: CMDs_done
2017.04.29 19:57:09 5: End notify loop for HM_36D06A
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A_Pwr, 9 event(s), first is boot: off
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 9 for device: HM_36D06A_Pwr
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: boot: off
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: current: 0
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: eState: E: 0 P: 0 I: 0 U: 188.7 f: 49.97
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: energy: 0
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: energyCalc: 0
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: frequency: 49.97
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: power: 0
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: 0
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_Pwr , Event: voltage: 188.7
2017.04.29 19:57:09 5: End notify loop for HM_36D06A_Pwr
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A_SenF, 1 event(s), first is 49.97
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 1 for device: HM_36D06A_SenF
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_SenF , Event: 49.97
2017.04.29 19:57:09 5: End notify loop for HM_36D06A_SenF
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A_SenI, 1 event(s), first is 0
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 1 for device: HM_36D06A_SenI
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_SenI , Event: 0
2017.04.29 19:57:09 5: End notify loop for HM_36D06A_SenI
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A_SenPwr, 1 event(s), first is 0
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 1 for device: HM_36D06A_SenPwr
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_SenPwr , Event: 0
2017.04.29 19:57:09 5: End notify loop for HM_36D06A_SenPwr
2017.04.29 19:57:09 5: Starting notify loop for HM_36D06A_SenU, 1 event(s), first is 188.7
2017.04.29 19:57:09 5: batteries: not on any display, ignoring notify
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> ### start of new Logcycle ###
2017.04.29 19:57:09 4: DbLog logdb -> ################################################################
2017.04.29 19:57:09 4: DbLog logdb -> amount of events received: 1 for device: HM_36D06A_SenU
2017.04.29 19:57:09 4: DbLog logdb -> check Device: HM_36D06A_SenU , Event: 188.7
2017.04.29 19:57:09 5: End notify loop for HM_36D06A_SenU

Kennt jemand den Grund oder kann helfen ?

Vielen Dank vorab !

Bernd

stromer-12 · 01 Mai 2017, 19:58:25

powerOn wird gesetzt wenn das Gerät neu bestromt wird.

pwlr · 02 Mai 2017, 11:05:48

ja, da hast Du absolut Recht.

Aber leider bei dem von mir berichteten Fehler kommt dieses Reading nicht. Man kann soviel Power ab- und anschalten wie man will, es kommt kein Reading und damit natürlich auch kein Trigger für ein notify.

Scheint mir wirklich ein BUG zu sein. Hoffentlich kann jemnd helfen !

Moin
Bernd

MadMax-FHEM · 02 Mai 2017, 12:09:26

Zitat von: pwlr am 02 Mai 2017, 11:05:48
ja, da hast Du absolut Recht.

Aber leider bei dem von mir berichteten Fehler kommt dieses Reading nicht. Man kann soviel Power ab- und anschalten wie man will, es kommt kein Reading und damit natürlich auch kein Trigger für ein notify.

Scheint mir wirklich ein BUG zu sein. Hoffentlich kann jemnd helfen !

Moin
Bernd

Was meinst du mit "Power ab- und anschalten"?

set Device/Channel on|off?

Das war nicht gemeint, sondern das Gerät selbst vom Strom trennen und wieder anschließen...
...beispielsweise den Zwischenstecker mit Leistungsmessung aus der Steckdose ziehen und wieder stecken: dann powert er on -> powerOn

Gruß, Joachim

pwlr · 02 Mai 2017, 18:40:01

Moin,

klar, Power ab- und anschalten ist für mich die 200V Sicherung für diese Devices des Hausnetzes aus- und wieder einschalten bzw. das Gerät aus der Steckdose ziehen und nach einer Wartezeit wieder einstecken.

Dann sollte, wie bei anderen Devices auch, das Reading powerOn mit aktuellem Einschaltedatum und Uhrzeit gesetzt, in Folge davon ein Trigger ausgelöst werden und meine entsprechenden notifys anlaufen. Aber leider kommt kein Reading und damit geht dann der Rest auch nicht....

Ok ?
Moin
Bernd

martinp876 · 02 Mai 2017, 21:16:47

Sniffe die msgs wenn ein Power Up machst.

Pfriemler · 03 Mai 2017, 00:05:06

Mystisch. Ich habe 5.8 am 1.3. aufgezogen und zuletzt ein powerOn am 29.3.17 in einem PMSw1-Pl gehabt (was jedoch seither nicht mehr aktualisiert wird), im anderen -Pl existiert das Reading nicht, genauso wie in meinem -DR. Alle drei haben die gleiche Firmware 2.5 und die gleichen expert-Attribute. Einen Zusammenhang mit powerUpAction sehe ich auch nicht.

pwlr · 03 Mai 2017, 00:11:19

Moin,

scheint der gleiche Fehler wie bei mir zu sein.

Martin: der Logauszug im ersten Beitrag oben zu diesem Thread ist bei Poweron entstanden (verbose 5). Reicht das, oder braucht Du etwas anderes?
Viele Grüße
Bernd

Pfriemler · 03 Mai 2017, 08:49:58

Moinsen,
frisch eingestromt: Mein HM-ES-PMSw1-Pl #2 mit der ID 3425BE:

Code Auswählen

2017.05.03 08:43:44.582 0: HMLAN_Parse: HMLAN1 R:E3425BE   stat:0000 t:8658E949 d:FF r:FFBD     m:01 A45F 3425BE 1411AB 8000000000000000090AFE
2017.05.03 08:43:44.589 0: HMLAN_Parse: HMLAN1 R:E1411AB   stat:0000 t:8658E9BC d:FF r:FFC5     m:01 8002 1411AB 3425BE 00
2017.05.03 08:43:44.869 0: HMLAN_Parse: HMLAN1 R:E3425BE   stat:0000 t:8658EB37 d:FF r:FFBD     m:02 A410 3425BE 1411AB 06010000
2017.05.03 08:43:44.960 0: HMLAN_Parse: HMLAN1 R:E1411AB   stat:0000 t:8658EBB1 d:FF r:FFC5     m:02 8002 1411AB 3425BE 00

Mehr war zwischen den beiden nicht.

pwlr · 03 Mai 2017, 10:06:00

Moin,

ich will nicht doof sterben - wie hast Du diese Auswertung erzeugt ? Will ich auch können

Pfriemler · 03 Mai 2017, 22:25:40

FHEM Wiki: Homematic Nachrichten sniffen
Da OT, nur kurz:
Ich habe mir dafür zwei Minisubs in die 99_myUtils.pm gelegt und zwei Links für die Weboberfläche eingerichtet (per menuEntries-Attribut in der benutzten FHEMWEB-Instanz). Die Subs erzeugen je eine Zeile in der Logdatei, so kann ich den Block mit den Sniffs schnell wiederfinden. Wollte das Logging auch gleich auf bestimmte Devices beschränken, aber das habe ich noch nicht fertigbekommen.

pwlr · 04 Mai 2017, 15:33:50

ok, danke !! Die Anregung habe ich mal sofort aufgegriffen und etwas mit Infos zum Device aufgebohrt

Also, Device aus der Steckdose, Wartezeit, Device wieder in die Steckdose gesteckt. Ergebnis des sniffens für dieses Device bei mir:

Code Auswählen

2017.05.04 15:15:51 1: ************** eyecatcher ***********************
2017.05.04 15:15:51 1: sniffer_01 for HM_36D06A started
2017.05.04 15:15:51 3: HM_36D06A  model     HM-ES-PMSw1-Pl
2017.05.04 15:15:51 3: HM_36D06A  firmware  2.5
2017.05.04 15:15:51 3: HM_36D06A  serialNr  MEQ0271884
2017.05.04 15:15:51 3: HMLAN1     HMID      123ABC
2017.05.04 15:15:51 3: HMLAN2     HMID      123ABC
2017.05.04 15:16:13.275 0: HMLAN_Parse: HMLAN1 R:E36D06A   stat:0000 t:0F29A8C8 d:FF r:FFD2     m:01 A45F 36D06A 123ABC 8000000000000000090CFE
2017.05.04 15:16:13.470 0: HMLAN_Parse: HMLAN2 R:E36D06A   stat:0000 t:0F2B4696 d:FF r:FF99     m:01 A45F 36D06A 123ABC 8000000000000000090CFE
2017.05.04 15:16:13.485 0: HMLAN_Parse: HMLAN2 R:E123ABC   stat:0000 t:0F2B470A d:FF r:FFAE     m:01 8002 123ABC 36D06A 00
2017.05.04 15:16:14.082 0: HMLAN_Parse: HMLAN1 R:E36D06A   stat:0000 t:0F29ABE2 d:FF r:FFD2     m:02 A410 36D06A 123ABC 06010000
2017.05.04 15:16:14.116 0: HMLAN_Parse: HMLAN2 R:E36D06A   stat:0000 t:0F2B49B0 d:FF r:FF99     m:02 A410 36D06A 123ABC 06010000
2017.05.04 15:16:14.173 0: HMLAN_Parse: HMLAN2 R:E123ABC   stat:0000 t:0F2B4A29 d:FF r:FFAD     m:02 8002 123ABC 36D06A 00

2017.05.04 15:17:55.373 1: ************** eyecatcher ***********************
2017.05.04 15:17:55.373 1: sniffer_01 ended

ok ?
Bernd

martinp876 · 04 Mai 2017, 21:08:15

Scheinbar kommt hier die pup msg erst als 2. Das sollte sich korrigieren lassen.

pwlr · 05 Mai 2017, 00:58:47

Hallo Martin,
danke !

@all : Vielleicht als Anregung, wie das Sniffen einfach durchgeführt werden kann. Ich habe mir dazu nach der Idee vom Pfriemler einen dummy Namens "Sniffer" definiert, der über set-Befehle den Ablauf steuert.
set Sniffer off schalten das Sniffing aus.
set Sniffer <Devicename> schaltet das Sniffng für ein Device ein.

Code Auswählen

Internals: 
   NAME       Sniffer 
   NR         1670 
   STATE      off 
   TYPE       dummy 
   Readings: 
     2017-05-04 15:17:55   state           off 
Attributes: 
   comment    Starten und Beenden des sniffers 

set Sniffer devicename => aktivieren 
set Sniffer off => deaktivieren 
   devStateIcon off:general_aus@green .*:message_attention@red:off 
   event-on-change-reading .* 
   group      Debugging 
   room       -System

Und dann ein notify, das vom dummy getriggert wird und eine sub in der 99_myUtils.pm aufruft.

Code Auswählen

Internals: 
   DEF        Sniffer:.* { sniffer_01($EVTPART0) } 
   NAME       Sniffer_notify 
   NOTIFYDEV  Sniffer 
   NR         1671 
   NTFY_ORDER 50-Sniffer_notify 
   REGEXP     Sniffer:.* 
   STATE      active 
   TYPE       notify 
   Readings: 
     2017-05-04 12:47:20   state           active 
Attributes: 
   comment    Starten und Beenden des Sniffers 
   devStateIcon active:general_an:inactive inactive:general_aus@red:active inactive:general_aus 
   group      Debugging 
   room       -System 
   showtime   0

Und noch die sub in 99_myUtils.pm. Die schreibt zunächst einen eyecatcher zum besseren Auffinden im Log, dann einige Deviceinfos für das Debugging und setzt dann die attr in der Global und (bei mir) im HMLAN. Beim Beenden wird wieder alles zurückgesetzt. Ist nicht ganz sauber programmiert, siehe Endemeldung und logIDs beim Beenden. Geht aber.

Code Auswählen

sub sniffer_01($) {
# generats all attributes to activate or deactivate sniffing for one device
#
# ev. dummy-device "off" definieren, bei off ist der Wert im attr logIDs leer
#
my($device) = @_;
my$rec01="none";

{Log 1, "************** eyecatcher ***********************"};
if ($device eq "off") {Log 1, "sniffer_01 ended"} else {Log 1, "sniffer_01 for $device started"};
if ($device eq "off") {$rec01 = "ended"} else {$rec01 = "started"};

my$dev01=ReadingsVal($device,"D-firmware","0");
my$dev02=ReadingsVal($device,"D-serialNr","0");
my$dev03=ReadingsVal(HMLAN1,"D-HMIdAssigned","0");
my$dev04=ReadingsVal(HMLAN2,"D-HMIdAssigned","0");
my$dev05=AttrVal($device,"model","empty");

if ($device ne "off") {Log 3, "$device  model     $dev05"};
if ($device ne "off") {Log 3, "$device  firmware  $dev01"};
if ($device ne "off") {Log 3, "$device  serialNr  $dev02"};
if ($device ne "off") {Log 3, "HMLAN1     HMID      $dev03"};
if ($device ne "off") {Log 3, "HMLAN2     HMID      $dev04"};

if ($device eq "off") {fhem("attr global mseclog 0")} else {fhem("attr global mseclog 1")};
if ($device eq "off") {fhem("attr global verbose 3")} else {fhem("attr global verbose 1")};

{fhem("attr HMLAN1 logIDs $device")};
{fhem("attr HMLAN2 logIDs $device")};
return $rec01;}

Das ist alles, funktioniert bei mir super einfach.

Moin
Bernd

nils_ · 05 Mai 2017, 09:15:12

hab mal ne verständnisfrage:

funktioniert das mit identischen ids? (oder ist nur was in deiner ausgabe falsch?!)

Code Auswählen

2017.05.04 15:15:51 3: HMLAN1     HMID      123ABC
2017.05.04 15:15:51 3: HMLAN2     HMID      123ABC