Philipps Hue mit HM-LC-SW1-FM schaltet zeitverzögert

[steewan]

Hallo,

ich habe bei mir einen  HM-LC-SW1-FM installiert. Wenn dieser geschaltet wird, sollen die Leuchten mit Philipps Hue eingeschaltet werden. Das ganze habe ich mit einem define ... notify switch:on set hue on  verknüpft. Soweit funktioniert dieses auch. Allerdings gibt es zwischen dem betätigen des Schalters und dem Schalten der Leuchten eine Pause von ca. 3-4 Sekunden, was natürlich nciht schön ist. Hat jemand eine Idee wieso?

Wenn ich die Leuchten direkt mit Philipps Hue oder der Weboberfläche schalte, dann werden die Leuchten nicht mit solch einer Verzögerung geschaltet.

Viele Grüße
Stefan

[der-Lolo]

Ich kann das verhalten bestätigen, wenn ich den Schalter betätige vergeht ne Weile bis die Hue Lampe angeht - wenn du den Kanal aber über die webcmd schaltest verhalten sie sich genau wie mit der Hue app.

Ich kann das zwar in meinem Anwendungsfall akzeptieren - grundsätzlich würde ich aber auch gerne wissen wie es zu dieser Verzögerung kommt, ich habe schon überlegt einen Dummy zu Peeren und die Hue dann mithilfe das Dummys zu schalten. Ich vermute nämlich das die Hue Lampe erst schaltet wenn der HM-Switch eine positive Rückmeldung gibt.

[martinp876]

ihr könnt sicher entsprechende logs ziehen. Schaltet einmal "viele" logs ein - und dann schauen, was  wann passiert

attr global verbose 5
attr global mseclog 1

schalten und loggen, timing auswerten

Gruss Martin

[der-Lolo]

Hallo Martin,
Ok - ich habe gerade mal mein Glück versucht...

2013.11.05 15:25:18.657 5: HM_LAN dispatch A0F74A4101AA72B0655060601C80080C8::-64:HM_LAN
2013.11.05 15:25:18.721 5: Triggering ku_sw1.1 (9 changes)
2013.11.05 15:25:18.724 5: Notify loop for ku_sw1.1 phyLevel: 100 %
2013.11.05 15:25:18.738 5: Triggering Hue_ku_an
2013.11.05 15:25:18.741 5: Cmd: >set HUEDevice13 on : bri 27 : ct 359<
2013.11.05 15:25:18.763 5: HUEBridge_HTTP_Request http://192.168.178.31//lights/13/state: Got data, length: 122
2013.11.05 15:25:18.790 5: HUEBridge_HTTP_Request http://192.168.178.31//lights/13: Got data, length: 358
2013.11.05 15:25:18.814 5: Triggering HUEDevice13 (6 changes)
2013.11.05 15:25:18.817 5: Notify loop for HUEDevice13 ct: 359 (2785K)
2013.11.05 15:25:18.845 5: Cmd: >set HUEDevice12 on : bri 27 : ct 359<
2013.11.05 15:25:18.867 5: HUEBridge_HTTP_Request http://192.168.178.31//lights/12/state: Got data, length: 122
2013.11.05 15:25:18.894 5: HUEBridge_HTTP_Request http://192.168.178.31/api/lights/12: Got data, length: 359
2013.11.05 15:25:18.919 5: Triggering HUEDevice12 (6 changes)
2013.11.05 15:25:18.922 5: Notify loop for HUEDevice12 ct: 359 (2785K)
2013.11.05 15:25:18.971 5: Triggering ku_sw1.2 (2 changes)
2013.11.05 15:25:18.974 5: Notify loop for ku_sw1.2 chn:off  phys:100 %
2013.11.05 15:25:18.997 5: Triggering ku_sw1.3 (2 changes)
2013.11.05 15:25:19.000 5: Notify loop for ku_sw1.3 chn:off  phys:100 %

So wie ich das sehe sieht der zeitliche Verlauf beim schalten von ku_sw gar nicht so schlecht aus - die LEDs die direkt am Schalter hängen schalten aber unverzüglich, die HUE leuchtmittel hängen etwa 2 Sekunden hinterher...

Beim schalten über den webcmd:

2013.11.05 15:34:09.951 5: Cmd: >set ku_sw1.1 on<
2013.11.05 15:34:09.957 5: Triggering ku_sw1.1 (1 changes)
2013.11.05 15:34:09.960 5: Notify loop for ku_sw1.1 set_on
2013.11.05 15:34:09.982 2: CUL_HM set ku_sw1.1 on
2013.11.05 15:34:09.984 5: HMLAN_Send:  HM_LAN I:+1AA72B,00,00,
2013.11.05 15:34:09.988 5: HMLAN_Send:  HM_LAN S:S28AF5C05 stat:  00 t:00000000 d:01 r:28AF5C05 m:01 A011 065506 1AA72B 0201C80000
2013.11.05 15:34:09.994 4: Connection closed for FHEMWEB:192.168.178.8:60649
2013.11.05 15:34:09.997 4: Connection closed for FHEMWEB:192.168.178.8:60654
2013.11.05 15:34:09.999 4: Connection closed for FHEMWEB:192.168.178.8:60651
2013.11.05 15:34:10.128 4: HTTP FHEMWEB:192.168.178.8:60655 GET /fhem?room=Test
2013.11.05 15:34:10.212 4: /fhem?room=Test / RL:1487 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2013.11.05 15:34:10.215 5: HMLAN_Parse: HM_LAN R:R28AF5C05 stat:0001 t:62E26372 d:FF r:FFC0     m:01 8002 1AA72B 065506 0101C80044A4
2013.11.05 15:34:10.217 5: HM_LAN dispatch A0F0180021AA72B0655060101C80044A4::-64:HM_LAN
2013.11.05 15:34:10.230 5: Triggering ku_sw1.1 (8 changes)
2013.11.05 15:34:10.232 5: Notify loop for ku_sw1.1 level: 100 %
2013.11.05 15:34:10.245 5: Triggering Hue_ku_an
2013.11.05 15:34:10.248 5: Cmd: >set HUEDevice13 on : bri 27 : ct 359<
2013.11.05 15:34:10.270 5: HUEBridge_HTTP_Request http://192.168.178.31/api//lights/13/state: Got data, length: 122
2013.11.05 15:34:10.300 5: HUEBridge_HTTP_Request http://192.168.178.31//lights/13: Got data, length: 358
2013.11.05 15:34:10.325 5: Triggering HUEDevice13 (6 changes)
2013.11.05 15:34:10.328 5: Notify loop for HUEDevice13 ct: 359 (2785K)
2013.11.05 15:34:10.348 5: Cmd: >set HUEDevice12 on : bri 27 : ct 359<
2013.11.05 15:34:10.371 5: HUEBridge_HTTP_Request http://192.168.178.31/api//lights/12/state: Got data, length: 122
2013.11.05 15:34:10.402 5: HUEBridge_HTTP_Request http://192.168.178.31//lights/12: Got data, length: 359
2013.11.05 15:34:10.426 5: Triggering HUEDevice12 (6 changes)

Mein Define schaut so aus...

define Hue_ku_an notify ku_sw1.1:on.* set HUEDevice13 on : bri 27 : ct 359 ;; set HUEDevice12 on : bri 27 : ct 359

[martinp876]

Hi,

wie du schon sagst - alles was zu sehen ist reagiert im Rahmen von 500ms.
mit HUE kenne ich mich nicht aus, musst du bei den Spezialisten nachfragen. Es wird offensichtlich über http angesprochen. Hier kann ich nicht sehen, wie lange das braucht.
HM reagiert im Rahmen seiner Möglichkeiten.

Gruss Martin

[justme1968]

wenn der http request zurück kommt schaltet die bridge die lampen. d. h da ist auch nicht wirklich eine verzögerung. schalte dir lampen mal testweise einfach nur mit 'set on' und vielleicht auch ein mal mit zusätzlichem 'transitiontime 0'.

macht das einen unterschied?

siehst du eine verzögerung zwischen erster und zweiter lampe?

gruss
  andre

[der-Lolo]

Eine Verzögerung zwischen erster und zweiter Lampe gibt es nicht wohl aber zwischen direkt am Schalter angeschlossener LEDs und den Hue leuchten...
Ein einfaches set on oder set on transitiontime 0 bringt keinen Unterschied...
Ich hab das für mich schon als Schönheitsfehler abgehackt - habe auch noch einen zweiten HM Schalter mit dem ich das hue System schalte, hier ist es genauso...

Was mich nur wundert ist das beim schalten über Webcmd die Verzögerung zwar auch da ist, aber eindeutig kürzer ausfällt...
Vor ner Weile fragte mal jemand ob man hue über einen MDIR Bewegungsmelder schalten kann - da schrieb ich dann das er sicher nicht glücklich damit wird - weil ja der MDIR schon nicht umgehend schaltet und dann noch die hue Verzögerung dazu käme...

[justme1968]

ja. ich weiß. wobei ich meine hues über einen mdir schalte es die verzögerung völlig ok und nicht größer als bei einem hm led dimmer. der allerdings auch über fhem und nicht direkt.

bei den bewegungsmeldern kommt ja auch noch dazu das das erkenne an sich manchmal länger dauert als erwartet.

warum das direkt schalten der hues bei dir per
notify so sehr viel langsamer ist als über das web frontend ist komisch. aber vielleicht ist das eine gerade unter der schwelle 'verzögerung bemerkbar' und das andere gerade drüber und der unterschied ist messbar gar nicht so viel größer.

gruss
  andre

[der-Lolo]

Hehe, vielleicht mach ich ja mal ein Video...
In meinem fall hab ich kein Problem - die LEDs sorgen ja für licht - die HUEs sind eh nur detailbeleuchtung...

[martinp876]

Langsame notifies hatte ich auch schon beobachtet. Je nachdem, wie es bearbeitet wird sind bei einem Notify erst ALLE mithörer zu informieren - über alle Events. Und die Hörer/empfänger der notifies müssen ggf ihre Arbeit verrichten. Das kann das schreiben von files sein  - oder schlimmeres.
Hast du viele Notifies am Start? Bedenke, dass quasi alle Logfiles eigentlich notifies sind - und es kann noch andere Versteckte geben. Das muss kein Problem sein, könnte aber.
Eine Verzögerung von 2-3 sek ist aber dennoch gewaltig.
Trotzdem - kontrollieren einmal, wen du alles an start findest.

Gruss Martin

[Benny_82]

Die Schaltzeiten der ersten HUE-Lampe sind bei mir in Ordnung, jedoch habe ich den Effekt, das die Lampen deutlich nacheinander schalten.
Es schwankt alles ein wenig, aber ich würde schätzen 0,5 bis 1 Sekunde kann es schon sein.
Wollte ein "aufblinken" realisieren als optische Rückmeldung, dass macht aber keinen sind wenn die lampen völlig asynchron aufblinken...

Habt ihr ähnliche Effekte oder läuft es bei euch Zeitgleich?
Der Effekt tritt auch bei einem Wechsel mit direkt mit "set lightszene scene hell" auf. Ich kann immer schön beobachten wie Lampe für Lampe nacheinander eingeschaltet wird.

Hardware:
Rapsberry PI Model B 512
Sollte alles auf dem Neuesten Stand sein

HUE-Bridge sowie diverse HUE - Bulbs und LC Lampen

[justme1968]

die lampen werden zur zeit aus dem fhem modul unabhängig gesteuert. d.h. nacheinander und nicht als hue groups. auch wenn es über lightscene geht.

bitte schau mal zum einen ob die hue bulbs alle die gleiche firmware haben und zum anderen ob es einheitlicher wird wenn du zum aufblinken die ramptime explizit sehr niedrig (also z.b. auf 1) setzt oder ob ein set alert weniger asynchron ist.

kannst du mir mal bitte ein log mit verbose 5 senden von einem 'set lightszene scene hell'? vielleicht bin ich weniger empfindlich aber ich habe nicht den eindruck das ich bei meinen lampen wirklich ein nacheinander sehe.

die hue groups über die bridge zu steuern habe ich noch vor. ich weiss aber noch nicht so genau wie sich das am besten in fhem integrieren lässt.

gruss
  andre

[martinp876]

Hallo Benny, Andre,

Ist ein bisschen off-topic aber vielleicht hilft es:
zum einen könnt ihr prüfen, wann die Kommandos gesendet werden - global mseclog =1 setzen.

zum Anderen habe ich eine Utility gebastelt, die langsame Funktionen finden soll - also Funktionen, die lange brauchen und daher den Ablauf blockieren.
Voraussetzung ist, das fhem aktuell ist.
Das File im Anhang in das FHEM Verzeichniss kopieren und ein "reload apptime" machen.
Es werden nun alle Laufzeiten der "applikationen" aufgezeichnet (nicht der 'Kernel').
mit
apptime
sieht man dann die Funktionen und deren Laufzeit.

apptime   [clear|<field>] [top|all] [<filter>] application function calls and duration

apptime clear
werden alle Zähler gelöscht, auswertung beginnt neu
<field> kann sein :count,funktion,average,clear,max,name,total
und ist die Sortierung der Ausgabe

top sind die Grössten Werte der Sortierung, all sind alle
man kann noch filtern, nach Namen

Für Delays ist in erster Linie "max" verantwortlich - das ist die maximal gemessene Laufzeit einer Funktion. Average eben der Mittelwert.
Total ist die akkumulierte Laufzeit des Moduls.

Alle Zeiten in ms

Gruss Martin

[Benny_82]

Hier der Logfile-Auszug einen Fehler in einem notifiy konnte ich noch finden, den ich wohl gestern abend eingebaut hatte, da der on Status bei den HUE-lampen nicht immer korrekt gesetzt wurde, da musste mal schnell ein workaround her, da ich den fehler nicht sinnvoll reproduzieren konnte.

Die Softwareversionen sind unterschiedlich, da auch unterschiedliche Geräte angesteuert werden
HUE Bulbs (3) : 65003148
LC Bloom (3): 3.0.0.7119
LC Aura (2) + LC Iris (1): 4.6.0.8274

Die beiden Tests ramptime/alert kann ich leider erst am Donnerstag machen, da ich derzeit nicht zuhause bin und nur per VPN zugreifen kann.

2013.12.02 15:58:25.167 5: Cmd: >set lampen_wohnzimmer scene hell<
2013.12.02 15:58:25.186 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/1/state: Got data, length: 132
2013.12.02 15:58:25.211 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/1: Got data, length: 340
2013.12.02 15:58:25.235 5: Triggering HUEDevice1 (1 changes)
2013.12.02 15:58:25.247 5: Notify loop for HUEDevice1 RGB: ffd05c
2013.12.02 15:58:25.336 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/12/state: Got data, length: 135
2013.12.02 15:58:25.363 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/12: Got data, length: 367
2013.12.02 15:58:25.388 5: Triggering HUEDevice12 (1 changes)
2013.12.02 15:58:25.400 5: Notify loop for HUEDevice12 RGB: ffd56e
2013.12.02 15:58:25.486 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/2/state: Got data, length: 132
2013.12.02 15:58:25.511 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/2: Got data, length: 347
2013.12.02 15:58:25.535 5: Triggering HUEDevice2 (1 changes)
2013.12.02 15:58:25.547 5: Notify loop for HUEDevice2 RGB: ffd05c
2013.12.02 15:58:25.633 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/3/state: Got data, length: 132
2013.12.02 15:58:25.658 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/3: Got data, length: 349
2013.12.02 15:58:25.682 5: Triggering HUEDevice3 (1 changes)
2013.12.02 15:58:25.694 5: Notify loop for HUEDevice3 RGB: ffd05c
2013.12.02 15:58:25.781 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/4/state: Got data, length: 132
2013.12.02 15:58:25.806 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/4: Got data, length: 349
2013.12.02 15:58:25.830 5: Triggering HUEDevice4 (1 changes)
2013.12.02 15:58:25.842 5: Notify loop for HUEDevice4 RGB: ffd05c
2013.12.02 15:58:25.928 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/6/state: Got data, length: 132
2013.12.02 15:58:25.953 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/6: Got data, length: 348
2013.12.02 15:58:25.977 5: Triggering HUEDevice6 (1 changes)
2013.12.02 15:58:25.989 5: Notify loop for HUEDevice6 RGB: ffd05c
2013.12.02 15:58:26.076 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/7/state: Got data, length: 132
2013.12.02 15:58:26.101 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/7: Got data, length: 347
2013.12.02 15:58:26.126 5: Triggering HUEDevice7 (1 changes)
2013.12.02 15:58:26.137 5: Notify loop for HUEDevice7 RGB: ffd05c
2013.12.02 15:58:26.226 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/8/state: Got data, length: 132
2013.12.02 15:58:26.253 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/8: Got data, length: 369
2013.12.02 15:58:26.277 5: Triggering HUEDevice8 (1 changes)
2013.12.02 15:58:26.289 5: Notify loop for HUEDevice8 xy: 0.4124,0.4011
2013.12.02 15:58:26.359 5: Triggering HUEDevice8 (1 changes)
2013.12.02 15:58:26.370 5: Notify loop for HUEDevice8 RGB: ffe06f
2013.12.02 15:58:26.460 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/9/state: Got data, length: 132
2013.12.02 15:58:26.486 5: HUEBridge_HTTP_Request http://192.168.3.105/api/5acc62c005d2cfe2e1c14d937340c845/lights/9: Got data, length: 363
2013.12.02 15:58:26.510 5: Triggering HUEDevice9 (1 changes)
2013.12.02 15:58:26.521 5: Notify loop for HUEDevice9 xy: 0.2524,0.1877
2013.12.02 15:58:26.591 5: Triggering HUEDevice9 (1 changes)
2013.12.02 15:58:26.602 5: Notify loop for HUEDevice9 RGB: 564bfb
2013.12.02 15:58:26.671 5: Triggering lampen_wohnzimmer (1 changes)
2013.12.02 15:58:26.683 5: Notify loop for lampen_wohnzimmer scene hell

EDIT: Zeitversatz sind also ca. 1,5 Sekunden was zwar einen lustigen Effekt bei lichtwechseln hat (neue Farbe "schwimmt" langsam von rechts nach links durch die Wohnung), aber für ein "aufblinken" drei mal eine Sekunde, immernoch zu viel ist.

[martinp876]

25.247 Notify loop for HUEDevice1 RGB: ffd05c
25.400 Notify loop for HUEDevice12 RGB: ffd56e
25.547 Notify loop for HUEDevice2 RGB: ffd05c
25.694 Notify loop for HUEDevice3 RGB: ffd05c
25.842 Notify loop for HUEDevice4 RGB: ffd05c
25.989 Notify loop for HUEDevice6 RGB: ffd05c
26.137 Notify loop for HUEDevice7 RGB: ffd05c
26.289 Notify loop for HUEDevice8 xy: 0.4124,0.4011
26.370 Notify loop for HUEDevice8 RGB: ffe06f
26.521 Notify loop for HUEDevice9 xy: 0.2524,0.1877
26.602 Notify loop for HUEDevice9 RGB: 564bfb

zu sehen ist, dass jedes schalten 150ms braucht. Insgesamt ist es nach 1,4sec erledigt. Ist dies dein Problem oder ist das Device noch einmal langsamer?
Ansonsten muss  bei Scene oder HUE gesucht werden, was man beschleunigen kann.
Was du nicht aufgezeichnet hast ist die message vom Schalter. Somit kann man nicht sehen, wie "langsam" dies ist.

Gruss Martin