fhem mit sonos im docker container Problem

FunkOdyssey · 13 Februar 2018, 12:16:25

Ich starte den Subprozess wie folgt:

#!/bin/bash
set -e
echo "Starte SONOS"
perl /opt/fhem/FHEM/00_SONOS.pm 4711 5 1

Ich habe auch ein wenig Output in STDOUT:

Code Auswählen

Starte SONOS 2018.02.13 10:19:33.469 1: SONOS0: /opt/fhem/FHEM/00_SONOS.pm is listening to Port 4711 2018.02.13 10:19:59.065 3: SONOS0: Connection accepted from ? d:48502 2018.02.13 10:20:09.071 3: SONOS0: Connection accepted from ? d:48664 2018.02.13 10:20:10.074 5: SONOS0: Received: 'SetData:Sonos:0:-:syn:192.168.0.224,192.168.0.201:192.168.0.200,192.168.0.211,192.168.0.216,192.168.0.110:0:Sonos_Kueche,Sonos_Wohnzimmer:RINCON_B8E937B7C36201400_MR,RINCON_B8E937B7C31001400_MR'

Und das mit verbose5. Ziemlich knapp, oder?
Irgendetwas mache ich hier falsch.

(1) Nun habe ich testweise das SONOS-Device in FHEM mit disable=1 deaktiviert. Es hat sich in keinen Logs etwas geändert.
(2) Aber kurz darauf stieg die CPU-Auslastung im Produktiv-FHEM-Container auf 100% (perl fhem.pl fhem.cfg).
(3) Dann habe ich das SONOS-Device wieder aktiviert (disable=0).
(4) Das Produktiv-FHEM hat sich wieder erholt.
(5) Aber der Container mit "perl 00_SONOS.pm 4711 3 1" geht danach auf 100% CPU-Last.
(6) Ich führe ein Container-Restart des Sonos-Container aus
(7) und alles ist wieder normal.

Irgendwie habe ich das Gefühl, dass sich FHEM und SubProzess in einer solchen Konstellation nicht richtig unterhalten.

Reinerlein · 13 Februar 2018, 12:31:40

Hi FunkOdyssey,

du musst auch noch am Sonos-Device Verbose auf 5 setzen. Die Angabe am Sonos-SubProzess ist nur für den initialen Loglevel zuständig.
Sorry, hätte ich auch früher schreiben können, habs nur selber übersehen...

Grüße
Reinerlein

FunkOdyssey · 13 Februar 2018, 14:59:53

Zitat von: Reinerlein am 13 Februar 2018, 12:31:40
du musst auch noch am Sonos-Device Verbose auf 5 setzen. Die Angabe am Sonos-SubProzess ist nur für den initialen Loglevel zuständig.
Sorry, hätte ich auch früher schreiben können, habs nur selber übersehen...

Macht doch nichts. Ich bin froh, dass du dich überhaupt mit mir beschäftigst.

Das Log ist wohl zu groß fürs CODE-Tag. Daher habe ich die Datei als Anhang beigefügt.

Reinerlein · 13 Februar 2018, 15:31:53

Hi FunkOdyssey,

da scheint ein Thread aus der vorherigen Verbindung noch übrig geblieben zu sein.

in deiner Zeitphase ab "13:21:46.541" dürfte niemals mehr der Thread 1 auftauchen (zu erkennen am SONOS1 nach dem Loglevel). Tut er aber...

Was genau passiert denn in den Zeilen vor dem Schnipsel hier:

Code Auswählen


attr Sonos disable 0 (100% CPU-Last)
====================================

2018.02.13 13:21:46.541 3: SONOS0: Connection accepted from ?d:58812

?

Dort müsste was von Threads stehen, die sich beenden... und nur noch Ausgaben der Ebene 0 auftauchen...

Grüße
Reinerlein

FunkOdyssey · 13 Februar 2018, 15:41:33

Zitat von: Reinerlein am 13 Februar 2018, 15:31:53
Hi FunkOdyssey, da scheint ein Thread aus der vorherigen Verbindung noch übrig geblieben zu sein.
in deiner Zeitphase ab "13:21:46.541" dürfte niemals mehr der Thread 1 auftauchen (zu erkennen am SONOS1 nach dem Loglevel). Tut er aber...

Das ich jetzt nicht wirklich verstanden. Sorry.

Zitat von: Reinerlein am 13 Februar 2018, 15:31:53
Was genau passiert denn in den Zeilen vor dem Schnipsel hier:
Code Auswählen Erweitern
attr Sonos disable 0 (100% CPU-Last) ==================================== 2018.02.13 13:21:46.541 3: SONOS0: Connection accepted from ?d:58812?

Dort müsste was von Threads stehen, die sich beenden... und nur noch Ausgaben der Ebene 0 auftauchen...

Hi, ich habe das Log nicht gekürzt, sondern einfach nur ein paar Leerzeilen mit der Überschrift eingefügt, um besser zu erkennen, was wann passiert ist. Es fehlt im Verlauf nicht eine Sekunde.

Als ich das "disable" gesetzt habe, ist NICHTS passiert.

Reinerlein · 13 Februar 2018, 16:10:32

Hi FunkOdyssey,

du hast sowas von Recht. Der Part, der beim disablen dem SubProzess bescheid sagen sollte, ist überhaupt noch nicht geschrieben. Soll heißen: fehlt noch $:-\$
Momentan kann man nur Fhem beenden/neustarten, dabei wird dem SubProzess sauber mitgeteilt, dass man jetzt verschwinden wird...

Ok, zum Testen.
Kannst du die Prozedur "SONOS_StopSubProcess" folgendermaßen anpassen (so komplett wie unten):

Code Auswählen


sub SONOS_StopSubProcess($) {
	my ($hash) = @_;
	
	RemoveInternalTimer($hash);
	
	# Wenn wir einen eigenen UPnP-Server gestartet haben, diesen hier auch wieder beenden, 
	# ansonsten nur die Verbindung kappen
	if ($SONOS_StartedOwnUPnPServer) {
		DevIo_SimpleWrite($hash, "shutdown\n", 2);
	} else {
		DevIo_SimpleWrite($hash, "disconnect\n", 2);
	}
	DevIo_CloseDev($hash);
	
	setReadingsVal($hash, "state", 'disabled', TimeNow());
	$hash->{STATE} = 'disabled';
	
	# Alle SonosPlayer-Devices disappearen
	for my $player (SONOS_getAllSonosplayerDevices()) {
		SONOS_readingsBeginUpdate($player);
		SONOS_readingsBulkUpdateIfChanged($player, 'presence', 'disappeared');
		SONOS_readingsBulkUpdateIfChanged($player, 'state', 'disappeared');
		SONOS_readingsBulkUpdateIfChanged($player, 'transportState', 'STOPPED');
		SONOS_readingsEndUpdate($player, 1);
		
		if (AttrVal($player->{NAME}, 'stateVariable', '') eq 'Presence') {
			$player->{STATE} = 'disappeared';
		}
	}
}

Mal schauen, was der SubProzess dann macht...

Grüße
Reinerlein

FunkOdyssey · 13 Februar 2018, 16:20:54

Oh, vielen Dank.
Ich mag es gar nicht ansprechen, aber wenn ich die 00_SONOS.pm bearbeite und speichere, so erscheint (ein ganz anderer) Fehler:

Code Auswählen

ERROR:
Too many arguments for main::SONOSPLAYER_SimulateCurrentTrackPosition at ./FHEM/00_SONOS.pm line 1570, near "$hash)" BEGIN not safe after errors--compilation aborted at ./FHEM/00_SONOS.pm line 2767.

Wäre es besser, die Datei außerhalb von FHEM zu bearbeiten?

Reinerlein · 13 Februar 2018, 16:45:58

Das wäre wohl besser. Ich weiß nicht, wie dieser Fehler zustandekommen kann. An der Stelle hast du ja nix verändert...

FunkOdyssey · 14 Februar 2018, 17:58:34

Wow, ist das schön. Das scheint zu funktionieren.

Ich habe die überarbeitete 00_SONOS.pm in beiden FHEM-Container abgelegt. Vermutlich hätte es im Sonos-Container gerreicht.

Folgende Varianten habe ich ausprobiert:
- Disable des SONOS-Device im (Produktiv-)FHEM
- Neustart (Produktiv-)FHEM

Und mit Erfolg. Ich konnte in STDOUT des Sonos-Containers erkennen, wie die Prozesse beendet wurden.

Jetzt werde ich über die Tage mal beobachten, wie sich die SubProzesse verhalten, wenn das FHEM unerwartet beendet wird.

Vielen Dank, Reinerlein.

FunkOdyssey · 14 Februar 2018, 20:08:16

Gerade festgestellt: Wenn ich den FHEM-Container über die Konsole neu starte, dann bin ich danach wieder auf 100%.

Kann man den SubProzessen nicht eine Art Heartbeat hinzufügen? So dass die autom. pausieren, wenn aus FHEM keine Rückmeldung kommt?

Reinerlein · 14 Februar 2018, 20:44:31

Hi FunkOdyssey,

ja, das hatte ich mir schon gedacht...

Aber du schießt doch auch nicht einfach den Fhem-Prozess ab, oder?
Den solltest du doch im Normalfall sauber beenden, damit auch deine Zustände der Devices gesichert wird, und alles dort weitergeht, wo es angehalten wurde.

Ich werde aber trotzdem mal schauen, ob/was ich da einbauen kann...

Grüße
Reinerlein

FunkOdyssey · 14 Februar 2018, 20:55:40

Leider passiert das in einer Docker-Umgebung relativ häufig.
Darf nicht - will ich auch nicht - mache ich aber leider immer wieder. Da fehlt mir noch die Docker-Erfahrung.
Offtopic: bei jeden ,,docker-compose up -d" wird ein Recreating des Containers durchgeführt. Und somit ein Neustart. Das muss ich noch in den Griff bekommen.

Reinerlein · 14 Februar 2018, 21:02:39

Hi,

bevor du ,,docker-compose up -d" aufrufst, musst du doch nur ein "stop" aufrufen, oder nicht?

FunkOdyssey · 14 Februar 2018, 22:11:29

Nee, das sollte keinen Unterschied machen.
Ich stelle gerade fest, dass folgender Aufruf kein Recreating durchführt.

Code Auswählen

docker-compose up -d --no-recreate

Reinerlein · 21 Februar 2018, 20:22:17

Hi FunkOdyssey,

kannst du nochmal einen Code zum Testen einfügen?

Am Ende der Input-Verarbeitung (ca. bei Zeile 9914):

Code Auswählen


if (defined($inp)) {
	# Abschließende Zeilenumbrüche abschnippeln
	$inp =~ s/[\r\n]*$//;
		 			
	# Consume and send evt. reply
	SONOS_Log undef, 5, "Received: '$inp'";
	SONOS_Client_ConsumeMessage($so, $inp);
}

noch einen Else-Fall anfügen:

Code Auswählen


if (defined($inp)) {
	# Abschließende Zeilenumbrüche abschnippeln
	$inp =~ s/[\r\n]*$//;
		 			
	# Consume and send evt. reply
	SONOS_Log undef, 5, "Received: '$inp'";
	SONOS_Client_ConsumeMessage($so, $inp);
} else {
	$SONOS_Client_Selector->remove($so);
}

Danke schon mal...

Grüße
Reinerlein