Sonos - falsche Lautstärke durch Queue / Restore

[ruhr70]

Ich versuche gerade etwas "Ordnung" in die sayit Ansagen über SONOS reinzubekommen und teste einige Varianten.

Jetzt habe ich eine Version, die die Ansagen in ein Array (als Ansagen-Queue) schreibt, und daraus abarbeitet. Sobald eine Ansage zu Ende ist, wird die nächste Ansage mit setState() geschrieben.

Dabei bin ich über folgendes Verhalten gestolpert:

sonos-0	2015-07-12 19:17:18	info	Play on sonos[RINCON_B8E937E0D77601400]: http://172.16.130.122:8082/state/sayit.3.tts.mp3, Volume: undefined
[sonos]	2015-07-12 19:17:18	info	emitting group-volume
sonos-0	2015-07-12 19:17:18	info	Restore state: volume - 20, mute: false, uri: x-sonos-spotify:spotify%3atrack%3axxxxxxxxxxxxxx?sid=9&flags=32&sn=3
sonos-0	2015-07-12 19:17:17	info	Queue on sonos[RINCON_B8E937E0D77601400]: http://172.16.130.122:8082/state/sayit.3.tts.mp3, Volume: 40

Das sieht für mich so aus, als ob das Timing beim Adapter nicht stimmt:

1.) es wird die neue Ansage mit Volume 40 in die Sonos Queue geschrieben

2.) dann wird die alte Lautstärke aus dem unterbrochenem Lied gesetzt: 20

3.) die Ansage aus der Queue wird mit Lautstärke: undefined abgespielt, was der 20 aus dem Restore entspricht

Wenn ich mehrere Ansagen hintereinander abspiele laufe ich in diese Falle.

Arbeitet der Adapter selbst mit einer Ansagen Queue?

Dann würde ich ein Restore erst durchführen, wenn alle Ansagen aus der Queue abgearbeitet sind.

[ruhr70]

Gut, es hat nichts mit dem Timing zu tun, sondern anscheinend einfach an dem "undefined" bei der Lautstärke bei mehren Aufrufen hitereinander.

Das Log, wenn man einfach nur dreimal setSate in das SayIt Objekt schreibt.

sonos-0	2015-07-14 21:45:10	info	Play on sonos[RINCON_B8E937E0D77601400]: http://172.16.130.122:8082/state/sayit.3.tts.mp3, Volume: undefined
[sonos]	2015-07-14 21:45:10	info	emitting group-volume
sonos-0	2015-07-14 21:45:10	info	Queue on sonos[RINCON_B8E937E0D77601400]: http://172.16.130.122:8082/state/sayit.3.tts.mp3, Volume: 40
sonos-0	2015-07-14 21:45:10	info	try to control id sonos.0.root.172_16_130_146.tts with {"val":"40;http://172.16.130.122:8082/state/sayit.3.tts.mp3","ack":false,"ts":1436903110,"from":"system.adapter.sayit.3","lc":1436888221}
sonos-0	2015-07-14 21:45:09	info	Restore state: volume - 12, mute: false, uri: x-sonos-spotify:spotify%3atrack%3a2Q0xxxxxxxxxx?sid=9&flags=32&sn=3

Der SayIt/Sonos Adapter arbeitet wohl auch mit einer Queue (steht ja auch im Log). Das hätte ich mir sparen können. Wobei ich in meiner Variante keine Echos mehr hatte.

Hier kommen die Aktionen Restore, Queue, Play nun in der richtigen Reihenfolge. Beim Play geht aber die Lautstärke verloren (undefined).

sonos-0 2015-07-14 21:45:10 info Play on sonos[RINCON_B8E937E0D77601400]: http://172.16.130.122:8082/state/sayit.3.tts.mp3, Volume: undefined

Der Effekt tritt auf, wenn man mind. zweimal setState(sayitID, ….) direkt hintereinander aufruft.

[Bluefox]

Danke für deine Untersuchung. Nach hqWidgets werde ich das anschauen.

Oder du kannst selbst probieren

[ruhr70]

einen Blick in den Quellcode des Adapter hatte ich schon geworfen.

Eine Nummer zu hoch

schaue aber auch noch einmal

Gesendet von iPhone mit Tapatalk

[ruhr70]

habe jetzt etwas rumgebastelt, da ich das Thema zu mindestens zum üben mit Webstorm verwenden wollte.

Ich bekomme auf meinem Mac den Sonos-Apadter allerdings nicht aktiv

Auto-Discovery scheitert. Manuel eingetragene IP Adressen greifen nicht (Sayit spielt dann lokal am Browser ab, statt bei der IP des Test-Sonos-Lautsprechers).

[sonos]	2015-07-16 18:14:13	info	notification server listening on port 3500
[sonos]	2015-07-16 18:14:13	error	at process._tickCallback (node.js:355:11)
[sonos]	2015-07-16 18:14:13	error	at dns.js:85:18
[sonos]	2015-07-16 18:14:13	error	at dgram.js:224:28
[sonos]	2015-07-16 18:14:13	error	at exports._errnoException (util.js:746:11)
[sonos]	2015-07-16 18:14:13	error	Error: bind EADDRINUSE
[sonos]	2015-07-16 18:14:13	error	at process._tickCallback (node.js:355:11)
[sonos]	2015-07-16 18:14:13	error	at dns.js:85:18
[sonos]	2015-07-16 18:14:13	error	at dgram.js:224:28
[sonos]	2015-07-16 18:14:13	error	at exports._errnoException (util.js:746:11)
[sonos]	2015-07-16 18:14:13	error	Error: bind EADDRINUSE
[sonos]	2015-07-16 18:14:13	error	at process._tickCallback (node.js:355:11)
[sonos]	2015-07-16 18:14:13	error	at dns.js:85:18
[sonos]	2015-07-16 18:14:13	error	at dgram.js:224:28
[sonos]	2015-07-16 18:14:13	error	at exports._errnoException (util.js:746:11)
[sonos]	2015-07-16 18:14:13	error	Error: bind EADDRINUSE
[sonos]	2015-07-16 18:14:13	info	relevant IPs 172.16.130.113=null, 192.168.184.1=null, 192.168.225.1=null
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from utun1
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from vmnet8
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from vmnet1
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from utun0
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from en3
[sonos]	2015-07-16 18:14:13	info	discovering all IPs from lo0
[sonos]	2015-07-16 18:14:13	info	binding SSDP to port 1901
sonos-0	2015-07-16 18:14:13	info	http sonos server listening on port 8083
sonos-0	2015-07-16 18:14:13	info	starting. Version 0.1.6 in /Users/herwig/iobroker/node_modules/iobroker.sonos

• Webstorm läuft auf dem Mac

• die ioBroker Testumgebung für Webstorm läuft auf dem Mac

• ioBroker produktiv läuft unter Debian auf einer VM auf dem Mac (eigene IP im Bridge Modus)

• als Client für beide ioBroker Installationen nutze ich den Mac mit Chrome

• im produktivem ioBroker funktioniert Sonos

na ja, eine Chance hätte ich wahrscheinlich eh nciht gehabt den Fehler zu finden :mrgreen:
2268_log_2.txt