FHEM Forum

FHEM => Anfängerfragen => Thema gestartet von: dantist am 25 Oktober 2019, 08:39:30

Titel: FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 25 Oktober 2019, 08:39:30
Hallo zusammen,

ich betreibe seit Jahren eine FHEM-Installation, die ohne Änderung des Setups plötzlich nicht mehr will. Die Weboberfläche lädt teilweise gar nicht mehr, das Licht (Homematic-Schalter -> Hue) schaltet teilweise erst mit über eine Minute Verzögerung. Der Raspberry Pi idelt dabei ohne CPU-Last vor sich hin, in den Logs steht auch nichts.

Wie kann ich rausfinden, was hier blockiert?

Danke & Gruß
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Otto123 am 25 Oktober 2019, 08:50:42
Moin,

liest sich erstmal ähnlich ? https://forum.fhem.de/index.php/topic,104703.msg986545.html#new

Netzteil, SD Card ...

Gruß Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Wernieman am 25 Oktober 2019, 09:37:15
Könnte auch diverse Funkstörungen sein .. was sagen den die Logfiles des Systems/FHEM bzw. die Eventlist von FHEM?
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 25 Oktober 2019, 09:42:23
Ich habe grade auf Verdacht alle Sonos-Geräte gelöscht, weil dieses Modul gerne Ärger macht, und es war tatsächlich der Übeltäter. Ohne Sonos rennt alles wie gewohnt. Ich verstehe bloß nicht, wie ein Modul FHEM fast zum Stillstand bringen kann, ohne CPU-Last zu erzeugen..
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: MadMax-FHEM am 25 Oktober 2019, 09:58:08
Fhem ist single threaded (wenn nicht was extra "nonblocking" von einem Modul gemacht wird), wenn dann fhem auf was wartet (z.B. Antwort Sonos) ist die CPU Last (von fhem) praktisch null trotzdem geht in fhem nix weil: wartet ja...

EDIT: wie aktuell ist fhem? Ist Sonos mittlerweile nicht auch schon non-blocking? Hat das Attribut dnsServer bei global Auswirkungen bei Sonos? Ist das gesetzt?

Gruß, Joachim
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 25 Oktober 2019, 10:04:29
FHEM ist auf dem aktuellsten Stand. Hatte auch länger keine Probleme mit Sonos, keine Ahnung, was plötzlich los ist. Ich habe im Moment einen der Lautsprecher nicht angeschlossen, aber das sollte doch nicht das ganze SmartHome lahmlegen ;D

Das Attribut dnsServer kenne ich nicht, muss ich mir mal anschauen.
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Otto123 am 25 Oktober 2019, 10:14:01
Das hatte ich noch nicht mit Sonos. Aber Zum Thema alle "Geräte gelöscht" will ich mal noch folgendes sagen:
attr Sonos disable 1 setzt Sonos auf eine "smarte" Art erstmal in den "Standby/Schlaf" disable 0 aktiviert den Prozess wieder. (Da laufen ja Prozesse außerhalb von FHEM)
delete Sonos sollte alles im System von Sonos löschen, alle Player usw. Dies kann bei alten Installationen unvollkommen sein, ist aber deutlich einfacher als alles zu Fuß zu löschen.
define Sonos SONOSsollte die Landschaft wieder sauber in Betrieb nehmen.

Gruß Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 25 Oktober 2019, 11:15:00
Danke Otto, ich werde heute Abend mal testen, ob ein disable den gleichen Effekt wie das Löschen aller Player hat.
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 29 Oktober 2019, 09:49:28
So, ein Update hierzu: Ich habe Sonos neu hinzugefügt, ohne die derzeit abgesteckten Lautsprecher. FHEM funktioniert damit soweit ok, allerdings besteht weiterhin das Problem, dass bei Druck auf einen Homematic-Schalter oder nach Bewegungserkennung das Licht sehr verzögert angeht. Nicht mehr so schlimm wie vorher, aber immer noch teils 10 Sekunden verzögert. Wenn ich "attr Sonos disable 1" ausführe gibt es keine Probleme mit dem Licht.

Beide Szenarien habe ich je zwei Tage lange testet, bin also ziemlich sicher, dass es am Sonos-Modul liegt. Wie komme ich hier weiter?
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Otto123 am 29 Oktober 2019, 11:39:23
Moin,

das klingt danach, als ob der separate Sonos UPNP Thread Probleme hat und den System belastet oder ausbremst.
Ich würde irgendwelche Konflikte im Bereich IP Adressen und Namen vermuten. Schau mal in dem langen Sonos Thread gab es da lange Diskussionen. Such mal nach dem Begriff ignoredIPs
Aber ich habe nur mitgelesen, ich hatte das Problem selbst nicht.

Gruß Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 29 Oktober 2019, 23:10:15
Nur um sicherzugehen, dass der Ansatz richtig ist: Alle meine Sonos liegen im Bereich 192.168.1.8* (also 80-89). Wenn ich alle anderen Geräte im Netzwerk ignorieren möchte, ist folgendes korrekt?

usedonlyIPs /192.168.1.8\d*/
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Otto123 am 29 Oktober 2019, 23:19:57
Ich weiß es nicht. Aber ich lese die Doku anders - da steht nicht regEx:
ZitatusedonlyIPs <IP-Adresse>[,IP-Adresse]
Mit diesem Attribut können IP-Adressen angegeben werden, die ausschließlich vom UPnP-System berücksichtigt werden sollen. Z.B.: "192.168.0.11,192.168.0.37"
Also schreib doch einfach die  9 Adressen hin?
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 29 Oktober 2019, 23:33:36
Zitat von: Otto123 am 29 Oktober 2019, 23:19:57
Ich weiß es nicht. Aber ich lese die Doku anders - da steht nicht regEx:Also schreib doch einfach die  9 Adressen hin?
Eine Zeile weiter steht es  :)

ZitatEs sind auch reguläre Ausdrücke pro Element zulässig. Diese dürfen nur keine Kommata oder Doppelpunkte enthalten. Z.B: /192.168.0.(1|2|3)/,/192.168.1.\d*/.

Zumindest tauchen die Lautsprecher noch in FHEM auf. Werde das Verhalten von Homematic/Hue damit weiter beobachten.
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Otto123 am 29 Oktober 2019, 23:40:04
Wo steht das? In der Cref nicht  :-[ ??? oder ist es schon so spät?
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: Prof. Dr. Peter Henning am 30 Oktober 2019, 08:53:32
Tipp: Alle Devices, die auf irgendwelche Rückgaben aus dem Netz warten, auf eine separate FHEM-Instanz auslagern.

LG

pah
Titel: Antw:FHEM reagiert nicht / sehr verzögert
Beitrag von: dantist am 30 Oktober 2019, 09:18:06
Zitat von: Otto123 am 29 Oktober 2019, 23:40:04
Wo steht das? In der Cref nicht  :-[ ??? oder ist es schon so spät?

Hab's aus dem Wiki: https://wiki.fhem.de/wiki/SONOS

Leider war FHEM heute morgen wieder komplett unresponsive. Erst nach einem Neustart konnte ich Sonos auf disable=1 setzen, jetzt flutscht wieder alles.
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: der-Lolo am 30 Oktober 2019, 10:31:49
Vielleicht gibt es auch einen IP Konflikt, sowas hatte ich mal. Auch im zusammenhang mit einem Lautsprecher den ich aus Energiespargründen tagsüber deaktivieren wollte.

Wie kommunizierst Du denn mit den Homematic komponenten?
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 30 Oktober 2019, 22:13:20
Zitat von: der-Lolo am 30 Oktober 2019, 10:31:49
Vielleicht gibt es auch einen IP Konflikt, sowas hatte ich mal. Auch im zusammenhang mit einem Lautsprecher den ich aus Energiespargründen tagsüber deaktivieren wollte.

Wie kommunizierst Du denn mit den Homematic komponenten?

Einen IP-Konflikt kann ich ausschließen, die habe ich alle sauber in meinem eigenen DHCP-Server vergeben. Die Sonos-Lautsprecher und alle anderen Geräte im Netz haben seit eh und je ihre festen IPs.

Homematic läuft über einen HM-CFG-USB Stick.
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: det. am 30 Oktober 2019, 22:53:40
Ist hier schon öfter diskutiert worden, aber vielleicht an Dir vorbeigegangen. Nur als Lösungsansatz: denk einfach mal über die Neuanschaffung eines potenteren Servers nach. RPI ist wie, wenn Du Formel1 mit einem 500ter Fiat fahren willst. Es gibt hier im Forum sicher viele, die Dir gern dabei helfen, mit der lahmen Kiste trotzdem über die Ziellinie zu kommen. Die Frage stellt sich nur, ist es der Aufwand wert?
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 30 Oktober 2019, 22:58:51
Vorschlag:
usedonlyIPs und nur ein paar Adressen per Hand und ohne regEx eintragen: entweder erst mal die obere Hälfte oder die untere Hälfte der Sonosboxen. Die Zeit bis zum Fehler ist ja nur ein Nacht.

Gruß Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 01 November 2019, 01:13:31
Ich habe heute früh zwei der Sonos-Lautsprecher aktiviert, bisher scheint alles zu laufen. Werde es noch etwas beobachten und dann weitere hinzufügen, bis das Problem wieder auftritt.
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 04 November 2019, 22:51:01
Ich habe die letzten Tage nach und nach die Lautsprecher wieder aktiviert und folgendes festgestellt: Gefühlt ist es so, dass je mehr Lautsprecher aktiv sind, desto häufiger die Aussetzer auftreten.

Außerdem noch interessant: In den 10-20 Sekunden, in denen nach Tastendruck das Licht nicht angeht, hängt FHEM komplett. Kein Zugriff auf die Web-Oberfläche. In dem Moment, wo das Licht angeht, lädt auch die Oberfläche wieder.

Anders herum gesagt: Das Sonos-Modul scheint FHEM hin und wieder komplett zu blockieren, wodurch Befehle verzögert ausgeführt werden.
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 04 November 2019, 22:59:41
In meinem FHEM sind 7 Sonos Boxen aktiv. Es läuft auf einem Pi. Ich habe einiges an Homematic. Hänger im System, Verzögerung bei Homematic kenne ich nicht.

Ich habe keine konkreten Tipps für Dich, aber ich vermute im Netzwerk ist was faul. Ich vermute am ehesten IP Adressen Konflikte, DNS Auflösung....
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 04 November 2019, 23:53:23
Wenn es Probleme im Netzwerk gäbe, müsste ich das doch auch außerhalb von FHEM merken? Die Boxen lassen sich über die App jederzeit ansteuern und spielen auch, wenn FHEM grade hängt.

Lässt sich irgendwie debuggen, warum FHEM stehenbleibt? Oder merkt es das selbst gar nicht?
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 05 November 2019, 11:22:14
ich glaube (und so hatte ich mal Probleme im Sonos Thread verstanden) das weder FHEM noch irgendetwas anderes konkret und für alle nachvollziehbar Probleme hat oder macht. Das Sonos Modul startet einen separaten UPNP Prozess der mit den Sonos Boxen und FHEM kommuniziert. Wenn Du Sonos disabled setzt, beendest Du damit indirekt auch diesen UPNP Prozess. Da dann alles funktioniert, vermute ich das Problem dort.
Aus der Diskussion im Sonos Thread habe ich heraus gelesen, das der Prozess Probleme hat wenn er auf Geräte im Netzwerk stößt die für ihn so aussehen wie eine Sonos Box.
Für Details kannst Du dort bloß mal auf Suche gehen, ich  kann Dir da nicht weiter helfen.

FHEM debuggen:
Du kannst mit erhöhtem Logging und Stacktrace sowie dem Modul freezemon versuchen an Informationen zu gelangen.
Aber ich vermute mal da kommt raus Sonos hängt? Ich weiß es nicht.

Viel Erfolg
Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 09 November 2019, 21:28:08
Zitat von: Otto123 am 05 November 2019, 11:22:14
Das Sonos Modul startet einen separaten UPNP Prozess der mit den Sonos Boxen und FHEM kommuniziert. Wenn Du Sonos disabled setzt, beendest Du damit indirekt auch diesen UPNP Prozess. Da dann alles funktioniert, vermute ich das Problem dort.
Aus der Diskussion im Sonos Thread habe ich heraus gelesen, das der Prozess Probleme hat wenn er auf Geräte im Netzwerk stößt die für ihn so aussehen wie eine Sonos Box.
Für Details kannst Du dort bloß mal auf Suche gehen, ich  kann Dir da nicht weiter helfen.

Jo, so sieht's aus. Mein ganzes Leid mit dem Sonos Modul, Emby Server und TVHeadend habe ich hier beschrieben und analysiert:


https://github.com/netdata/netdata/issues/6527

Alle 3 Services nutzen UPNP. Mein netdata spamt mich zu mit Emails, dass es udp errors gibt. Auch wenn der zuvor verlinkte Issue bei github auf closed ist, ist das Problem nicht gelöst. Die Probleme treten nur auf, wenn das Sonos Modul aktiv ist.

Bei mir fällt das allerdings nicht ins Gewicht, da ich nen XEON mit 64GB Ram habe... ;) Zumindest spüre ich keine Verzögerungen. Alles flutscht. Ich habe jetzt netdata deaktiviert, um nicht weiter von den Mails genervt zu werden. Zum Schluss kamen sie alle 5min.

Zeig mal die Ausgaben von:

netstat -unlp | grep ":1900"

und:

netstat -anus

Hast du packet receive errors bzw. receive buffer errors?

Der Pi hat ja nur eine 100MBit Schnittstelle. Meine Vermutung ist, dass dein receive buffer überläuft. Anschließend hast du dann wahrscheinlich Verzögerungen. Wenn du den Pi rebootest, wird die Statistik und auch der buffer auf 0 zurückgesetzt. Dann dauert es ein wenig bis sich das System ,,hochschaukelt" und der receive buffer erneut voll-/überläuft.

Bin gespannt auf dein Ergebnis. Wenn es das ist, Prost Mahlzeit. Das Thema ist anscheinend ein Moorloch. Gefühlt versteht es niemand so richtig. Wenn man Berichte mit ähnlichen Problemen findet, versandet es oder Konfigurationslösungen funktionieren in Zusammenhang mit dem Sonos Modul nicht.

Alle anderen Lösungen wurden hier wohl schon genannt. Kauf dir nen performanteren Server oder lager FHEM auf einen anderen Server/Pi aus. Ob das dann wirklich die Lösung ist, ich weiß es nicht.

Da ich persönlich keine Performance-Einbußen habe, werde ich mich erst wieder damit beschäftigen, wenn ich von Stretch zu Buster migriere.

In dem Zuge wandert FHEM dann entweder in einen Docker oder in einen LXC Container, so dass ich FHEM eine eigene IP geben kann.


Gruß Hoppel
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 09 November 2019, 22:50:49
Hallo Hoppel,

danke für deine super ausführliche Antwort - ich bin nicht sicher, ob ich alles verstanden habe ;) Raspbian läuft bei mir schon auf Buster, die Hardware ist ein RPi 3 B+, der schafft etwa 300 MBit/s an der Netzwerkschnittstelle statt 100.

Habe das Sonos-Modul jetzt nochmal hinzugefügt, um dir aktuelle Logs und den Output der Shell-Befehle zeigen zu können.

Direkt nach FHEM-Start, das Modul läuft noch: https://i.imgur.com/FUBRwe6.png

Kurze Zeit später beendet sich der Prozess, dann sieht die Ausgabe so aus: https://i.imgur.com/dsWDBEL.png

Hier das FHEM-Log vom Booten bis zum zweiten Ausstieg des Sonos-Moduls:

2019.11.09 22:33:28 0: Server shutdown
2019.11.09 22:33:49 1: Including fhem.cfg
2019.11.09 22:33:49 3: telnetPort: port 7072 opened
2019.11.09 22:33:49 3: WEB: port 8083 opened
2019.11.09 22:33:49 3: WEBphone: port 8084 opened
2019.11.09 22:33:49 3: WEBtablet: port 8085 opened
2019.11.09 22:33:50 2: eventTypes: loaded 6595 events from ./log/eventTypes.txt
2019.11.09 22:33:52 3: HUEDevice3: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEDevice9: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEDevice2: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEDevice8: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEDevice1: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEDevice4: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEGroup1: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEGroup0: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEGroup3: I/O device is hueBridge1
2019.11.09 22:33:52 3: HUEGroup2: I/O device is hueBridge1
2019.11.09 22:33:58 1: HMLAN_Parse: hmusb new condition disconnected
2019.11.09 22:33:58 3: Opening hmusb device 127.0.0.1:1234
2019.11.09 22:33:58 1: HMLAN_Parse: hmusb new condition init
2019.11.09 22:33:58 3: hmusb device opened
2019.11.09 22:33:59 3: HUEGroup5: I/O device is hueBridge1
2019.11.09 22:33:59 3: Opening AVReceiver device 192.168.108.59:23
2019.11.09 22:34:00 3: AVReceiver device opened
2019.11.09 22:34:00 2: VIERA: defined with host: 192.168.108.58 and interval: 30
2019.11.09 22:34:00 3: HUEGroup6: I/O device is hueBridge1
2019.11.09 22:34:00 3: HUEDevice15: I/O device is hueBridge1
2019.11.09 22:34:00 3: HUEGroup4: I/O device is hueBridge1
2019.11.09 22:34:00 3: HUEGroup7: I/O device is hueBridge1
2019.11.09 22:34:00 3: HUEDevice17: I/O device is hueBridge1
2019.11.09 22:34:00 3: Opening ZWaveDongle device /dev/ttyACM0
2019.11.09 22:34:00 3: Setting ZWaveDongle serial parameters to 115200,8,N,1
2019.11.09 22:34:02 3: ZWaveDongle device opened
2019.11.09 22:34:02 3: ZWave: cannot load Crypt::Rijndael, SECURITY class disabled
2019.11.09 22:34:02 3: HUEDevice10: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice7: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice11: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice6: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice13: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice5: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice18: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEGroup8: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice23: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice22: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice21: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice20: I/O device is hueBridge1
2019.11.09 22:34:02 3: HUEDevice19: I/O device is hueBridge1
2019.11.09 22:34:03 1: SONOS0: Modify Device: Sonos
2019.11.09 22:34:03 1: Including ./log/fhem.save
2019.11.09 22:34:03 3: Device BewegungsmelderFlur added to ActionDetector with 000:10 time
2019.11.09 22:34:04 3: Device SensorWohnungstuer added to ActionDetector with 000:50 time
2019.11.09 22:34:04 3: Device Steckdose01_HM added to ActionDetector with 000:10 time
2019.11.09 22:34:04 3: Device Steckdose02_HM added to ActionDetector with 000:10 time
2019.11.09 22:34:04 3: Device Wassermelder added to ActionDetector with 028:00 time
2019.11.09 22:34:06 0: Featurelevel: 5.7
2019.11.09 22:34:06 0: Server started with 236 defined entities (fhem.pl:20460/2019-11-05 perl:5.028001 os:linux user:fhem pid:714)
2019.11.09 22:34:06 2: ZWDongle_ProcessSendStack: no ACK, resending message 0107000301020100f9
2019.11.09 22:34:06 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2019.11.09 22:34:06 3: CUL_HM set Steckdose01_HM_Sw statusRequest
2019.11.09 22:34:07 1: HMLAN_Parse: hmusb new condition ok
2019.11.09 22:34:08 3: CUL_HM set Steckdose02_HM_Sw statusRequest
2019.11.09 22:34:08 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2019.11.09 22:34:23 3: Opening Sonos device localhost:4711
2019.11.09 22:34:23 3: SONOS0: Connection accepted from localhost:54340
2019.11.09 22:34:23 3: Sonos device opened
2019.11.09 22:34:24 3: SONOS1: UPnP-Thread gestartet.
2019.11.09 22:34:24 1: SONOS2: IsAlive-Thread gestartet. Warte 120 Sekunden und pruefe dann alle 30 Sekunden...
2019.11.09 22:34:24 1: SONOS3: Restore-Thread gestartet. Warte auf Arbeit...
2019.11.09 22:34:25 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E9375542B401400_MR'
2019.11.09 22:34:26 2: SONOS1: SonosPlayer 'Kueche_RF' (S1) with ID 'RINCON_B8E9375542B401400_MR' is already defined (as 'Sonos_Kueche_RF') and will only be updated
2019.11.09 22:34:26 2: SONOS1: SonosPlayer 'Kueche_RF' is now updated
2019.11.09 22:34:26 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000029
2019.11.09 22:34:26 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000030
2019.11.09 22:34:26 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000031
2019.11.09 22:34:26 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000032
2019.11.09 22:34:26 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000033
2019.11.09 22:34:26 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000034
2019.11.09 22:34:26 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000035
2019.11.09 22:34:26 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000036
2019.11.09 22:34:26 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:34:26 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E937544FD201400_MR'
2019.11.09 22:34:27 2: SONOS1: SonosPlayer 'Kueche' (S1) with ID 'RINCON_B8E937544FD201400_MR' is already defined (as 'Sonos_Kueche') and will only be updated
2019.11.09 22:34:27 2: SONOS1: SonosPlayer 'Kueche' is now updated
2019.11.09 22:34:27 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000046
2019.11.09 22:34:27 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000047
2019.11.09 22:34:27 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000048
2019.11.09 22:34:27 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000049
2019.11.09 22:34:27 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000050
2019.11.09 22:34:27 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000051
2019.11.09 22:34:27 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000052
2019.11.09 22:34:27 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000053
2019.11.09 22:34:27 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:34:27 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:27 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:27 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:27 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:28 2: SONOS1: Discover Sonosplayer 'Bad' (S12) Software Revision 10.5 with ID 'RINCON_949F3E0918F601400_MR'
2019.11.09 22:34:28 2: SONOS1: SonosPlayer 'Bad' (S12) with ID 'RINCON_949F3E0918F601400_MR' is already defined (as 'Sonos_Bad') and will only be updated
2019.11.09 22:34:28 2: SONOS1: SonosPlayer 'Bad' is now updated
2019.11.09 22:34:28 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000056
2019.11.09 22:34:28 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000057
2019.11.09 22:34:28 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000058
2019.11.09 22:34:28 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000059
2019.11.09 22:34:28 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000060
2019.11.09 22:34:28 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000061
2019.11.09 22:34:28 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000062
2019.11.09 22:34:28 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000063
2019.11.09 22:34:28 3: SONOS1: Discover: End of discover-event for "Bad".
2019.11.09 22:34:28 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:28 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:28 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:28 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:28 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B8B201400_MR'
2019.11.09 22:34:29 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) with ID 'RINCON_B8E937B7B8B201400_MR' is already defined (as 'Sonos_Schlafzimmer') and will only be updated
2019.11.09 22:34:29 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
2019.11.09 22:34:29 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000046
2019.11.09 22:34:29 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000047
2019.11.09 22:34:29 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000048
2019.11.09 22:34:29 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000049
2019.11.09 22:34:29 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000050
2019.11.09 22:34:29 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000051
2019.11.09 22:34:29 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000052
2019.11.09 22:34:29 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000053
2019.11.09 22:34:29 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
2019.11.09 22:34:29 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:34:30 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:34:30 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:30 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:30 2: SONOS1: Discover Sonosplayer 'Flur' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B86401400_MR'
2019.11.09 22:34:30 2: SONOS1: SonosPlayer 'Flur' (S1) with ID 'RINCON_B8E937B7B86401400_MR' is already defined (as 'Sonos_Flur') and will only be updated
2019.11.09 22:34:30 2: SONOS1: SonosPlayer 'Flur' is now updated
2019.11.09 22:34:30 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000045
2019.11.09 22:34:30 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000046
2019.11.09 22:34:30 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000047
2019.11.09 22:34:30 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000048
2019.11.09 22:34:30 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000049
2019.11.09 22:34:30 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000050
2019.11.09 22:34:30 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000051
2019.11.09 22:34:30 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000052
2019.11.09 22:34:30 3: SONOS1: Discover: End of discover-event for "Flur".
2019.11.09 22:34:30 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:31 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:31 2: SONOS1: Discover Sonosplayer 'Wohnzimmer' (ZP90) Software Revision 10.5 with ID 'RINCON_B8E93798F38A01400_MR'
2019.11.09 22:34:31 2: SONOS1: SonosPlayer 'Wohnzimmer' (ZP90) with ID 'RINCON_B8E93798F38A01400_MR' is already defined (as 'Sonos_Wohnzimmer') and will only be updated
2019.11.09 22:34:31 2: SONOS1: SonosPlayer 'Wohnzimmer' is now updated
2019.11.09 22:34:31 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000063
2019.11.09 22:34:31 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000064
2019.11.09 22:34:31 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000065
2019.11.09 22:34:31 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000066
2019.11.09 22:34:31 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000067
2019.11.09 22:34:31 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000068
2019.11.09 22:34:31 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000069
2019.11.09 22:34:31 2: SONOS1: AudioIn-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000070
2019.11.09 22:34:31 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000071
2019.11.09 22:34:31 3: SONOS1: Discover: End of discover-event for "Wohnzimmer".
2019.11.09 22:34:31 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:34:32 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:34:32 2: SONOS1: Discover Sonosplayer 'Lukas' (S1) Software Revision 10.5 with ID 'RINCON_B8E937E0533001400_MR'
2019.11.09 22:34:32 2: SONOS1: SonosPlayer 'Lukas' (S1) with ID 'RINCON_B8E937E0533001400_MR' is already defined (as 'Sonos_Lukas') and will only be updated
2019.11.09 22:34:32 2: SONOS1: SonosPlayer 'Lukas' is now updated
2019.11.09 22:34:32 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000045
2019.11.09 22:34:32 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000046
2019.11.09 22:34:32 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000047
2019.11.09 22:34:32 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000048
2019.11.09 22:34:32 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000049
2019.11.09 22:34:33 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000050
2019.11.09 22:34:33 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000051
2019.11.09 22:34:33 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000052
2019.11.09 22:34:33 3: SONOS1: Discover: End of discover-event for "Lukas".
2019.11.09 22:34:33 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:34:33 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:34:33 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:33 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:34:33 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:34:33 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:34:33 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:33 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:34:33 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:34:33 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:34:33 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:34:33 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:34:33 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:34:33 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:34:33 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:34:33 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:34:33 3: SONOS1: Event: Received MusicServices-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:36:08 3: Watchdog HallLeft triggered
2019.11.09 22:36:33 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1573335273.21678 ~ 2019-11-09 22:34:33)... try to restart the process and connection...
2019.11.09 22:36:34 3: SONOS0: Disconnecting client and shutdown server...
2019.11.09 22:36:34 3: SONOS0: Trying to kill Sonos_Thread...
2019.11.09 22:36:34 3: SONOS0: Trying to kill IsAlive_Thread...
2019.11.09 22:36:34 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.11.09 22:36:34 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
2019.11.09 22:37:03 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2019.11.09 22:37:04 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2019.11.09 22:37:11 3: Opening Sonos device localhost:4711
2019.11.09 22:37:11 3: SONOS0: Connection accepted from localhost:54872
2019.11.09 22:37:11 3: Sonos device opened
2019.11.09 22:37:12 3: SONOS1: UPnP-Thread gestartet.
2019.11.09 22:37:12 1: SONOS2: IsAlive-Thread gestartet. Warte 120 Sekunden und pruefe dann alle 30 Sekunden...
2019.11.09 22:37:12 2: SONOS1: Discover Sonosplayer 'Bad' (S12) Software Revision 10.5 with ID 'RINCON_949F3E0918F601400_MR'
2019.11.09 22:37:12 1: SONOS3: Restore-Thread gestartet. Warte auf Arbeit...
2019.11.09 22:37:13 2: SONOS1: SonosPlayer 'Bad' (S12) with ID 'RINCON_949F3E0918F601400_MR' is already defined (as 'Sonos_Bad') and will only be updated
2019.11.09 22:37:13 2: SONOS1: SonosPlayer 'Bad' is now updated
2019.11.09 22:37:13 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000064
2019.11.09 22:37:13 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000065
2019.11.09 22:37:13 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000066
2019.11.09 22:37:13 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000067
2019.11.09 22:37:13 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000068
2019.11.09 22:37:13 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000069
2019.11.09 22:37:13 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000070
2019.11.09 22:37:13 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000071
2019.11.09 22:37:13 3: SONOS1: Discover: End of discover-event for "Bad".
2019.11.09 22:37:13 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E937544FD201400_MR'
2019.11.09 22:37:14 2: SONOS1: SonosPlayer 'Kueche' (S1) with ID 'RINCON_B8E937544FD201400_MR' is already defined (as 'Sonos_Kueche') and will only be updated
2019.11.09 22:37:15 2: SONOS1: SonosPlayer 'Kueche' is now updated
2019.11.09 22:37:15 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000054
2019.11.09 22:37:15 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000055
2019.11.09 22:37:15 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000056
2019.11.09 22:37:15 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000057
2019.11.09 22:37:15 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000058
2019.11.09 22:37:15 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000059
2019.11.09 22:37:15 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000060
2019.11.09 22:37:15 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000061
2019.11.09 22:37:15 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:37:15 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:37:15 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:37:15 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E9375542B401400_MR'
2019.11.09 22:37:16 2: SONOS1: SonosPlayer 'Kueche_RF' (S1) with ID 'RINCON_B8E9375542B401400_MR' is already defined (as 'Sonos_Kueche_RF') and will only be updated
2019.11.09 22:37:16 2: SONOS1: SonosPlayer 'Kueche_RF' is now updated
2019.11.09 22:37:16 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000037
2019.11.09 22:37:16 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000038
2019.11.09 22:37:17 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000039
2019.11.09 22:37:17 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000040
2019.11.09 22:37:17 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000041
2019.11.09 22:37:17 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000042
2019.11.09 22:37:17 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000043
2019.11.09 22:37:17 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000044
2019.11.09 22:37:17 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:37:17 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:17 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:17 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B8B201400_MR'
2019.11.09 22:37:18 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) with ID 'RINCON_B8E937B7B8B201400_MR' is already defined (as 'Sonos_Schlafzimmer') and will only be updated
2019.11.09 22:37:18 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
2019.11.09 22:37:18 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000054
2019.11.09 22:37:18 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000055
2019.11.09 22:37:18 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000056
2019.11.09 22:37:18 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000057
2019.11.09 22:37:18 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000058
2019.11.09 22:37:18 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000059
2019.11.09 22:37:18 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000060
2019.11.09 22:37:18 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000061
2019.11.09 22:37:18 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
2019.11.09 22:37:18 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:37:18 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:37:18 2: SONOS1: Discover Sonosplayer 'Lukas' (S1) Software Revision 10.5 with ID 'RINCON_B8E937E0533001400_MR'
2019.11.09 22:37:19 2: SONOS1: SonosPlayer 'Lukas' (S1) with ID 'RINCON_B8E937E0533001400_MR' is already defined (as 'Sonos_Lukas') and will only be updated
2019.11.09 22:37:19 2: SONOS1: SonosPlayer 'Lukas' is now updated
2019.11.09 22:37:19 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000053
2019.11.09 22:37:19 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000054
2019.11.09 22:37:19 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000055
2019.11.09 22:37:19 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000056
2019.11.09 22:37:19 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000057
2019.11.09 22:37:19 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000058
2019.11.09 22:37:19 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000059
2019.11.09 22:37:19 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000060
2019.11.09 22:37:19 3: SONOS1: Discover: End of discover-event for "Lukas".
2019.11.09 22:37:19 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:19 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:20 2: SONOS1: Discover Sonosplayer 'Wohnzimmer' (ZP90) Software Revision 10.5 with ID 'RINCON_B8E93798F38A01400_MR'
2019.11.09 22:37:20 2: SONOS1: SonosPlayer 'Wohnzimmer' (ZP90) with ID 'RINCON_B8E93798F38A01400_MR' is already defined (as 'Sonos_Wohnzimmer') and will only be updated
2019.11.09 22:37:20 2: SONOS1: SonosPlayer 'Wohnzimmer' is now updated
2019.11.09 22:37:20 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000072
2019.11.09 22:37:20 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000073
2019.11.09 22:37:20 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000074
2019.11.09 22:37:20 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000075
2019.11.09 22:37:20 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000076
2019.11.09 22:37:20 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000077
2019.11.09 22:37:20 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000078
2019.11.09 22:37:20 2: SONOS1: AudioIn-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000079
2019.11.09 22:37:20 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000080
2019.11.09 22:37:20 3: SONOS1: Discover: End of discover-event for "Wohnzimmer".
2019.11.09 22:37:20 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:20 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:20 2: SONOS1: Discover Sonosplayer 'Flur' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B86401400_MR'
2019.11.09 22:37:21 2: SONOS1: SonosPlayer 'Flur' (S1) with ID 'RINCON_B8E937B7B86401400_MR' is already defined (as 'Sonos_Flur') and will only be updated
2019.11.09 22:37:21 2: SONOS1: SonosPlayer 'Flur' is now updated
2019.11.09 22:37:21 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000053
2019.11.09 22:37:21 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000054
2019.11.09 22:37:21 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000055
2019.11.09 22:37:21 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000056
2019.11.09 22:37:21 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000057
2019.11.09 22:37:21 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000058
2019.11.09 22:37:21 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000059
2019.11.09 22:37:21 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000060
2019.11.09 22:37:21 3: SONOS1: Discover: End of discover-event for "Flur".
2019.11.09 22:37:21 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:37:22 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:22 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:22 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:37:22 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Bad".
2019.11.09 22:37:22 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Bad".
2019.11.09 22:37:22 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Lukas".
2019.11.09 22:37:22 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Lukas".
2019.11.09 22:37:22 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:22 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:22 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:37:22 3: SONOS1: Event: Received GroupRendering-Event for Zone "Sonos_Flur".
2019.11.09 22:37:22 3: SONOS1: Event: End of GroupRendering-Event for Zone "Sonos_Flur".
2019.11.09 22:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:37:22 3: SONOS1: Event: Received MusicServices-Event for Zone "Sonos_Bad".
2019.11.09 22:39:22 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1573335442.02732 ~ 2019-11-09 22:37:22)... try to restart the process and connection...
2019.11.09 22:39:23 3: SONOS0: Disconnecting client and shutdown server...
2019.11.09 22:39:23 3: SONOS0: Trying to kill Sonos_Thread...
2019.11.09 22:39:23 3: SONOS0: Trying to kill IsAlive_Thread...
2019.11.09 22:39:23 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.11.09 22:39:23 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
2019.11.09 22:39:46 3: Watchdog HallLeft triggered
2019.11.09 22:39:52 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2019.11.09 22:39:53 0: SONOS0: Can't bind Port 4711: Bind failed: Address already in use at ./FHEM/00_SONOS.pm line 9817.

2019.11.09 22:39:53 0: SONOS0: Retries left (wait 30s): 9
2019.11.09 22:40:00 3: Opening Sonos device localhost:4711
2019.11.09 22:40:00 1: Sonos: Can't connect to localhost:4711: Connection refused
2019.11.09 22:40:23 0: SONOS0: Can't bind Port 4711: Bind failed: Address already in use at ./FHEM/00_SONOS.pm line 9817.

2019.11.09 22:40:23 0: SONOS0: Retries left (wait 30s): 8
2019.11.09 22:40:53 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2019.11.09 22:41:00 3: SONOS0: Connection accepted from localhost:55452
2019.11.09 22:41:00 1: localhost:4711 reappeared (Sonos)
2019.11.09 22:41:01 3: SONOS1: UPnP-Thread gestartet.
2019.11.09 22:41:01 1: SONOS2: IsAlive-Thread gestartet. Warte 120 Sekunden und pruefe dann alle 30 Sekunden...
2019.11.09 22:41:01 2: SONOS1: Discover Sonosplayer 'Wohnzimmer' (ZP90) Software Revision 10.5 with ID 'RINCON_B8E93798F38A01400_MR'
2019.11.09 22:41:02 1: SONOS3: Restore-Thread gestartet. Warte auf Arbeit...
2019.11.09 22:41:02 2: SONOS1: SonosPlayer 'Wohnzimmer' (ZP90) with ID 'RINCON_B8E93798F38A01400_MR' is already defined (as 'Sonos_Wohnzimmer') and will only be updated
2019.11.09 22:41:02 2: SONOS1: SonosPlayer 'Wohnzimmer' is now updated
2019.11.09 22:41:02 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000081
2019.11.09 22:41:02 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000082
2019.11.09 22:41:02 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000083
2019.11.09 22:41:02 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000084
2019.11.09 22:41:02 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000085
2019.11.09 22:41:02 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000086
2019.11.09 22:41:02 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000087
2019.11.09 22:41:02 2: SONOS1: AudioIn-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000088
2019.11.09 22:41:02 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E93798F38A01400_sub0000000089
2019.11.09 22:41:02 3: SONOS1: Discover: End of discover-event for "Wohnzimmer".
2019.11.09 22:41:02 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E937544FD201400_MR'
2019.11.09 22:41:03 2: SONOS1: SonosPlayer 'Kueche' (S1) with ID 'RINCON_B8E937544FD201400_MR' is already defined (as 'Sonos_Kueche') and will only be updated
2019.11.09 22:41:03 2: SONOS1: SonosPlayer 'Kueche' is now updated
2019.11.09 22:41:03 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000062
2019.11.09 22:41:03 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000063
2019.11.09 22:41:03 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000064
2019.11.09 22:41:03 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000065
2019.11.09 22:41:03 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000066
2019.11.09 22:41:03 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000067
2019.11.09 22:41:03 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000068
2019.11.09 22:41:03 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937544FD201400_sub0000000069
2019.11.09 22:41:03 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:41:03 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:03 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:03 2: SONOS1: Discover Sonosplayer 'Flur' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B86401400_MR'
2019.11.09 22:41:04 2: SONOS1: SonosPlayer 'Flur' (S1) with ID 'RINCON_B8E937B7B86401400_MR' is already defined (as 'Sonos_Flur') and will only be updated
2019.11.09 22:41:04 2: SONOS1: SonosPlayer 'Flur' is now updated
2019.11.09 22:41:04 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000061
2019.11.09 22:41:04 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000062
2019.11.09 22:41:04 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000063
2019.11.09 22:41:04 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000064
2019.11.09 22:41:04 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000065
2019.11.09 22:41:04 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000066
2019.11.09 22:41:04 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000067
2019.11.09 22:41:04 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B86401400_sub0000000068
2019.11.09 22:41:04 3: SONOS1: Discover: End of discover-event for "Flur".
2019.11.09 22:41:04 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:04 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:05 2: SONOS1: Discover Sonosplayer 'Bad' (S12) Software Revision 10.5 with ID 'RINCON_949F3E0918F601400_MR'
2019.11.09 22:41:05 2: SONOS1: SonosPlayer 'Bad' (S12) with ID 'RINCON_949F3E0918F601400_MR' is already defined (as 'Sonos_Bad') and will only be updated
2019.11.09 22:41:05 2: SONOS1: SonosPlayer 'Bad' is now updated
2019.11.09 22:41:05 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000073
2019.11.09 22:41:05 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000074
2019.11.09 22:41:05 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000075
2019.11.09 22:41:05 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000076
2019.11.09 22:41:05 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000077
2019.11.09 22:41:05 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000078
2019.11.09 22:41:05 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000079
2019.11.09 22:41:05 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_949F3E0918F601400_sub0000000080
2019.11.09 22:41:05 3: SONOS1: Discover: End of discover-event for "Bad".
2019.11.09 22:41:05 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:05 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:05 2: SONOS1: Discover Sonosplayer 'Küche' (S1) Software Revision 10.5 with ID 'RINCON_B8E9375542B401400_MR'
2019.11.09 22:41:06 2: SONOS1: SonosPlayer 'Kueche_RF' (S1) with ID 'RINCON_B8E9375542B401400_MR' is already defined (as 'Sonos_Kueche_RF') and will only be updated
2019.11.09 22:41:06 2: SONOS1: SonosPlayer 'Kueche_RF' is now updated
2019.11.09 22:41:06 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000045
2019.11.09 22:41:06 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000046
2019.11.09 22:41:06 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000047
2019.11.09 22:41:06 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000048
2019.11.09 22:41:06 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000049
2019.11.09 22:41:06 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000050
2019.11.09 22:41:06 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000051
2019.11.09 22:41:06 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E9375542B401400_sub0000000052
2019.11.09 22:41:06 3: SONOS1: Discover: End of discover-event for "Küche".
2019.11.09 22:41:06 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:41:06 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Flur".
2019.11.09 22:41:07 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 10.5 with ID 'RINCON_B8E937B7B8B201400_MR'
2019.11.09 22:41:07 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) with ID 'RINCON_B8E937B7B8B201400_MR' is already defined (as 'Sonos_Schlafzimmer') and will only be updated
2019.11.09 22:41:07 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
2019.11.09 22:41:07 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000062
2019.11.09 22:41:07 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000063
2019.11.09 22:41:07 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000064
2019.11.09 22:41:07 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000065
2019.11.09 22:41:07 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000066
2019.11.09 22:41:07 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000067
2019.11.09 22:41:07 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000068
2019.11.09 22:41:07 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937B7B8B201400_sub0000000069
2019.11.09 22:41:07 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
2019.11.09 22:41:07 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:07 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:07 2: SONOS1: Discover Sonosplayer 'Lukas' (S1) Software Revision 10.5 with ID 'RINCON_B8E937E0533001400_MR'
2019.11.09 22:41:08 2: SONOS1: SonosPlayer 'Lukas' (S1) with ID 'RINCON_B8E937E0533001400_MR' is already defined (as 'Sonos_Lukas') and will only be updated
2019.11.09 22:41:08 2: SONOS1: SonosPlayer 'Lukas' is now updated
2019.11.09 22:41:08 2: SONOS1: Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000061
2019.11.09 22:41:08 2: SONOS1: Rendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000062
2019.11.09 22:41:08 2: SONOS1: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000063
2019.11.09 22:41:08 2: SONOS1: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000064
2019.11.09 22:41:08 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000065
2019.11.09 22:41:08 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000066
2019.11.09 22:41:08 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000067
2019.11.09 22:41:08 2: SONOS1: MusicServices-Service-subscribing successful with SID=uuid:RINCON_B8E937E0533001400_sub0000000068
2019.11.09 22:41:08 3: SONOS1: Discover: End of discover-event for "Lukas".
2019.11.09 22:41:08 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:41:08 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2019.11.09 22:41:08 3: SONOS1: Event: Received AudioIn-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:08 3: SONOS1: Event: End of AudioIn-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:08 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:09 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:41:09 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Lukas".
2019.11.09 22:41:09 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:41:09 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:09 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Kueche".
2019.11.09 22:41:09 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Lukas".
2019.11.09 22:41:09 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Lukas".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2019.11.09 22:41:09 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Wohnzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche_RF".
2019.11.09 22:41:09 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Flur".
2019.11.09 22:41:09 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2019.11.09 22:41:09 3: SONOS1: Event: Received MusicServices-Event for Zone "Sonos_Kueche".
2019.11.09 22:43:10 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1573335670.48031 ~ 2019-11-09 22:41:10)... try to restart the process and connection...
2019.11.09 22:43:11 3: SONOS0: Disconnecting client and shutdown server...
2019.11.09 22:43:11 3: SONOS0: Trying to kill Sonos_Thread...
2019.11.09 22:43:11 3: SONOS0: Trying to kill IsAlive_Thread...
2019.11.09 22:43:11 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.11.09 22:43:11 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 09 November 2019, 23:05:23
Du kannst Deine Bilder einfach als Anhang einfügen.
Erweiterte Optionen ...
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 11 November 2019, 09:29:27
Zitat von: dantist am 09 November 2019, 22:50:49
danke für deine super ausführliche Antwort - ich bin nicht sicher, ob ich alles verstanden habe ;)

Ich schätze, dass ich selbst nicht alles verstanden habe in dieser Thematik, sonst hätte ich das Problem wohl schon gelöst oder zumindest an der richtigen Stelle platziert. ;) Irgendwie hängt es mit dem Sonos-Modul zusammen. Sobald das Sonos Device disabled wird, gibt es auch keine receive buffer errors mehr.

Zitat von: dantist am 09 November 2019, 22:50:49
Raspbian läuft bei mir schon auf Buster, die Hardware ist ein RPi 3 B+, der schafft etwa 300 MBit/s an der Netzwerkschnittstelle statt 100.

OK, ich dachte alle RPi Versionen, außer RPi 4 haben eine 100MBit-Netzschnittstelle. Deiner hat ja anscheinend auch schon eine 1GBit-Netzwerkschnittstelle.

Zitat von: dantist am 09 November 2019, 22:50:49
Habe das Sonos-Modul jetzt nochmal hinzugefügt, um dir aktuelle Logs und den Output der Shell-Befehle zeigen zu können.

Direkt nach FHEM-Start, das Modul läuft noch: https://i.imgur.com/FUBRwe6.png

Kurze Zeit später beendet sich der Prozess, dann sieht die Ausgabe so aus: https://i.imgur.com/dsWDBEL.png


Wie von Otto schon beschrieben, es gibt einige Services (bspw. TVHeadend oder Emby), die auch auf Port 1900 lauschen. Bei dir ist das nicht der Fall. Das ist schonmal gut. Du hast auf jeden Fall aber auch buffer receive errors und das ist nicht normal. Das ist genau das Problem, das ich auch habe. Ich kriege das allerdings nicht in den Griff. Habe diverse Sachen probiert, um die verschiedenen TCP/UDP-Buffer zu optimieren, siehe meinen zuvor verlinkten Github-Artikel. 

Wahrscheinlich müsste man das mit dem Sonos-Modulentwickler gemeinsam analysieren.

@Otto123 Kannst du mal den Output von "netstat -anus" posten? Evtl. hast du ja auch diese buffer receive errors... Man merkt davon erstmal nichts. Wie gesagt, mein netdata hat mich dazu mit Emails informiert. Nur deshalb bin ich auf das Thema aufmerksam geworden.

Ich kann auch nicht mit Sicherheit sagen, dass diese buffer receive errors wirklich zu dem Verhalten bei @dantist führen. Mein FHEM läuft ganz normal weiter.

Gruß Hoppel
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 11 November 2019, 12:19:05
gerne:
netstat -anus
IcmpMsg:
    InType0: 5847
    InType3: 104132
    OutType3: 94541
    OutType8: 79612
Udp:
    69810 packets received
    0 packets to unknown port received.
    46704 packet receive errors
    19521 packets sent
    RcvbufErrors: 46704
    IgnoredMulti: 6720
UdpLite:
IpExt:
    InMcastPkts: 41604
    OutMcastPkts: 19
    InBcastPkts: 15228
    OutBcastPkts: 741
    InOctets: 282553212
    OutOctets: 165414539
    InMcastOctets: 19574231
    OutMcastOctets: 3826
    InBcastOctets: 5878579
    OutBcastOctets: 94988
    InNoECTPkts: 1432097
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 11 November 2019, 17:36:00
Hallo Otto,

du hast auch "packet receive errors" und in der gleichen Menge "RcvbufErrors".

Meine Ausgabe sieht momentan wie folgt aus:

:~# netstat -anus
IcmpMsg:
    InType3: 23252
    OutType3: 23161
Udp:
    636435 packets received
    48 packets to unknown port received
    132972 packet receive errors
    411440 packets sent
    132972 receive buffer errors
    0 send buffer errors
    IgnoredMulti: 61323
UdpLite:
IpExt:
    InMcastPkts: 577973
    OutMcastPkts: 368468
    InBcastPkts: 83725
    OutBcastPkts: 2070
    InOctets: 21499684706
    OutOctets: 13568690530
    InMcastOctets: 234573936
    OutMcastOctets: 142540820
    InBcastOctets: 22349345
    OutBcastOctets: 480151
    InNoECTPkts: 44260954
    InECT0Pkts: 7590


Warum bei mir "receive buffer errors" und bei dir "RcvbufErrors" weiß ich nicht. Wahrscheinlich nutzt du ein anderes OS als ich (Debian Stretch).

Auf was für einer Hardware betreibst du FHEM? Wie viele Sonos Endgeräte hast du in Betrieb?

Bei mir sind es mittlerweile 8 insgesamt:

- 4 im Wohnzimmer (5.1) - 1x Beam, 1x Sub, 2x Symfonisk Tischleuchte,
- 2 im Schlafzimmer (Stereo), 2x Symfonisk Tischleuchte,
- 1 im Büro, 1x Sonos One,
- 1 in der Galerie, 1x Sonos One

Ich habe dieses Thema seit ich das Sonos Modul nutze. Meine Erkenntnis (Fakt) ist, dass sich mein System innerhalb kürzester Zeit selbständig heilt, sobald das Sonos Modul disabled ist. Aber wie gesagt, außer die Warning Emails von meinem netdata kann ich sonst keine Probleme an meinem System feststellen. Wenn ich das Modul deaktiviere, erhalte ich kurz im Anschluss von netdata eine Email, dass alles wieder ok ist.

Ansonsten ist mir noch folgendes aufgefallen:

- in Otto's Output steht "0 packets to unknown port received",
- in dantist's Output steht "12 packets to unknown port received",
- in meinem Output steht "48 packets to unknown port received".

Ich habe keine Ahnung, ob die UDP-Thematik überhaupt mit dantist's Problem in Verbindung zu bringen ist.

Ich weiß auch nicht, wie man das lösen bzw. besser analysieren könnte.

Evtl. hat hier ja noch jemand anderes eine Idee? Ich bin zu jeder tiefer gehenden Analyse bereit. ;)

Viele Grüße Hoppel
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 11 November 2019, 17:49:21
Ich habe 7 Sonos Geräte.
FHEM läuft derzeit auf Raspbian Jessie.
Ich habe keine Probleme. Außer wenn der Strom ausfällt und dann wiederkommt ist manchmal anschließend der eine oder andere Player disappeared. Das löse ich mit disable / enable

Gruß Otto
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 11 November 2019, 21:13:21
Ok, Fazit:

1. An der Performance von dantist's RPi sollte es also nicht liegen. Bei dir läuft es ja auch mit 7 Sonos Geräten.
2. ,,ignoredIPs/usedonlyIPs" hat dantist erfolglos ausprobiert (Oder?)
3. Andere Services, die ebenfalls auf Port 1900 lauschen, gibt es bei dantist nicht, wie oben auf dem ersten Screenshot zu sehen ist. Dort werden wie bei mir nur die beiden Perl-Einträge angezeigt.

Warum sind das eigentlich 2 Einträge?

Bei mir sieht das beispielsweise wie folgt aus:

~# netstat -unlp | grep ":1900"
udp   8389376      0 0.0.0.0:1900            0.0.0.0:*                           4704/perl
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           4704/perl


2 Perl Prozesse, die auf Port 1900 lauschen. Bei einem läuft der von mir definierte Receive Buffer voll...

Wenn ich mir das bei TVHeadend bzw. Emby ansehe, sehe im Output dieses Befehls immer genau ein Eintrag pro Service.

@Otto123 Kannst du nochmal deinen Output zeigen?

@Reinerlein Ist das so richtig, dass hier 2 Perl Prozesse auf Port 1900 agieren?

Viele Grüße Hoppel
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: Otto123 am 11 November 2019, 21:41:13
ähnlich wie bei Dir:
netstat -unlp | grep ":1900"
udp   163840      0 0.0.0.0:1900            0.0.0.0:*                           941/perl       
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           941/perl       
Titel: FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 12 November 2019, 06:19:06
Ok, das bestätigt nochmal, dass deine Recv-Q auch übergelaufen ist. Bei dir ist allerdings der Defaultwert für die Buffergröße konfiguriert. Den Buffer zu erhöhen bringt definitiv nix (siehe meine Analyse bei Github:  https://github.com/netdata/netdata/issues/6527 ).

Wie ist deine Meinung dazu, dass 2 Perl Prozesse auf Port 1900 lauschen?

Meiner Analyse nach ,,kämpfen" die verschiedenen UPnP-Prozesse um den Port 1900. Als bei mir früher noch alle 3 Services (FHEM/Sonos-Modul, TVHeadend und EmbyServer) unter der IP Adresse des Hosts verfügbar waren, war auch immer nur einer wirklich per UPnP verfügbar, auch wenn ich mehrere mit netstat sehen konnte. Das Verhalten war allerdings unterschiedlich. Wenn EmbyServer zuerst gestartet wurde, hat der Perl-Prozess nicht mehr funktioniert (alle Player waren disappeared) und netdata meldete mir, dass das System nun geheilt ist. Wenn TVHeadend vor Pearl gestartet wurde, lief der Receive Buffer weiter über und ich bekam Warning Emails von netdata. So richtig nachvollziehbar ist dieses UPnP-Verhalten für mich nicht.

Mit dem folgenden Befehl sieht man sehr schön, dass ausschließlich bei dem einen Perl-Prozess die Recv-Q vollläuft:

:~# netstat -unlp
Aktive Internetverbindungen (Nur Server)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
udp        0      0 0.0.0.0:31909           0.0.0.0:*                           17804/perl
udp        0      0 0.0.0.0:68              0.0.0.0:*                           2580/dhclient
udp        0      0 0.0.0.0:111             0.0.0.0:*                           2250/rpcbind
udp        0      0 172.17.0.1:123          0.0.0.0:*                           2884/ntpd
udp        0      0 10.11.11.11:123         0.0.0.0:*                           2884/ntpd
udp        0      0 127.0.0.1:123           0.0.0.0:*                           2884/ntpd
udp        0      0 0.0.0.0:123             0.0.0.0:*                           2884/ntpd
udp        0      0 172.17.255.255:137      0.0.0.0:*                           2728/nmbd
udp        0      0 172.17.0.1:137          0.0.0.0:*                           2728/nmbd
udp        0      0 10.11.11.255:137        0.0.0.0:*                           2728/nmbd
udp        0      0 10.11.11.11:137         0.0.0.0:*                           2728/nmbd
udp        0      0 0.0.0.0:137             0.0.0.0:*                           2728/nmbd
udp        0      0 172.17.255.255:138      0.0.0.0:*                           2728/nmbd
udp        0      0 172.17.0.1:138          0.0.0.0:*                           2728/nmbd
udp        0      0 10.11.11.255:138        0.0.0.0:*                           2728/nmbd
udp        0      0 10.11.11.11:138         0.0.0.0:*                           2728/nmbd
udp        0      0 0.0.0.0:138             0.0.0.0:*                           2728/nmbd
udp        0      0 0.0.0.0:730             0.0.0.0:*                           2250/rpcbind
udp   8390400      0 0.0.0.0:1900            0.0.0.0:*                           17804/perl
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           17804/perl
udp        0      0 10.11.11.11:5353        0.0.0.0:*                           2721/homebridge
udp        0      0 10.11.11.11:5353        0.0.0.0:*                           2722/homebridge
udp        0      0 10.11.11.11:5353        0.0.0.0:*                           2739/homebridge
udp        0      0 0.0.0.0:5353            0.0.0.0:*                           2263/avahi-daemon:
udp        0      0 0.0.0.0:7359            0.0.0.0:*                           15259/EmbyServer
udp        0      0 127.0.0.1:8125          0.0.0.0:*                           14584/netdata
udp        0      0 0.0.0.0:48213           0.0.0.0:*                           2263/avahi-daemon:
udp        0      0 0.0.0.0:56620           0.0.0.0:*                           10418/tvheadend
udp6       0      0 172.17.0.1:59104        :::*                                15416/java
udp6       0      0 :::111                  :::*                                2250/rpcbind
udp6       0      0 ::1:123                 :::*                                2884/ntpd
udp6       0      0 :::123                  :::*                                2884/ntpd
udp6       0      0 :::730                  :::*                                2250/rpcbind
udp6       0      0 :::3478                 :::*                                15416/java
udp6       0      0 :::10001                :::*                                15416/java
udp6       0      0 10.11.11.11:22480       :::*                                15416/java


Es wäre wirklich schön, wenn @Reinerlein sich dazu mal äußern könnte. ;)

Keine Ahnung, ob das nun die Ursache für das Verhalten bei @dantist ist. Ich schätze eher nicht, da dieses Verhalten bei mir, Otto und wahrscheinlich allen anderen dasselbe ist und in FHEM nicht zum Totalabsturz führt. Auch eine zu schwache Hardware ist meiner Ansicht nach ausgeschlossen.

Gruß Hoppel
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: t1me2die am 12 November 2019, 07:24:59
Zitat von: Otto123 am 11 November 2019, 17:49:21
Ich habe 7 Sonos Geräte.
FHEM läuft derzeit auf Raspbian Jessie.
Ich habe keine Probleme. Außer wenn der Strom ausfällt und dann wiederkommt ist manchmal anschließend der eine oder andere Player disappeared. Das löse ich mit disable / enable

Gruß Otto

Offtopic:
Das Problem habe ich auch, habe mir dazu folgenden Workaround gebaut (musst nur auf deine Sonos Geräte regexen ;) ):

define n_Sonos notify Sonos_Bad:.*|Sonos_Kueche:.*
{   if ($EVENT eq "initialized")
    {   fhem "defmod -temporary t_Sonos_Rescan at +00:01:00 set Sonos RescanNetwork"
    }
    elsif (($EVENT eq "closed") or ($EVENT eq "disappeared") or ($EVENT eq "disabled"))
    {   fhem "defmod -temporary t_Sonos_Rescan at +00:01:00 set Sonos RescanNetwork";
        fhem "attr Sonos disable 1 ;; sleep 10 ;; attr Sonos disable 0";
    }
}


Gruß
Mathze
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: hoppel118 am 12 November 2019, 08:53:06
@t1me2die Ich habe das Problem auch. Ich musste kürzlich den FI für das Obergeschoss umlegen. Mein Server hängt am FI vom Dachgeschoss. Anschließend waren alle Player disappeared. Nachdem ich einmal das Sonos Modul disabled und anschließend wieder enabled hatte, waren die Player wieder da.

Kannst du auch mal die Outputs der beiden folgenden Befehle posten?


netstat -unlp | grep ":1900"
netstat -anus


Danke für das Regex. Schöner wäre, wenn man das direkt im Modul-Code lösen könnte... ;)

Viele Grüße Hoppel

Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: dantist am 12 November 2019, 09:47:03
Zitat von: hoppel118 am 11 November 2019, 21:13:21
,,ignoredIPs/usedonlyIPs" hat dantist erfolglos ausprobiert (Oder?)

usedonlyIPs hat bei mir nicht funktioniert, richtig. Dazu möchte ich noch sagen, dass die Probleme vor einigen Wochen scheinbar grundlos angefangen haben, ohne dass ich irgendwas am Setup geändert habe. Anfangs hing sich FHEM komplett auf (Logfile wurde noch befüllt, aber Befehle kamen nicht mehr an und die Web-Oberfläche war tot). Inzwischen hat sich das Problem dahingehend verlagert, dass sich das Sonos-Modul nach kurzer Zeit selbst beendet. Ein Rollback auf eine etwas ältere Version des Moduls hat nicht geholfen.
Titel: Antw:FHEM reagiert nicht / sehr verzögert, wenn Sonos-Modul aktiv ist
Beitrag von: huhu am 18 Mai 2020, 11:30:45
Hallo zusammen,

ich würde das Thema gerne nochmal aufgreifen, da ich exakt die gleichen Freezer beobachte. Habt ihr eine Lösung oder Workaround herausgefunden?
Durch das Freezemon Tool sehe ich auch wann diese passieren:
2020.05.18 11:15:47 1: [Freezemon] myFreezemon: possible freeze starting at 11:15:24, delay is 23.812 possibly caused by: tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer)
2020.05.18 11:25:44 1: [Freezemon] myFreezemon: possible freeze starting at 11:25:24, delay is 20.766 possibly caused by: tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer) tmr-SONOSPLAYER_SimulateCurrentTrackPosition(Sonos_Wohnzimmer)


Interessant ist, dass dies ca. exakt alle 10Min passiert. usedonlyIPs hat leider keine Besserung gebracht.
Viele Grüße
huhu