Hallo Zusammen.
Habe mir mal zum testen einen HUE Dimmer Switch in fhem angelegt und will ihn als Master OFF Schalter der Wohnung nutzen.
Lt. Wiki (https://wiki.fhem.de/wiki/HUE_Dimmer_Switch) angelegt:
defmod DIM_VR_Master_Dimmer HUEDevice sensor 22 1 IODev=hueBridge1
attr DIM_VR_Master_Dimmer userattr initialized
attr DIM_VR_Master_Dimmer IODev hueBridge1
attr DIM_VR_Master_Dimmer alias Master Aus Schalter
attr DIM_VR_Master_Dimmer group Vorraum
attr DIM_VR_Master_Dimmer icon taster_ch
attr DIM_VR_Master_Dimmer room System
und auch das notify:
DIM_VR_Master_Dimmer:.00.* {
#ignore first state change?
if(AttrVal($NAME,"initialized","0") eq "1")
{
fhem("deleteattr ".$NAME." initialized");
#Log 1, "act_on_Master: Ignore first state change to: ".$EVENT;
return;
}
#Welche Taste wurde gedrückt
if(substr($EVENT, 0, 1) eq "1")
{
#Ein wurde gedrückt
Log 1, "act_on_Master: Ein gedrückt -> Schalte Vorraum ein!";
fhem("set VR_Decke on ;");
}
if(substr($EVENT, 0, 1) eq "2")
{
#Dim-Up wurde gedrückt
Log 1, "act_on_Master: Dim-UP gedrückt -> Schalte Vorraum ein!";
fhem("set VR_Decke on ;");
}
if(substr($EVENT, 0, 1) eq "3")
{
#Dim-Down wurde gedrückt
Log 1, "act_on_Master: Dim-DOWN gedrückt -> Schalte Vorraum aus!";
fhem("set VR_Decke off ;");
}
if(substr($EVENT, 0, 1) eq "4")
{
#Aus wurde gedrückt
Log 1, "act_on_Master: Aus gedrückt -> Alles Aus!";
fhem("set A_Szenen scene Aus ;");
}
}
Intervall ist auf 1 und die Reaktionszeit ok und es funktioniert alles.
Leider kommt es vor dass der Schalter auf einmal den letzten Befehl wiederholt sendet.
Das ist natürlich beim 400.* = Master aus für die Wohnung nicht so toll, da die komplette Wohnung abgeschaltet wird.
Das ganze ist z.B.: Heute wieder 2x passiert, es hat sicher keiner gedrückt bzw. es war keiner in der Nähe des Schalters.
Verwendet die Dimmer von euch jemand?
Hat jemand das gleiche Problem bzw. vll. eine Lösung?
PS.: Wollte nicht den alten Thread (https://forum.fhem.de/index.php/topic,50991.0.html) rauskramen.
Vll. hat @Kai-Uwe eine Idee?
Danke
pOpY
Heute schon wieder passiert, keiner eine Idee?
Es passiert auch wenn fhem neugestartet wird (shutdown restart).
Hier noch so ein Problem: https://forum.fhem.de/index.php/topic,71043.0.html
pOpY
häng mal ein log mit verbose 5 an wenn das problem auftritt
Zitat von: justme1968 am 07 Januar 2019, 21:02:07
häng mal ein log mit verbose 5 an wenn das problem auftritt
Hallo.
Nur von dem HUEDevice oder vom IODev?
Tritt immer beim Neustart auf bzw. sonst so alle paar Tage.
Update: Habe das HUEDevice auf verbose 5 -> das wird die SD Card aber nicht lange machen bei 1 Sec poll Zeit
pOpY
@justme1968:
Wie läuft das eigentlich im Modul? Wird der Timestamp des zuletzt empfangen Events gespeichert und nur wenn sich dieser ändert gibt es ein fhem event?
Gesendet von meinem ONEPLUS A6013 mit Tapatalk
vom hue device und vom iodevice.
du kannst ja schon mal zeigen wie es beim neustart ausschaut.
der sensor sendet einen zeitstempel, ein event wird nur erzeugt wenn der zeitstempel vom neuen event ungleich dem alten ist.
Zitat von: justme1968 am 08 Januar 2019, 15:23:44
vom hue device und vom iodevice.
du kannst ja schon mal zeigen wie es beim neustart ausschaut.
der sensor sendet einen zeitstempel, ein event wird nur erzeugt wenn der zeitstempel vom neuen event ungleich dem alten ist.
ok danke für die Info habe ein Log gemacht vom startvorgang, da wird 2x der Button press erkannt, obwohl dieser schon gestern war.
Am besten nach "HIER SCHAUEN" suchen, das ist das notify welches dann die Aktionen triggert.
Hier das Log: https://paste.ubuntu.com/p/VtSRN5ck2V/
Habe es mit Beyond Compare analysiert und das Log bei den beiden notifys verglichen.
Auffällig ist folgendes:
Erster Eintrag:
2019.01.08 20:18:32 4: DIM_VR_Master_Dimmer: lastupdated: 2019-01-07 20:09:46, hash->{lastupdated}: [b]2019-01-07 21:09:46[/b]
...
'state' => {
'lastupdated' => '2019-01-07T20:09:46',
'buttonevent' => 4002
},
Zweiter Eintrag:
2019.01.08 20:19:22 4: DIM_VR_Master_Dimmer: lastupdated: 2019-01-07 21:09:46, hash->{lastupdated}: [b]2019-01-07 20:09:46[/b]
...
'state' => {
'lastupdated' => '2019-01-07T20:09:46'
'buttonevent' => 4002,
}
Es schaut schwer nach localtime & UTC Umrechnungs Problem aus, oder?
2019-01-07 21:09:46 <> 2019-01-07 20:09:46
Obwohl die Daten bei "state" gleich sind (Siehe Log).
Was sagst du dazu?
Das mit dem verbose 5 log bei beiden devices und laufen lassen ist eher schlecht -> jetzt schon über 100MB log in nicht mal einem Tag.
Danke
pOpY
hast du die zeitzohne auf der bridge gesetzt ?
zeig mal bitte ein list vom bridge device.
Zitat von: justme1968 am 09 Januar 2019, 11:26:45
hast du die zeitzohne auf der bridge gesetzt ?
zeig mal bitte ein list vom bridge device.
Habe die bridge ganz normal mit der hue app laufen.
Wie stellt man da die Zeitzone ein?
Ich glaube aber auch nicht dass es an der Bridge liegt, diese liefert ja in beiden fällen nach dem Neustart den gleichen timestamp im state.
Nur die debug Meldung des huedevices darüber hat einmal die falsche Zeit!?
Hier das list:
Internals:
DEF 192.168.0.2 60
INTERVAL 60
NAME hueBridge1
NOTIFYDEV global
NR 59
NTFY_ORDER 50-hueBridge1
STATE connected
TYPE HUEBridge
apiversion 1.16.0
host 192.168.0.2
mac 00:17:88:16:8f:30
manufacturer Royal Philips Electronics
modelName Philips hue bridge 2012
modelid BSB001
name Philips hue
swversion 01041302
updatestate 2 [1,2,3]
zigbeechannel 15
READINGS:
2018-12-02 11:04:42 lastError resource, /groups/7, not available
2019-01-09 13:38:02 state connected
2018-12-17 18:53:55 swupdate ZGB_100B_0104 - 5.127.1.26420
helper:
apiversion 69632
count 0
last_config_timestamp 1547037482
offsetUTC 3600
updatestate 2
Attributes:
alias HUE Bridge
devStateIcon connected:rc_GREEN:on disconnected:rc_RED:off Initialized:message_socket_disabled
group Geräte
httpUtils 1
icon hue_filled_bridge_v1
key *******
noshutdown 1
pollDevices 2
room System
verbose 1
laut list hat deine bridge die richtige zeitzone.
ich verstehe nicht ganz was schief geht.
mach mal bitte ein list <device> .lastupdated. den punkt nicht vergessen. wenn es geht direkt nach dem neustart.
ich weiss auch nicht ob das problem beim neustart und zwischendurch wirklich die gleichen sind.
Zitat von: justme1968 am 10 Januar 2019, 10:08:53
laut list hat deine bridge die richtige zeitzone.
ich verstehe nicht ganz was schief geht.
mach mal bitte ein list <device> .lastupdated. den punkt nicht vergessen. wenn es geht direkt nach dem neustart.
ich weiss auch nicht ob das problem beim neustart und zwischendurch wirklich die gleichen sind.
Hier die Ausgaben:
Vor dem Neustart: DIM_VR_Master_Dimmer 2019-01-07 21:09:46 2019-01-07 21:09:46
Direkt nach dem Neustart: DIM_VR_Master_Dimmer 2019-01-07 20:09:46 2019-01-07 20:09:46
Nachdem die Notifys ausgelöst wurden: DIM_VR_Master_Dimmer 2019-01-07 21:09:46 2019-01-07 21:09:46
Da stimmt irgendwas mit der Zeitzone nicht beim laden des lastupdated Werts , aber ich glaube eher im Code.
Bei mir ist dass immer, zu 100% nachvollziehbar beim starten vom fhem.
Und nach ca. 1-2 Tage wird der letzte Event erneut ausgeführt, was die Taster unbrauchbar macht.
Bin Gerne für weitere Tests bereit.
Hast du Dimmer im Einsatz/Zuhause?
vll. kann @Hans-Ulrich Tag auch diese Tests machen? Er hatte hier das gleiche Problem: https://forum.fhem.de/index.php?action=post;quote=883406;topic=71043.0
pOpY
Kann es sein dass im Code in der 31_HUEDevice.pm an der Stelle vom my lastupdated:
my $lastupdated;
if( my $state = $result->{state} ) {
$lastupdated = $state->{lastupdated};
return undef if( !$lastupdated );
return undef if( $lastupdated eq 'none' );
substr( $lastupdated, 10, 1, ' ' ) if($lastupdated);
my $offset = 0;
if( my $iohash = $hash->{IODev} ) {
substr( $lastupdated, 10, 1, '_' );
my $sec = SVG_time_to_sec($lastupdated);
if( my $offset = $iohash->{helper}{offsetUTC} ) {
$sec += $offset;
Log3 $name, 4, "$name: offsetUTC: $offset";
}
$lastupdated = FmtDateTime($sec);
}
$hash->{lastupdated} = ReadingsVal( $name, '.lastupdated', undef ) if( !$hash->{lastupdated} );
return undef if( $hash->{lastupdated} && $hash->{lastupdated} eq $lastupdated );
if( my $state = $result->{state} ) {
$lastupdated = $state->{lastupdated};
return undef if( !$lastupdated );
return undef if( $lastupdated eq 'none' );
substr( $lastupdated, 10, 1, ' ' ) if($lastupdated);
my $offset = 0;
if( my $iohash = $hash->{IODev} ) {
substr( $lastupdated, 10, 1, '_' );
my $sec = SVG_time_to_sec($lastupdated);
if( my $offset = $iohash->{helper}{offsetUTC} ) {
$sec += $offset;
Log3 $name, 4, "$name: offsetUTC: $offset";
}
$lastupdated = FmtDateTime($sec);
}
$hash->{lastupdated} = ReadingsVal( $name, '.lastupdated', undef ) if( !$hash->{lastupdated} );
return undef if( $hash->{lastupdated} && $hash->{lastupdated} eq $lastupdated );
Log3 $name, 4, "$name: lastupdated: $lastupdated, hash->{lastupdated}: $hash->{lastupdated}";
Log3 $name, 5, "$name: ". Dumper $result if($HUEDevice_hasDataDumper);
$hash->{lastupdated} = $lastupdated;
Beim Starten von fhem bei der huebridge das offsetUTC noch nicht gelesen wurde und somit 0 ist?
Diese Stelle:
my $offset = 0;
if( my $iohash = $hash->{IODev} ) {
substr( $lastupdated, 10, 1, '_' );
my $sec = SVG_time_to_sec($lastupdated);
if( my $offset = $iohash->{helper}{offsetUTC} ) {
$sec += $offset;
Log3 $name, 4, "$name: offsetUTC: $offset";
}
Das würde das Verhalten erklären und auch die Ausgaben/Logs was ich gesammelt habe.
Danach wird nähmlich der Hash->lastupdated auf lastupdated gesetzt und dadurch 2x das Event ausgelöst.
pOpY
ja. das kann sein...
siehst du die offsetUTC meldung im log? nach dem device update oder davor?
aber eigentlich sollte die bridge vorher aktualisiert werden.
und es erklärt noch nicht das problem beim betrieb.
Hab mir in der 32_HUEDevice.pm das my lastupdated angesehen bzw. das Problem versucht zu debuggen.
Das Problem ist wirklich das beim starten die HUEBridge das offsetUTC erst nach einiger Zeit abfragt und bekommt.
Habe 2x debug Meldungen hinzugefügt:
my $offset = 0;
if( my $iohash = $hash->{IODev} ) {
substr( $lastupdated, 10, 1, '_' );
my $sec = SVG_time_to_sec($lastupdated);
if( my $offset = $iohash->{helper}{offsetUTC} ) {
$sec += $offset;
Log3 $name, 4, "$name: offsetUTC: $offset";
}else{
Log 1, "no offset!";
}
$lastupdated = FmtDateTime($sec);
}else{
Log 1, "no iohash!";
}
Es kommt nun immer "no offset!" bis zum 2ten notify nach dem neustart wo die bridge dann offsetUTC bekommen hat.
Habe es dann mit "list hueBridge1" kontrolliert gleich nach dem Neustart:
Es fehlt offsetUTC!!!
Internals:
DEF 192.168.0.2 60
INTERVAL 60
NAME hueBridge1
NOTIFYDEV global
NR 59
NTFY_ORDER 50-hueBridge1
STATE connected
TYPE HUEBridge
host 192.168.0.2
mac 00:17:88:16:8f:30
manufacturer Royal Philips Electronics
modelName Philips hue bridge 2012
READINGS:
2018-12-02 11:04:42 lastError resource, /groups/7, not available
2019-01-10 11:47:48 state connected
2018-12-17 18:53:55 swupdate ZGB_100B_0104 - 5.127.1.26420
helper:
count 0
last_config_timestamp 1547117268
Attributes:
alias HUE Bridge
devStateIcon connected:rc_GREEN:on disconnected:rc_RED:off Initialized:message_socket_disabled
group Geräte
httpUtils 1
icon hue_filled_bridge_v1
key ****
noshutdown 1
pollDevices 2
room System
verbose 1
Und nach ein paar Minuten Laufzeit,
offsetUTC ist vorhanden:
Internals:
DEF 192.168.0.2 60
INTERVAL 60
NAME hueBridge1
NOTIFYDEV global
NR 59
NTFY_ORDER 50-hueBridge1
STATE connected
TYPE HUEBridge
apiversion 1.16.0
host 192.168.0.2
mac 00:17:88:16:8f:30
manufacturer Royal Philips Electronics
modelName Philips hue bridge 2012
modelid BSB001
name Philips hue
swversion 01041302
updatestate 2 [1,2,3]
zigbeechannel 15
READINGS:
2018-12-02 11:04:42 lastError resource, /groups/7, not available
2019-01-10 11:48:49 state connected
2018-12-17 18:53:55 swupdate ZGB_100B_0104 - 5.127.1.26420
helper:
apiversion 69632
count 0
last_config_timestamp 1547117328
offsetUTC 3600
updatestate 2
Attributes:
alias HUE Bridge
devStateIcon connected:rc_GREEN:on disconnected:rc_RED:off Initialized:message_socket_disabled
group Geräte
httpUtils 1
icon hue_filled_bridge_v1
key ****
noshutdown 1
pollDevices 2
room System
verbose 1
Das erklärt nun warum sich fhem so verhält.
Zitat von: justme1968 am 10 Januar 2019, 11:51:24
ja. das kann sein...
siehst du die offsetUTC meldung im log? nach dem device update oder davor?
aber eigentlich sollte die bridge vorher aktualisiert werden.
und es erklärt noch nicht das problem beim betrieb.
Wie kann es sein das das bei mir (und anderen) nicht der Fall ist (offsetUTC wird erst später abgefragt/gesetzt)?
welche NR steht beim device in den internals ?
Zitat von: justme1968 am 10 Januar 2019, 12:05:27
welche NR steht beim device in den internals ?
Die NR ist 265, hier das ganze Listing:
Internals:
DEF sensor 22 1 IODev=hueBridge1
ID S22
INTERVAL 1
IODev hueBridge1
NAME DIM_VR_Master_Dimmer
NR 265
STATE 4002
TYPE HUEDevice
lastupdated 2019-01-07 21:09:46
manufacturername Philips
modelid RWL021
name Schalter Eingang
on 1
reachable 1
swversion 5.45.1.17846
type ZLLSwitch
uniqueid 00:17:88:01:04:ef:29:44-02-fc00
READINGS:
2019-01-07 21:09:46 battery 100
2019-01-10 11:48:49 batterystate high
2019-01-07 21:09:46 reachable 1
2019-01-07 21:09:46 state 4002
helper:
devtype S
reachable 0
update_timeout 1
setList:
Attributes:
IODev hueBridge1
alias Master Aus Schalter
group Vorraum
icon taster_ch
initialized 1
room System
userattr initialized
unsigned char Überlauf im Module?
nein. ich hatte gehofft es liegt an einer falschen reihenfolge :)
eine ideen zum testen:
in 31_HUEDevice.pm in zeile 375 das +10 mal deutlich erhöhen. damit wird die erst abfrage erst mal verzögert. geht es dann mit dem start?
Zitat von: justme1968 am 10 Januar 2019, 13:40:08
nein. ich hatte gehofft es liegt an einer falschen reihenfolge :)
eine ideen zum testen:
in 31_HUEDevice.pm in zeile 375 das +10 mal deutlich erhöhen. damit wird die erst abfrage erst mal verzögert. geht es dann mit dem start?
Habs mal auf +80 gestellt da bei mir das offsetUTC meistens 53 Sekunden dauerte bis der Helper vom bridge IODEV den Wert hatte.
Mit +80 3x neu gestartet und das Problem beim starten ist weg.
Das Problem während Betrieb kann ich noch nicht sagen ob es weg ist. Das dauert immer länger.
Vermutlich aber nicht.
Hätte eine Idee und Frage.
Die Frage zuerst: Ist die einzige Stelle wo das notify/event ausgelöst wird im "my lastupdated" in der 31_HUEDevice.pl?
Nun die Idee: Falls ja, mann könnte doch einbauen dass wenn kein offsetUTC vorhanden (Fehlerfall bei mir beim starten und vll. auch während Betrieb) dass er den offset vom system nimmt.
Ich vermute dass zu 99% auf der Bridge und am fhem die gleiche Zeitzone sind.
So währen vll. beide Fälle erschlagen ;)
Was sagst du dazu?
Danke
pOpY
ich muss mal überlegen wir man den start synchronisieren kann. so lange zu warten gefällt mir nicht.
das sollte die einzige stelle sein.
damit wäre nicht abgefangen wenn auf der bridge etwas falsches oder gar nichts gesetzt ist.
hast du eigentlich pollDevices gesetzt ?
das ganze kann auch nichts mit dem problem beim betrieb zu tun haben.
Zitat von: justme1968 am 10 Januar 2019, 14:24:02
ich muss mal überlegen wir man den start synchronisieren kann. so lange zu warten gefällt mir nicht.
das sollte die einzige stelle sein.
damit wäre nicht abgefangen wenn auf der bridge etwas falsches oder gar nichts gesetzt ist.
hast du eigentlich pollDevices gesetzt ?
das ganze kann auch nichts mit dem problem beim betrieb zu tun haben.
ok, ich vermute dass das problem während dem Betrieb das gleiche ist.
Was ist z.B.': wenn die bridge neu startet, braucht dann das offsetUTC auch wieder eine Zeit bis es gesetzt wird?
Ja, pollDevices ist auf 2. Wollte die bridge damit entlasten und lt. div, Threads & Wiki soll es dann ja auch so sein, oder?
nein. die internen werte im modul gehen nicht verloren so lange fhem nicht neu gestartet wird.
ja. pollDevices ist gut.
Zitat von: justme1968 am 10 Januar 2019, 14:30:52
nein. die internen werte im modul gehen nicht verloren so lange fhem nicht neu gestartet wird.
ok, dann is gut :)
Zitat von: justme1968 am 10 Januar 2019, 14:30:52
ja. pollDevices ist gut.
ok, danke für die Bestätigung.
Ist, ja echt komisch dass fhem bzw. meine bridge so lange benötigt bis die Daten da sind.
Habe auch httpUtils auf 1, da ich ansonsten FHEMWEB extrem langsam wurde (blockierte).
(muss dazu sagen dass ich aber sehr zu viele Geräte mit Intervall 1 hatte, die ich jetzt reduziert habe. Habs dann nicht mehr umgstellt von httputils 1).
Passt das auch ?
Zitat von: justme1968 am 10 Januar 2019, 14:24:02
ich muss mal überlegen wir man den start synchronisieren kann. so lange zu warten gefällt mir nicht.
Kann ich dich mit Tests da irgendwie Unterstützen?
sobald mir etwas einfällt :)
Zitat von: justme1968 am 10 Januar 2019, 18:13:45
sobald mir etwas einfällt :)
Ok :-)
Gesendet von meinem ONEPLUS A6013 mit Tapatalk
@justme1968:
Ich habe eine Idee ::)
Einen neuen internal namens lastupdated_UTC machen.
In diesem wird immer der von der bridge gesendete UTC timestamp geschrieben und gegen den gespeicherten state/hash verglichen.
Ist er anders wird erst die Zeitumrechnung gemacht und der lastupdated aktualisiert (welcher dann in localzeit ist).
So würde es egal sein wann offsetUTC daherkommt, es würde lediglich lastupdated nach einem boot nicht passen.
Was hältst du davon?
pOpY
Zitat von: justme1968 am 10 Januar 2019, 18:13:45
sobald mir etwas einfällt :)
Was sagst du zu meiner Idee für das startup Problem?
Hatte wieder das Problem dass einfach so das letzte Event ausgelöst wird (nach ~1 Tag Laufzeit).
Um die rpi sdcard zu schonen habe ich nun das Log auf einen Samba Share auf meinen Windows Server mit HDD umgestellt.
Bei dem DEV & der Bridge ist verbose 5 gesetzt.
So sehen wir hoffentlich von was das Problem ausgelöst wird.
Heute wie das Problem aufgetreten ist, ist mir folgendes Aufgefallen:
Ich habe ein notify welches einen "batterystate" als reading beim Gerät setzt:
(BM_.*|DIM_.*):battery.* {
#Device have low battery?
if (ReadingsNum($NAME, "battery", 0) < 10) {
#device has low battery
if (ReadingsVal($NAME, "batterystate", "high") eq "high") {
#speak alexa and log entry
fhem("set pushmsg_all message Batterie im Gerät ".$NAME." fast leer, bitte tauschen! ".FmtTime(time()));
Log 1, "act_BM_Battery: Batterie im Gerät ".$NAME." fast leer, bitte tauschen! ";
}
#set low battery state
fhem("setreading ".$NAME." batterystate low");
}
#battery high again
#if (ReadingsNum($NAME, "battery", 0) >= 100 && (ReadingsVal($NAME, "batterystate", "low") eq "low") ) {
if (ReadingsNum($NAME, "battery", 0) >= 80) {
#battery is high again
fhem("setreading ".$NAME." batterystate high");
}
}
Da setzte ich mit setreading "high" oder "low" je nach battery Wert, aber verhindere somit mehrfache ausgaben auf Alexa bzw. ans Handy.
Im Log wurde 2x state vom DImmer geändert, das schreibe ich ins log:
Log:
2019.01.11 15:04:53 1: act_on_Master: EVENT TO DEBUG: 4002 !!!!!!!!!!!!!!!!!!!!! HIER SCHAUEN!!!!!!!!
2019.01.11 15:05:53 1: act_on_Master: EVENT TO DEBUG: 4002 !!!!!!!!!!!!!!!!!!!!! HIER SCHAUEN!!!!!!!!
Habe dann 2h später wie ich Zeit hatte ein list vom DImmer gemacht:
Internals:
DEF sensor 22 1 IODev=hueBridge1
ID S22
INTERVAL 1
IODev hueBridge1
NAME DIM_VR_Master_Dimmer
NR 265
STATE 4002
TYPE HUEDevice
lastupdated 2019-01-07 21:09:46
manufacturername Philips
modelid RWL021
name Schalter Eingang
on 1
reachable 1
swversion 5.45.1.17846
type ZLLSwitch
uniqueid 00:17:88:01:04:ef:29:44-02-fc00
READINGS:
2019-01-07 21:09:46 battery 100
2019-01-11 15:05:53 batterystate high
2019-01-07 21:09:46 reachable 1
2019-01-07 21:09:46 state 4002
helper:
devtype S
reachable 0
update_timeout 1
setList:
Attributes:
IODev hueBridge1
alias Master Aus Schalter
group Vorraum
icon taster_ch
initialized 1
room System
userattr initialized
Interessant ist die Zeit vom batterystate reading, diese wurde aktualisiert und deckt sich mit dem wo das notify ausgelöst wurde
List: 2019-01-11 15:05:53 batterystate high
Log: 2019.01.11 15:05:53 1: act_on_Master: EVENT TO DEBUG: 4002 !!!!!!!!!!!!!!!!!!!!! HIER SCHAUEN!!!!!!!!
Habe dann versucht mittels:
setreading DIM_VR_Master_Dimmer batterystate high
setreading DIM_VR_Master_Dimmer batterystate low
setreading DIM_VR_Master_Dimmer battery 99
setreading DIM_VR_Master_Dimmer battery 100
Das Problem ev. nachzustellen aber ohne Erfolg, das Notify wird nicht ausgelöst.
Was sagst du dazu? Mache ich da was falsch?Jetzt läuft mal das Log und dann sehen wir weiter.
Danke
pOpY
Ich habe das gleich bei mir auch beobachtet, nach dem neustart von FHEM wird immer zumindest bei einem Hue Dimmer einmal ein Event ausgelöst. Nachdem ich den Thread gelesen habe, ist die Ursache anscheinend gefunden. Also popy ist nicht der Einzige wo das auftritt. Beste Grüsse und schönes Wochenende!
Zitat von: inoma am 11 Januar 2019, 22:22:14
Ich habe das gleich bei mir auch beobachtet, nach dem neustart von FHEM wird immer zumindest bei einem Hue Dimmer einmal ein Event ausgelöst. Nachdem ich den Thread gelesen habe, ist die Ursache anscheinend gefunden. Also popy ist nicht der Einzige wo das auftritt. Beste Grüsse und schönes Wochenende!
Yeah, ich bin nicht alleine ;)
Probier mal als workaround:
in 31_HUEDevice.pm in zeile 375 das +10 auf +80 ändern
Dann "shutdown restart" bei mir ist das Problem weg.
Ist aber nur ein Workaround, sprich das erste Update wird er nach 80 Sekunden gemacht.
Mal schauen was @justme1968 für Ideen hat um es schöner zu lösen ;)
Eine Frage Interessiert mich brennend, hast auch du nach ~1-2 Tage auf einmal ein Notify was auslöst weil ein Schalter den gleichen state wiederholt?
Also das einfach Schaltbefehle ausgeführt werden, obwohl keiner gedrückt hat.
pOpY
@justme1968:
Ich habe den sporadischen Fehler ;)
Siehe Log:
2019.01.11 23:06:58 4: parse status message for DIM_VR_Master_Dimmer
2019.01.11 23:06:58 5: $VAR1 = {
'type' => 'ZLLSwitch',
'config' => {
'reachable' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),
'on' => $VAR1->{'config'}{'reachable'},
'pending' => [],
'battery' => 100
},
'swversion' => '5.45.1.17846',
'state' => {
'lastupdated' => '2019-01-07T20:09:46',
'buttonevent' => 4002
},
'manufacturername' => 'Philips',
'uniqueid' => '00:17:88:01:04:ef:29:44-02-fc00',
'name' => 'Schalter Eingang',
'modelid' => 'RWL021'
};
2019.01.11 23:06:58 4: DIM_VR_Master_Dimmer: offsetUTC: 3600
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/5
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/8
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/11
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/14
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/17
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET sensors/20
2019.01.11 23:06:58 4: using HttpUtils_NonblockingGet: GET
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/22
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/5
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/8
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/11
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/14
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/17
2019.01.11 23:06:59 4: using HttpUtils_NonblockingGet: GET sensors/20
2019.01.11 23:06:59 2: hueBridge1: http request failed: http://192.168.0.2/api/MIMTbOjbs1GqHvrK68SHhIQoeKtCVIwrMx7JOlB7/sensors/20: empty answer received
2019.01.11 23:06:59 4: parse status message for hueBridge1
2019.01.11 23:06:59 4: hueBridge1: message for unknow sensor received: hueBridge1-S1
2019.01.11 23:06:59 4: hueBridge1: message for unknow sensor received: hueBridge1-S13
2019.01.11 23:07:00 4: parse status message for DIM_VR_Master_Dimmer
2019.01.11 23:07:00 5: $VAR1 = {
'state' => {
'buttonevent' => 4002,
'lastupdated' => '2019-01-07T20:09:46'
},
'manufacturername' => 'Philips',
'uniqueid' => '00:17:88:01:04:ef:29:44-02-fc00',
'type' => 'ZLLSwitch',
'config' => {
'reachable' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),
'on' => $VAR1->{'config'}{'reachable'},
'pending' => [],
'battery' => 100
},
'swversion' => '5.45.1.17846',
'name' => 'Schalter Eingang',
'modelid' => 'RWL021'
};
2019.01.11 23:07:00 4: DIM_VR_Master_Dimmer: offsetUTC: 3601
2019.01.11 23:07:00 4: DIM_VR_Master_Dimmer: lastupdated: 2019-01-07 21:09:47, hash->{lastupdated}: 2019-01-07 21:09:46
2019.01.11 23:07:00 5: DIM_VR_Master_Dimmer: $VAR1 = {
'state' => {
'buttonevent' => 4002,
'lastupdated' => '2019-01-07T20:09:46'
},
'manufacturername' => 'Philips',
'uniqueid' => '00:17:88:01:04:ef:29:44-02-fc00',
'type' => 'ZLLSwitch',
'config' => {
'reachable' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),
'on' => $VAR1->{'config'}{'reachable'},
'pending' => [],
'battery' => 100
},
'swversion' => '5.45.1.17846',
'name' => 'Schalter Eingang',
'modelid' => 'RWL021'
};
2019.01.11 23:07:00 1: act_on_Master: EVENT TO DEBUG: 4002 !!!!!!!!!!!!!!!!!!!!! HIER SCHAUEN!!!!!!!!
Das offsetUTC des Helpers ändert sich um eine Sekunde!
Vorher: 2019.01.11 23:06:58 4: DIM_VR_Master_Dimmer: offsetUTC: 3600
Problem: 2019.01.11 23:07:00 4: DIM_VR_Master_Dimmer: offsetUTC: 3601
Somit wäre das Problem auch gelöst wenn das Modul nicht mit der lokalzeit in lastupdated arbeiten würde sondern mit der UTC.
Was sagst du dazu?
pOpY
sorry. fürs nicht melden.
ich möchte erst noch die alexa geschichte fertig machen. dann schaue ich mir dein problem in ruhe an.
Zitat von: justme1968 am 12 Januar 2019, 11:41:05
sorry. fürs nicht melden.
ich möchte erst noch die alexa geschichte fertig machen. dann schaue ich mir dein problem in ruhe an.
Kein Thema.
Habe mich mal selbst an die Arbeit gemacht und folgendes realisiert:
- readings werden nur übernommen wenn internal lastupdated sich ändert -> Somit ist das Problem beim starten weg und auch wenn sich offsetUTC um eine Sekunden ändert (sporadischer Fall)
- Damit die angezeigten Zeiten die Lokalzeiten sind, habe ich folgendes gemacht
- ist noch kein offsetUTC von der bridge vorhanden wird der lokale verwendet -> egal wenn es anders wäre als bei der bridge da es nur um die Anzeige geht
- ist ein offsetUTC von der bridge vorhanden wird dies verwendet -> egal wenn sich dieses nun um 1 Sekunde ändert da es nur um die Anzeige geht
- das ganze wird als internal/reading lastupdated_local verwaltet/gespeichert
Kannst du Bitte mal über den Code/Patch schauen, da ich in perl nicht so bewandert bin.
Meine ersten Tests schauen vielversprechend aus, nach dem Neustart wird nixhts ausgelöst, Sporadischer Langzeittest läuft....
Angehängt die Files.
Ausgegangen bin ich von der aktuellen Version (heute ein Update gemacht).
Zitat von: inoma am 11 Januar 2019, 22:22:14
Ich habe das gleich bei mir auch beobachtet, nach dem neustart von FHEM wird immer zumindest bei einem Hue Dimmer einmal ein Event ausgelöst. Nachdem ich den Thread gelesen habe, ist die Ursache anscheinend gefunden. Also popy ist nicht der Einzige wo das auftritt. Beste Grüsse und schönes Wochenende!
Kannst du diese Version mal testen, also einfach die gepatchte 31_HUEDevice.pm einspielen nach /opt/fhem/FHEM und dann noch "chown fhem:dialout 31_HUEDevice.pm"
pOpY
@justme1968:
Kleines Update, seit ~3,5 Tagen keine einzige Fehlauslösung mit meiner Änderung.
Ich lasse jetzt noch bis Samstag laufen, dann ist es eine Woche ohne Fehlauslösung ;)
Hattest du schon Zeit dir den Patch anzusehen?
Wo kann ich den einchecken/einreichen?
Danke
pOpY
Ich habe gerade eben (heute Abend) deinen Patch eingespielt, und 2 mal shutdown-restart gemacht, ich kann bestätigen das mit dem Patch das event beim restart nicht mehr auftritt. Hier nochmal der Auszug aus dem Logfile von heute morgen, wo der Fehler noch auftritt:
2019.01.15 07:48:36 3: CUL_HM set Alarm_Smoke_SZ statusRequest
2019.01.15 07:48:36 3: HueDimmerKüche1 Event: 4002
2019.01.15 07:48:37 3: CUL_HM set Schalter_HausTuer statusRequest
Allerdings ist das event noch ein einziges mal vor dem ersten Shutdown-restart aufgetreten, und zwar nachdem ich deinen Patch mit 'reload 31_HUEDevice.pm' geladen hatte:
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Initialize redefined at ./FHEM/31_HUEDevice.pm line 160.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_devStateIcon redefined at ./FHEM/31_HUEDevice.pm line 192.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_summaryFn redefined at ./FHEM/31_HUEDevice.pm line 250.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Define redefined at ./FHEM/31_HUEDevice.pm line 259.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Undefine redefined at ./FHEM/31_HUEDevice.pm line 383.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_SetParam redefined at ./FHEM/31_HUEDevice.pm line 398.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Set redefined at ./FHEM/31_HUEDevice.pm line 613.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine cttorgb redefined at ./FHEM/31_HUEDevice.pm line 850.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine xyYtorgb redefined at ./FHEM/31_HUEDevice.pm line 887.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Get redefined at ./FHEM/31_HUEDevice.pm line 934.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_ReadFromServer redefined at ./FHEM/31_HUEDevice.pm line 1019.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_GetUpdate redefined at ./FHEM/31_HUEDevice.pm line 1036.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDeviceSetIcon redefined at ./FHEM/31_HUEDevice.pm line 1080.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Parse redefined at ./FHEM/31_HUEDevice.pm line 1106.
2019.01.15 23:19:00 1: PERL WARNING: Subroutine HUEDevice_Attr redefined at ./FHEM/31_HUEDevice.pm line 1505.
2019.01.15 23:19:01 3: HueDimmerKüche1 Event: 4002
2019.01.15 23:19:04 0: Server shutdown
2019.01.15 23:19:04 1: HMCCURPCPROC: [d_rpcBidCos_RF] Stopping RPC server
Danke für deine Tests.
Dass es nach dem einspielen und reload einmal aufgetreten ist kann ich erklären ;)
Die neue Version arbeitet mit lastupdated timestamps auf UTC Basis, also nicht mit der Lokalzeit wie vorher.
Da dein fhem bei allen Geräten als letzten lastupdated Timestamp auf Basis der Lokalzeit gespeichert hatte (alte Version) wurden diese aktualisiert auf den UTC timestamp und das Event je Gerät einmal getriggert.
Jeder weitete Neustart und auch zufälliges Auslösen während der Laufzeit (so wie bei mir) sollte jetzt der Vergangenheit angehören ;)
Ich werde ich paar Tage testen und mich wieder melden.
Danke
pOpY
Heute morgen auch kein Fehler bei 2-maligem restart. Scheint wirklich gut zu funktionieren.
Zitat von: inoma am 16 Januar 2019, 08:54:21
Heute morgen auch kein Fehler bei 2-maligem restart. Scheint wirklich gut zu funktionieren.
Danke für Deine positive Rückmeldung.
Warten wir mal auf @justme1968 bis er Zeit hat ;)
lg
pOpY
Bisher ist der Fehler nicht wieder augetreten, ich denke mal dein Patch funktioniert, und könnte übernommen werden.
Zitat von: inoma am 18 Januar 2019, 11:35:29
Bisher ist der Fehler nicht wieder augetreten, ich denke mal dein Patch funktioniert, und könnte übernommen werden.
Danke für die Info.
Auch bei mir bis jetzt kein Problem mehr ;)
Bin mit @justme1968 per PM in Kontakt und er wird sich das Thema nächste Woche ansehen.
pOpY
ich habe den patch eingebaut.
danke
andre
Zitat von: justme1968 am 22 Januar 2019, 11:53:20
ich habe den patch eingebaut.
danke
andre
Sprich ein update 31_HUEDevice und ich habe das offiziellen update?
ja. ab morgen halb 9.
Danke
Gesendet von meinem ONEPLUS A6013 mit Tapatalk
Eingespielt, Änderungen sind drinnen und funktionieren.
Danke