Wifilight.pm

[daniel2311]

Hallo Jörg,
vllt erinnerst du dich noch daran, dass ich mal gepostet habe, dass ich Probleme habe die LD382a anzusprechen und es häufig zu Verbindungsproblemen kommt.
Nachdem wir ja uns angeschaut haben, was im Hintergrund passiert, bin zumindest ich immer noch nicht schlauer, was das Problem ist. Aber es ist wirklich nervig, dass sie so häufig in der Praxis leider nicht schalten.

Könnte bzw. wäre es nicht eine Idee, dass man via Attribut definieren kann, dass man entweder immer eine neue TCP-Session öffnet oder die TCP-Session nach einem x Sekunden erneut öffnet? Ich habe jetzt einfach eingebaut, dass immer eine neue Verbindung geöffnet wird und die Probleme scheinen nahezu verschwunden, auch wenn ich verstehe, dass man lieber das zugrunde liegende Problem lösen wollen würde.

LG
Daniel

[herrmannj]

Moin Daniel,

das ist keine allgemeine Lösung.

Der Verbindungsaufbau kostet sehr viel. Vergleiche das mit einem Telefonat. Vor jedem Wort was Du sagst musst Du wählen, das Freizeichen abwarten und dann sagt jemand "Hallo". Für die transitions ist das ein No-go.

Vorschlag: schau doch mal das Du etwas separates ausarbeitest, grob skizziert so:
XXX Sekunden nachdem der letzte Befehl rausgeht (watchdog?): "undef $defs{LED'}{helper}{SOCKET}" wobei LED der Name des ld382 device ist.

Wer von dem Problem betroffen ist kann das dann 'add-on' installieren, evtl mit Hilfe im Wiki.

Das müsste imho das Problem lösen;
"undef $defs{LED'}{helper}{SOCKET}" sorgt dafür das der nächste "send" die Verbindung neu aufbaut.

Noch genauer wäre dies (passt ja auch in einen watchdog):
{
  $defs{LED'}{helper}{SOCKET}->shutdown(2);
  $defs{LED'}{helper}{SOCKET}->close();
  undef $defs{LED'}{helper}{SOCKET};
}

Alle bei denen das nicht auftritt haben dann kein penalty durch den connect.

beim watchdog müsste man RGB nehmen können (?).

vg
joerg

[daniel2311]

Aloha Jörg,

hmm, wie meinst du denn, dass das keine allgemeine Lösung ist?
Wenn du das Reconnect nur ausführen würdest, wenn ein bestimmtest Attribut gesetzt würde, dann wäre das doch Allgemein und würde auch kein Nachteil für die transitions bringen.

Letztlich wäre meine Idee doch genau das, was du jetzt beim Watchdog vorschlägst - wobei das natürlich auch mein Problem genauso löst - hoffe ich zumindest Also vielen Dank!

Meine LED heißt "LED_Wohnzimmer_Durchreiche. Wenn der RGB-Wert sich für 60 Sekunden nicht ändert, wird der Socket geschlossen und anschließend entfernt. Wichtig ist wohl das Attribut autoRestart zu setzen.

define LED_Wohnzimmer_Durchreiche_watchdog watchdog LED_Wohnzimmer_Durchreiche:RGB.* 00:00:60 LED_Wohnzimmer_Durchreiche:RGB.* {   $defs{'LED_Wohnzimmer_Durchreiche'}{helper}{SOCKET}->shutdown(2);;   $defs{'LED_Wohnzimmer_Durchreiche'}{helper}{SOCKET}->close();;   undef $defs{'LED_Wohnzimmer_Durchreiche'}{helper}{SOCKET};; }
attr LED_Wohnzimmer_Durchreiche_watchdog autoRestart 1

Ich berichte mal die Tage, ob das zumindest bei mir etwas hilft. Bin mir auch noch nicht sicher, ob das ein Windows-Problem ist. Aber wir werden sehen...

[herrmannj]

sieht jut aus.

Aus reinem Interesse (windows hat vmtl nix mit dem problem zu tun. Das ist der controller):

welches windows ? Native (active perl oder stawberry) oder der neue Linux Unterbau ?

[daniel2311]

ja kann auch sein - das China Zeug halt manchmal Wobei es mit der App, wenn ich sie dann mal benutze, tatsächlich immer klappt.

Es ist ein Windows Home Server 2011 mit Active Perl.

Was ist denn der neue Linux Unterbau?

[herrmannj]

https://docs.microsoft.com/en-us/windows/wsl/install-win10

[daniel2311]

Übrigens bisher arbeiten die Wachhunde tadellos ^^
Bisher keine Schwierigkeiten mehr gehabt.

[DanielGab]

Das heißt, den LD382A angeschlossen an eine schaltbare Steckdose führt nicht dazu, dass es diese ewige Verzögerung nach dem wieder einschalten gibt? Das wäre ja toll

[DecaTec]

Hi,

ich habe in den letzten Tagen auch ein paar LED-Stripes im Haus installiert. Verwende hierzu einen "alten" LW12 und einige neuere LD382A.
Zunächst hat das alles problemlos geklappt, bei längerer "Laufzeit" tritt jedoch das von daniel2311 beschriebene Problem auf: Die LED-Controller sind irgendwie nicht mehr zu erreichen ("low level cmd queue send ERROR xxxxx, qlen 2 (reconnect giving up)").

Netzwerk-Probleme würde ich hier erst einmal ausschließen, da alle Controller eine gute WLAN-Verbindung haben und z.T. direkt neben dem Router angebracht sind.

Der Tipp mit dem Watchdog, der die TCP-Verbindung resettet, hat ein wenig geholfen, d.h. das Problem tritt nun gefühlt weniger oft auf. Ganz verschwunden ist es jedoch leider nicht. Der Watchdog sieht dabei folgendermaßen aus:

Code Auswählen Erweitern

define WatchdogLedDecke watchdog LedDecke:RGB.* 00:00:60 LedDecke:RGB.* { $defs{'LedDecke'}{helper}{SOCKET}->shutdown(2);; $defs{'LedDecke'}{helper}{SOCKET}->close();; undef $defs{'LedDecke'}{helper}{SOCKET};; }
attr WatchdogLedDecke autoRestart 1

Hat vielleicht jemand noch einen Tipp? Ist ein bisschen blöd, wenn die LED immer erst beim zweiten Mal schalten wirklich an gehen, besonders mit Alexa...

Hier noch das komplette Log mit verbose 5:

Code Auswählen Erweitern

2018.01.19 17:15:08 4: LedDecke high level cmd queue clear
2018.01.19 17:15:08 5: LedDecke low level cmd queue add 71230fa3, qlen 1
2018.01.19 17:15:08 5: LedDecke low level cmd queue qlen 1, send 71230fa3
2018.01.19 17:15:08 4: LedDecke low level cmd queue send 71230fa3, qlen 1 connection refused: trying to reconnect
2018.01.19 17:15:09 3: LedDecke low level cmd queue send ERROR 71230fa3, qlen 1 (reconnect giving up)
2018.01.19 17:15:09 3: LedDecke RGB LD382A set on (39, 100, 100) 1
2018.01.19 17:15:09 5: LedDecke prepare start hsv transition (is actual) hsv 174, 100, 0, 1516378509.99159
2018.01.19 17:15:09 4: LedDecke current HSV 174, 100, 0
2018.01.19 17:15:09 3: LedDecke set HSV 39, 100, 100 with ramp: 1, flags:
2018.01.19 17:15:09 4: LedDecke color rotation dev cc:135, cw:225, shortest:-1
2018.01.19 17:15:09 4: LedDecke transit (H>S||V) steps: 10 stepwide: 100
2018.01.19 17:15:09 4: LedDecke add to hl queue h:160.5, s:100, v:10 (1/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 161, 100, 10, ctrl , targetTime 1516378509.99159, qlen 1
2018.01.19 17:15:09 5: LedDecke high level cmd queue exec dropper delay: -0.000359058380126953
2018.01.19 17:15:09 4: LedDecke high level cmd queue exec hsv 161, 100, 10, delay 100, hl qlen 1, ll qlen 1, lock 0
2018.01.19 17:15:09 4: LedDecke RGB LD382A set h:161, s:100, v:10
2018.01.19 17:15:09 5: LedDecke low level cmd queue add 3100070200000f49, qlen 2
2018.01.19 17:15:09 5: LedDecke low level cmd queue add 00, qlen 3
2018.01.19 17:15:09 4: LedDecke high level cmd queue ask next 1516378510.09416
2018.01.19 17:15:09 4: LedDecke add to hl queue h:147, s:100, v:20 (2/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 147, 100, 20, ctrl , targetTime 1516378510.09158, qlen 2
2018.01.19 17:15:09 4: LedDecke add to hl queue h:133.5, s:100, v:30 (3/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 134, 100, 30, ctrl , targetTime 1516378510.19159, qlen 3
2018.01.19 17:15:09 4: LedDecke add to hl queue h:120, s:100, v:40 (4/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 120, 100, 40, ctrl , targetTime 1516378510.29158, qlen 4
2018.01.19 17:15:09 4: LedDecke add to hl queue h:106.5, s:100, v:50 (5/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 107, 100, 50, ctrl , targetTime 1516378510.39159, qlen 5
2018.01.19 17:15:09 4: LedDecke add to hl queue h:93, s:100, v:60 (6/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 93, 100, 60, ctrl , targetTime 1516378510.49159, qlen 6
2018.01.19 17:15:09 4: LedDecke add to hl queue h:79.5, s:100, v:70 (7/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 80, 100, 70, ctrl , targetTime 1516378510.59158, qlen 7
2018.01.19 17:15:09 4: LedDecke add to hl queue h:66, s:100, v:80 (8/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 66, 100, 80, ctrl , targetTime 1516378510.69159, qlen 8
2018.01.19 17:15:09 4: LedDecke add to hl queue h:52.5, s:100, v:90 (9/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 53, 100, 90, ctrl , targetTime 1516378510.79158, qlen 9
2018.01.19 17:15:09 4: LedDecke add to hl queue h:39, s:100, v:100 (10/10)
2018.01.19 17:15:09 4: LedDecke high level cmd queue add hsv/ctrl 39, 100, 100, ctrl , targetTime 1516378510.89159, qlen 10
2018.01.19 17:15:10 5: LedDecke low level cmd queue qlen 2, send 3100070200000f49
2018.01.19 17:15:10 4: LedDecke low level cmd queue send 3100070200000f49, qlen 2 connection refused: trying to reconnect
2018.01.19 17:15:11 3: LedDecke low level cmd queue send ERROR 3100070200000f49, qlen 2 (reconnect giving up)
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 8
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 7
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 6
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 5
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 4
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 3
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 2
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec drop frame at hlQueue level. hl qlen: 1
2018.01.19 17:15:11 5: LedDecke high level cmd queue exec dropper delay: -0.15264892578125
2018.01.19 17:15:11 4: LedDecke high level cmd queue exec hsv 39, 100, 100, delay 100, hl qlen 1, ll qlen 2, lock 1
2018.01.19 17:15:11 4: LedDecke RGB LD382A set h:39, s:100, v:100
2018.01.19 17:15:11 5: LedDecke low level cmd queue add 31ff6f0000000fae, qlen 3
2018.01.19 17:15:11 5: LedDecke low level cmd queue add 00, qlen 4
2018.01.19 17:15:11 4: LedDecke high level cmd queue ask next 1516378511.14649
2018.01.19 17:15:11 5: LedDecke | LedDecke unlock queue 1
2018.01.19 17:15:11 5: LedDecke low level cmd queue qlen 2, send 31ff6f0000000fae
2018.01.19 17:15:11 4: LedDecke low level cmd queue send 31ff6f0000000fae, qlen 2 connection refused: trying to reconnect
2018.01.19 17:15:12 3: LedDecke low level cmd queue send ERROR 31ff6f0000000fae, qlen 2 (reconnect giving up)
2018.01.19 17:15:12 5: LedDecke | LedDecke unlock queue 0

[DecaTec]

So, das Thema hat mir irgendwie keine Ruhe gelassen, daher habe ich noch ein wenig herumprobiert:
Folgende Zeile dürfte der eigentliche Grund dafür sein, dass immer erst beim zweiten Mal geschaltet wird: "low level cmd queue send ERROR xxxx, qlen 2 (reconnect giving up)".

Wenn man sich den Sourcecode des Moduls ansieht, dann wird diese Log-Zeile nur an einer Stelle geschrieben: In der Methode WifiLight_LowLevelCmdQueue_Send (Zeile 3944). Und zwar dann, wenn der Aufruf des Konstruktors für den Socket fehlschlägt. Im ctor wird ein Timeout von 1 Sek. angegeben. Ich habe bei mir lokal mal den Timeout auf 5 Sek. erhöht und siehe da: Es wird gleich beim ersten Mal geschaltet. Zwar mit einer Verzögerung von mehreren Sekunden, aber immerhin.

Der Code sieht nun folgendermaßen aus:

Code Auswählen Erweitern

$ledDevice->{helper}->{SOCKET} = IO::Socket::INET-> new (
PeerPort => $ledDevice->{PORT},
PeerAddr => $ledDevice->{IP},
Timeout => 5,
Blocking => 0,
Proto => 'tcp') or Log3 ($ledDevice, 3, "$ledDevice->{NAME} low level cmd queue send ERROR $dbgStr, qlen ".@{$ledDevice->{helper}->{llCmdQueue}}." (reconnect giving up)");

Ich stecke nicht sonderlich tief in der Materie drin, aber meine Vermutung wäre, dass die Connection zum LED-Controller irgendwann abbricht (wie ja schon daniel2311 herausgefunden hat). Der Neuaufbau funktioniert irgendwie auch nicht, da die Verbindung nicht innerhalb von 1 Sek. zustande kommt. Kann es sein, dass sich diese Controller nach einer gewissen Zeit "schlafen legen" um Energie zu sparen?

Nach Erhöhung des Timeout-Wertes scheint es bei mit nun besser zu funktionieren. Dass das nicht die beste Lösung ist, ist mir auch klar - aber besser die LEDs werden überhaupt geschaltet (wenn auch manchmal langsamer). Aber wie gesagt, da stecke ich nicht drin...

[herrmannj]

der connect ist blockierend - FHEM steht dann für 5 Sekunden. Das solltet Du wissen bevor du das für Dich adaptierst ...

[DecaTec]

OK, guter Hinweis. Sorry, bin echt nicht fit in Perl...

Ich versuch mal was anderes.

[Amenophis86]

Kann man den connect nicht in nonBlockingCall auslagern?

[herrmannj]

ja, ist aber nicht so trivial. Ich plane Erweiterungen auf Basis einer lib die ich entwickle um, dann mit multitasking etc. Die kann das schon. Aber da muss zuerst die lib fertig fertig sein sonst ist das doppelter Aufwand.

Das mit dem connect ist auch nur ein Teilaspekt. Den disconnect (vorher) kann man auch besser abwickeln ...

[DecaTec]

Hi,

habe wieder mal etwas rumprobiert:
Wenn die Instanz nicht erzeigt werden kann, dann wird es einfach mehrfach versucht (bis zu 10x). Code-technisch schaut es dann so aus:

Code Auswählen Erweitern

Log3 ($ledDevice, 4, "$ledDevice->{NAME} low level cmd queue send $dbgStr, qlen ".@{$ledDevice->{helper}->{llCmdQueue}}." connection refused: trying to reconnect");

  if ($ledDevice->{helper}->{SOCKET}) {
$ledDevice->{helper}->{SOCKET}->shutdown(2);
$ledDevice->{helper}->{SOCKET}->close();
  }
 
  # Try for 10 times to instantiate the socket if it isn't there.
  foreach my $i (0..9) {
$ledDevice->{helper}->{SOCKET} = IO::Socket::INET-> new (
PeerPort => $ledDevice->{PORT},
PeerAddr => $ledDevice->{IP},
Timeout => 1,
Blocking => 0,
Proto => 'tcp') or Log3 ($ledDevice, 3, "$ledDevice->{NAME} cannot instantiate the socket, retry...");

if ($ledDevice->{helper}->{SOCKET}) {
last;
}
  }
 
  # Was not able to instantiate socket, giving up
  if (!$ledDevice->{helper}->{SOCKET}) {
Log3 ($ledDevice, 3, "$ledDevice->{NAME} low level cmd queue send ERROR $dbgStr, qlen ".@{$ledDevice->{helper}->{llCmdQueue}}." (reconnect giving up)");
  }
 
  $ledDevice->{helper}->{SELECT} = IO::Select->new($ledDevice->{helper}->{SOCKET}) if $ledDevice->{helper}->{SOCKET};

Ich weiß, das ist immer noch mehr oder weniger eine Holzhammer-Methode, aber ich hatte seitdem nie mehr die Situation, dass die LED-Controller nicht geschaltet hätten. Nachteil: Es dauert u.U. etwas länger, bis das Licht angeht. In meinem speziellen Fall ist das zwar etwas störend, aber ich denke, dass ich zunächst einmal damit leben kann.
Vielleicht ist das ja für den einen oder anderen nützlich, der ähnliche Probleme mit den LED-UFOs hat...

@herrmannj: Freue mich schon auf deine Erweiterungen. Wenn du jemanden zum testen brauchst, dann sag bescheid. Weil meine Lösung ist ja auch nur ein temporärer Workaround.