YAMAHA_AVR Verzögerungen

vbs · 05 November 2015, 13:36:33

Hi Markus,

ich bin mal dem Phänomen auf den Grund gegangen, warum FHEM bei mir manchmal für mehrer Sekunden blockiert wird und es scheint bei mir an dem Modul YAMAHA_AVR zu liegen. Und zwar passiert es, wenn ich mit "set volume" die Laustärke ändere. Durch "volume-smooth-change" wird ja die neue Lautstärke ja nicht hart gesetzt, sondern langsam "reingefadet", was dann einen Moment dauert.
Das sieht dann bei mir Log zB so aus:

Code Auswählen

2015.11.05 13:29:10.107 5: YAMAHA_AVR (wz_avr) - set wz_avr volume
2015.11.05 13:29:10.107 4: YAMAHA_AVR (wz_avr) - new target volume: -80.5
2015.11.05 13:29:10.107 4: YAMAHA_AVR (wz_avr) - use smooth volume change (with 5 steps of -5.5 volume change to reach -80.5)
2015.11.05 13:29:10.108 4: YAMAHA_AVR (wz_avr) - set volume to -56.5 dB (target is -80.5 dB)
2015.11.05 13:29:10.108 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -56.5" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-565</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.303 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -56.5"
2015.11.05 13:29:10.304 5: YAMAHA_AVR (wz_avr) - got response for "volume -56.5": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.304 4: YAMAHA_AVR (wz_avr) - set volume to -62 dB (target is -80.5 dB)
2015.11.05 13:29:10.304 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -62" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-620</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.505 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -62"
2015.11.05 13:29:10.506 5: YAMAHA_AVR (wz_avr) - got response for "volume -62": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.506 4: YAMAHA_AVR (wz_avr) - set volume to -67.5 dB (target is -80.5 dB)
2015.11.05 13:29:10.507 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -67.5" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-675</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.807 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -67.5"
2015.11.05 13:29:10.808 5: YAMAHA_AVR (wz_avr) - got response for "volume -67.5": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:10.809 4: YAMAHA_AVR (wz_avr) - set volume to -73 dB (target is -80.5 dB)
2015.11.05 13:29:10.809 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -73" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-730</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.107 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -73"
2015.11.05 13:29:11.108 5: YAMAHA_AVR (wz_avr) - got response for "volume -73": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.108 4: YAMAHA_AVR (wz_avr) - set volume to -78.5 dB (target is -80.5 dB)
2015.11.05 13:29:11.108 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -78.5" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-785</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.309 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -78.5"
2015.11.05 13:29:11.310 5: YAMAHA_AVR (wz_avr) - got response for "volume -78.5": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.310 4: YAMAHA_AVR (wz_avr) - set volume to -80.5 dB (target is -80.5 dB)
2015.11.05 13:29:11.310 5: YAMAHA_AVR (wz_avr) - execute blocking "volume -80.5" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Volume><Lvl><Val>-805</Val><Exp>1</Exp><Unit>dB</Unit></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.510 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "volume -80.5"
2015.11.05 13:29:11.511 5: YAMAHA_AVR (wz_avr) - got response for "volume -80.5": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Volume><Lvl></Lvl></Volume></Main_Zone></YAMAHA_AV>
2015.11.05 13:29:11.511 3: onWzAvrInput: Volume set
2015.11.05 13:29:11.512 3: onWzAvrInput: Leaving...
2015.11.05 13:29:11.514 5: YAMAHA_AVR (wz_avr) - set wz_avr ?
2015.11.05 13:29:11.518 1: Perfmon: possible freeze starting at 13:29:09, delay is 2.518

Das smooth-change finde ich eigentlich sehr schick und würde es gerne beibehalten (wenn möglich). Es scheint nun jedoch so zu sein, dass die HTTP-Befehle an den Yamaha sequentiell blockierend durchgeführt werden und dann eben die set-Funktion erst fertig wird, wenn alle Volume-Befehle durch sind.
Ist das das erwartete Verhalten oder gibt es irgendeine Chance, dem Modul zu sagen, dass er das setVolume nicht-blockierend machen soll?

Vielen Dank!

Markus Bloch · 05 November 2015, 14:43:03

Das ist das gewollte Vorgehen. Wenn der Receiver "present" ist, werden alle Anfragen "blocking" durchgeführt, wenn der Receiver "absent" ist, werden alle Anfragen "non-blocking" durchgeführt.

Hintergrund:

Viele User machen wilde Kommandoverkettungen um den Receiver vom ausgeschalteten Zustand in den gewünschten Zustand zu bekommen. Wenn diese Kommandos alle non-blocking sofort abgesetzt werden, ist das zu schnell und der Receiver bearbeitet diese nicht.

Mein Plan ist es, das Modul grundlegend umzustellen auf eine einzige konstante HTTP Verbindung mit einer Kommando-Queue die dann asynchron abgearbeitet wird. Sobald eine Antwort für den letzten Request vorliegt, wird das nächste Kommando aus der Queue gesendet. Alles non-blocking und mit keep-alive Mechanismus, so dass man nicht dauernd eine TCP Verbindung aufbauen muss.

Bis ich dazu Zeit finde, wird es aber wohl wieder etwas dauern.

Viele Grüße

Markus

Markus Bloch · 05 November 2015, 14:44:21

Alternativ kannst du versuchen die volume steps für das smooting auf z.B. 3 runter zu setzen.

vbs · 05 November 2015, 14:46:16

Ok, danke für die schnelle Info! Werde ich mal ausprobieren!

vbs · 07 November 2015, 17:08:42

Hi Markus,

sorry, ich nochmal: Ich hatte jetzt noch einen anderen Fall bei dem eine ziemliche Verzögerung aufgetreten ist (ohne Lautstärkeänderungen). Das sah im Log so aus:

Code Auswählen


2015.11.07 01:36:39.237 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "statusRequest toneStatus"
2015.11.07 01:36:39.237 5: YAMAHA_AVR (wz_avr) - got response for "statusRequest toneStatus": <YAMAHA_AV rsp="GET" RC="0"><Main_Zone><Sound_Video><Tone><Bass><Val>60</Val><Exp>1</Exp><Unit>dB</Unit></Bass></Tone></Sound_Video></Main_Zone></YAMAHA_AV>
2015.11.07 01:36:39.238 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "statusRequest toneStatus"
2015.11.07 01:36:39.238 5: YAMAHA_AVR (wz_avr) - got response for "statusRequest toneStatus": <YAMAHA_AV rsp="GET" RC="0"><Main_Zone><Sound_Video><Tone><Treble><Val>0</Val><Exp>1</Exp><Unit>dB</Unit></Treble></Tone></Sound_Video></Main_Zone></YAMAHA_AV>
2015.11.07 01:36:39.417 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "statusRequest fwUpdate"
2015.11.07 01:36:39.417 5: YAMAHA_AVR (wz_avr) - got response for "statusRequest fwUpdate": <YAMAHA_AV rsp="GET" RC="0"><System><Misc><Network><Update><Status>Available</Status></Update></Network></Misc></System></YAMAHA_AV>
2015.11.07 01:37:09.005 3: Turning off Samsung TV: wz_tv
2015.11.07 01:37:10.013 3: set wz_tv:FILTER=STATE=opened POWEROFF : 1
2015.11.07 01:37:10.016 5: YAMAHA_AVR (wz_avr) - execute nonblocking "statusRequest basicStatus" on wz_avr: <YAMAHA_AV cmd="GET"><Main_Zone><Basic_Status>GetParam</Basic_Status></Main_Zone></YAMAHA_AV>
2015.11.07 01:37:10.018 5: YAMAHA_AVR (wz_avr) - execute nonblocking "statusRequest fwUpdate" on wz_avr: <YAMAHA_AV cmd="GET"><System><Misc><Update><YAMAHA_Network_Site><Status>GetParam</Status></YAMAHA_Network_Site></Update></Misc></System></YAMAHA_AV>
2015.11.07 01:37:10.019 5: YAMAHA_AVR (wz_avr) - execute nonblocking "statusRequest toneStatus" on wz_avr: <YAMAHA_AV cmd="GET"><Main_Zone><Sound_Video><Tone><Bass>GetParam</Bass></Tone></Sound_Video></Main_Zone></YAMAHA_AV>
2015.11.07 01:37:10.021 5: YAMAHA_AVR (wz_avr) - execute nonblocking "statusRequest toneStatus" on wz_avr: <YAMAHA_AV cmd="GET"><Main_Zone><Sound_Video><Tone><Treble>GetParam</Treble></Tone></Sound_Video></Main_Zone></YAMAHA_AV>
2015.11.07 01:37:10.023 5: YAMAHA_AVR (wz_avr) - execute nonblocking "statusRequest fwUpdate" on wz_avr: <YAMAHA_AV cmd="GET"><System><Misc><Network><Update><Status>GetParam</Status></Update></Network></Misc></System></YAMAHA_AV>
2015.11.07 01:37:10.035 5: YAMAHA_AVR (wz_avr) - received HTTP code 400 for command "statusRequest fwUpdate"
2015.11.07 01:37:10.044 1: tv.fritz.box:55000 disconnected, waiting to reappear (wz_tv)
2015.11.07 01:37:10.051 3: onSamsungTvChange: wz_tv - DISCONNECTED
2015.11.07 01:37:10.052 3: Samsung TV turned off
2015.11.07 01:37:10.052 3: Setting AVR wz_avr scene to 3
2015.11.07 01:37:10.053 5: YAMAHA_AVR (wz_avr) - set wz_avr scene scene3
2015.11.07 01:37:10.053 5: YAMAHA_AVR (wz_avr) - execute blocking "scene scene3" on wz_avr: <YAMAHA_AV cmd="PUT"><Main_Zone><Scene><Scene_Sel>Scene 3</Scene_Sel></Scene></Main_Zone></YAMAHA_AV>
2015.11.07 01:37:13.348 5: YAMAHA_AVR (wz_avr) - received HTTP code 200 for command "scene scene3"
2015.11.07 01:37:13.348 5: YAMAHA_AVR (wz_avr) - got response for "scene scene3": <YAMAHA_AV rsp="PUT" RC="0"><Main_Zone><Scene><Scene_Sel></Scene_Sel></Scene></Main_Zone></YAMAHA_AV>
2015.11.07 01:37:13.349 3: Setting DM7020HD wz_dm7020hd to off
2015.11.07 01:37:13.351 3: ENIGMA2 set wz_dm7020hd off
2015.11.07 01:37:13.358 1: Perfmon: possible freeze starting at 01:37:11, delay is 2.358

Da scheint fhem ein "set wz_avr scene scene3" zu machen, welches erst nach über 3 Sekunden beantwortet wird. Ich vermute, dass das damit zusammen hängt, dass das "set scene" wenige Millisekunden abgesetzt wird, nachdem das AVR-Modul intern die statusRequests abgesetzt hat, was wohl alle 30 Sekunden passiert.

Da gilt wahrscheinlich auch deine vorherige Antwort, dass das momentan das erwartete Verhalten ist und erst durch den Umbau besser werden würde, richtig?

Markus Bloch · 07 November 2015, 17:25:18

Hi,

das "set wz_avr scene scene3" wird nicht durch YAMAHA_AVR selber getriggert, sondern durch etwas anderes in deiner FHEM-Installation. Die Verzögerung kommt hier durch die lange Antwortzeit die der Receiver sich gönnt.

Das Problem lässt sich wie gesagt nur durch eine grundlegende Änderung des Moduls lösen wie bereits beschrieben.

Viele Grüße

Markus

vbs · 07 November 2015, 17:27:54

Zitat von: Markus Bloch am 07 November 2015, 17:25:18
das "set wz_avr scene scene3" wird nicht durch YAMAHA_AVR selber getriggert, sondern durch etwas anderes in deiner FHEM-Installation. Die Verzögerung kommt hier durch die lange Antwortzeit die der Receiver sich gönnt.

Ja genau, sorry hab ich blöd beschrieben: Mein TV geht aus und durch ein notify wird dann "set wz_avr scene scene3" ausgelöst.

Ok danke, dann weiß ich Bescheid.

vbs · 09 November 2015, 18:58:58

Hallo Markus,

sorry, mein letzer Input zu dem Thema, versprochen

Was hältst du davon, wenn der Benutzer über ein async-Attribut steuern könnte, ob Anfragen auch asynchron geschickt werden sollen, wenn der Receiver eingeschaltet ist? Bei mir ists eben so, dass schon ein einzelner Ausschalt-Befehl gerne mal FHEM für 3 Sekunden blockiert. Ich fänds super wenn ich den asynchron schicken könnte. Dann könnte der User sich zumindest aussuchen, in welchen sauren Apfel er beißen möchte.

Markus Bloch · 29 November 2015, 13:00:19

Ich habe gestern bereits das YAMAHA_BD Modul auf das genannte Queueing-Verfahren umgestellt und es dann 1:1 auf YAMAHA_AVR angewandt. Anbei mal meine aktuelle Version von YAMAHA_AVR die dieses Verfahren bereits enthält.

Probier mal bitte, wie sich das bei dir verhält.

Vielen Dank

Gruß
Markus

dev0 · 06 Dezember 2015, 10:33:23

Ich vermute mal, dass diese Änderung auch heute per update kamen.

Code Auswählen


YAMAHA_AVR: added HTTP request queue, send only one request at the same time.
This increases command reliability and response behaviour of the AV receiver.

Heißt das auch, dass man auf die Verzögerung mit sleep zwischen einzelnen Befehlen verzichten könnte? request queue hört sich ja danach an.

/Uli

Markus Bloch · 06 Dezember 2015, 11:27:19

Ja zum Teil durchaus. Zum Beispiel funktionieren damit folgende Konstrukte:

Code Auswählen

set AV_Receiver on;set AV_Receiver input av2;set AV_Receiver volume 22

Dies bedingt aber, dass ich noch die Fehlermeldung herausnehmen muss von wegen "input can only be used, when device is powered on" (hab ich bei mir in meiner lokalen Entwicklungsvariante bereits durchgeführt, läuft astrein). Bei mir funktionieren dieses Konstrukt zum Beispiel problemlos, was natürlich einem schnelleren Einschaltverhalten zugute kommt.

Bei den Menüs (Net Radio, Server, USB, ...) sieht das ganze etwas anders aus. Hier habe ich aber gestern aufbauend auf den Änderungen mit der Warteschlange einen generellen Mechanismus gebaut, der sicher und ohne sleeps intern durch ein Menü hangelt. Das ganze habe ich erstmal zum testen hier vorgestellt: http://forum.fhem.de/index.php/topic,19896.msg370073.html#new

Hier würde ich mich freuen, wenn das ein paar Leute testen können, da damit diese ganzen remoteControl/sleep-Konstrukte komplett wegfallen würden und nebenbei auch noch deutlich zuverlässiger und einfacher laufen.

Viele Grüße

Markus

dev0 · 06 Dezember 2015, 12:13:14

Hört sich toll an - werde ich testen. Menus benutze ich nicht, aber recht viele zone-ein-aus-laut-leise-input-schaltum Konstrukte.

Nur um sicher zu sein nicht die falsche Version zu testen - die hier hat die "input can only be used" nicht mehr drin:
http://forum.fhem.de/index.php/topic,19896.msg370073.html#new
Richtig?

Code Auswählen


Thread: # $Id: 71_YAMAHA_AVR.pm 9509 2015-10-18 09:49:01Z markusbloch $
Update: # $Id: 71_YAMAHA_AVR.pm 10100 2015-12-05 15:45:00Z markusbloch $

Markus Bloch · 06 Dezember 2015, 12:40:32

Nein, leider nicht.

Nimm die angehangene Version. Die hat alle aktuellen Änderungen von mir drin. Also Menü-browsen, sowie die entfernten "only be used when device is powered on"-Sachen.

Viele Grüße

Markus

edit: Die Revision wird erst hochgezählt, wenn ich es im SVN einchecke. Da ich aber die eingecheckte Version von gestern noch nicht auf mein eigenes System geupdatet habe, hat dies noch die alte Revision-Nummer, obwohl ich gerade daran fleißig rumschaube.

Schlimbo · 06 Dezember 2015, 14:21:55

Hi Markus,
ich habe mir mit der Android App "Tasker" eine Universal Fernbedienung zusammengestellt, mit der ich meine Multimedia Anlage über FHEM steuer. Für die Lautstärke Steuerung nutze ich die Kommandos "set AV_Receiver volumeUp" und "set AV_Receiver volumeDown", hier habe ich Taster, die ich oft hintereinander betätige um die Lautstärke zu verändern, mit der neuen Version funktioniert das jetzt aber nicht mehr so dynamisch wie zuvor, da jetzt ja nach jedem Kommando erst auf die Antwort des Receivers gewartet wird. Für die Volume Änderung fände ich es gut, wenn du eine Ausnahme einbauen könntest, damit das schnelle Ändern der Lautstärke wieder funktioniert.

Markus Bloch · 06 Dezember 2015, 14:44:55

Hallo Schlimbo,

das ist richtig. Die volumeUp und volumeDown Funktionen sind da ein wenig speziell, wenn man sie schnell hintereinander verwendet, da hier noch das volume-smoothing mit reinspielt.

In deinem Fall würde ich dir raten, im Tasker kein volume-smoothing zu verwenden, da du ja mehrfach schnell auf die tasten hämmerst

Am besten du verwendest folgende Befehle im Tasker:

Code Auswählen

set AV_Receiver volumeDown 2 direct
set AV_Receiver volumeUp 2 direct

Damit wird die Lautstärke sofort um 2 % geändert ohne smoothing. Wenn du dann mehrmals drauf hämmerst sollte das besser funktionieren als aktuell.

Desweiteren wird nach jeder Lautstärkenänderung die abgeschlossen ist, ein vollständiger statusRequest durchgeführt. Das habe ich in der angehangen Version unterbunden. Bitte prüf mal, ob das damit schneller geht.

Viele Grüße

Markus