Sonos Probleme mit fhem Log

[rapster]

@rapsklaus, ist bei mir nicht so (z.B. mit Spotify als Quelle)

Wird eigtl bei mir nur beim SPDIF-Eingang angezeigt.
Was nutzt du als Quelle im Player?

[Reinerlein]

Hi Claudiu,

komisch... Ich kann mir das nur so erklären, dass es dort eine Zeitdifferenz gibt, und die Readings wieder gesetzt werden, nachdem ich sie entfernt habe.
Leider kann man in Fhem keine Readings als "nicht-speicherbar" markieren. Das würde das Problem im Keim lösen...
Ich denke, wir werden mit der jetzigen Situation leben müssen. Ich hoffe, dass es in den meisten Fällen für einen ruhigen Start sorgt...

@raspklaus: Du solltest sicherstellen, dass du eine Cover-Liefernde Quelle ausgewählt hast (Audio-Eingänge machen das z.B. nie). Des Weiteren musst du Reload beim Browser drücken, da es kein Longpoll für Weblinks gibt...

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

ja generell sehe ich so kleine Schönheitsfehler auch nicht als problematisch an, ob man das jetzt sieht oder nicht ändert erstmal nichts an der Funktion, genauso wie die ein oder andere warning im log/stdout.

Als interne Variablen lässt sich diese Value nicht speichern oder? Da hätten wir das Problem auch nicht..

Danke für deine Mühe, Gruß Claudiu

[Reinerlein]

Hi Claudiu,

von der Funktion her ist der Inhalt der Variablen ja ein Reading (mit der wichtigen Möglichkeit ein Notify darauf zu legen), und so sollte der Benutzer es auch verwenden können.
Es geht nur darum, dass nach einem Neustart sichergestellt ist, dass diese Felder keine Vorbelegung haben, da es sein könnte, dass der Zustand der Player sich während der Abwesenheit verändert hat...

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

OK, dann muss man das mit dieser Warnung eben so hinnehmen.

Allerdings scheint sich heute irgendwie ein Fehler in der Dev eingeschlichen zu haben.

Seit dem letzten Update wo diese Warnung beim restart/rereadcfg entfernt werden sollte erhalte ich nun schon zum 3. mal beim restart von Fhem diesen Fehler und das Sonos Modul startet nicht:

Code Auswählen Erweitern


Bind failed: Die Adresse wird bereits verwendet at FHEM/00_SONOS.pm line 5212.
2014.11.21 22:28:35.020 3: Opening Sonos device localhost:4711
2014.11.21 22:28:35.020 3: Can't connect to localhost:4711: Verbindungsaufbau abgelehnt


Das erste mal ist es vorhin bei der Version wo die Klammer fehlte passiert, kommt sehr sporadisch..

Gruß Claudiu

[Reinerlein]

Hi Claudiu,

ich hatte das "rereadcfg"-Event falsch verstanden. Ich dachte es käme *vor* dem eigentlichen Durchführen (wie z.B beim "Shutdown"-Event). Es kommt aber danach

Ich habe da jetzt wieder einiges umgebaut, und bei mir jetzt schon ein Weilchen am Laufen... Sieht erstmal gut aus...

Kannst du das nochmal bei dir testen?
Danke schon mal...

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

ich glaube es schaut jetzt gut aus 

habe zwar (nach dem ersten shutdown+restart in fhem) beim ersten restart nochmal das problem gehabt:

Code Auswählen Erweitern

root@fhem:~>service fhem restart
Restarting FHEM...
OLD Process ID: 3219
NEW Process ID: 3259
root@fhem:~>Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3545.
Current: "fhem.pl", gPath: "./FHEM"
Smartmatch is experimental at FHEM/00_SONOS.pm line 3545.
Current: "FHEM/00_SONOS.pm", gPath: ""
Bind failed: Die Adresse wird bereits verwendet at FHEM/00_SONOS.pm line 5226.

Allerdings habe ich jetz nochmal ~30 mal einen restart durchgeführt und alles ist sauber durchgelaufen.

Ich werde es beobachten 

Danke dir! Gruß Claudiu

EDIT:
Ganz vergessen, die presence Fehlermeldung beim 'rereadcfg' ist nun auch weg 

[rapster]

Hi Reinerlein,

habe grad ein fhem-update durchgeführt, und nach dem obligatorischen shutdown+restart ist sonos nicht mehr gestartet.

Ich hatte leider kein stdout offen, allerdings da anschließend keine Sonos PID zu finden war, gehe ich davon aus dass es sich wieder um das Port Problem handelte.

Lässt sich evtl. für debugging zwecke ein Log definieren in welches der Subprozess schreibt? Da ja dieses Problem anscheining sehr unregelmäßig auftritt muss man natürlich Glück haben dass man grad ein passendes Terminal offen hat um die stdout Ausgaben zu erhalten.

Gruß Claudiu

EDIT:
gerade eben eine *.cfg bearbeitet und anschließend 'shutdown+restart' durchgeführt, und wieder das Problem

Code Auswählen Erweitern

2014.11.22 14:22:58.361 1: Including ./FHEM/sonos.cfg
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3545.
Current: "fhem.pl", gPath: "./FHEM"
2014.11.22 14:22:58.533 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 1 Sekunde(n) darauf...
Smartmatch is experimental at FHEM/00_SONOS.pm line 3545.
Current: "FHEM/00_SONOS.pm", gPath: ""
Bind failed: Die Adresse wird bereits verwendet at FHEM/00_SONOS.pm line 5226.
2014.11.22 14:22:59.535 3: Opening Sonos device localhost:4711
2014.11.22 14:22:59.535 3: Can't connect to localhost:4711: Verbindungsaufbau abgelehnt


Evtl. tritt das nur auf wenn fhem schon eine weile läuft?

EDIT2:
Also bei mir lässt sich das reproduzieren indem ich fhem ein paar Minuten (2 - 4 sollten reichen) laufen lassen und anschließend ein 'shutdown+restart' ausführe.
Anschließend startet sonos nicht mehr aufgrund des Port Problems.
Ich habe mal das gesamt log ab einem shutdown+restart angehangen.

[Reinerlein]

Hi Claudiu,

irgendwie will der beendete Perl-Prozess bei dir den Port nicht wieder hergeben...
Ich habe den Port jetzt mal auf eine andere Art geschlossen (vorher stand da close, jetzt mache ich es mit shutdown). Vielleicht gehorcht er ja jetzt...

Bei mir geht ein shutdown+restart auf jeden Fall immer. Da gab es noch nie Probleme mit einem geblockten Port. Das hilft hier jetzt nur auch nix

Die Logausgabe (STDOUT) wird bei mir direkt im Fhem-Startskript in eine Datei umgeleitet, sodass ich immer nachschauen kann. Das sollte bei dir doch auch möglich sein, oder?
Das Skript kannst du sonst ja auch parametrisieren, dann kannst du es für Debug-Zwecke anders aufrufen.

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

ohhwee, das war ja mal wieder zu einfach um selbst draufzukommen, einfach stdout+stderr im initscript umzuleiten 

Aber das Problem ist leider gleich geblieben
Nach einem Shutdown+Restart wenn fhem schon eine weile läuft ist der Port noch belegt.

Code Auswählen Erweitern


Bind failed: Die Adresse wird bereits verwendet at FHEM/00_SONOS.pm line 5226.


Ich habe zum test auch die Waittime mal wieder auf 8 erhöht, hat leider nicht geholfen.

Gruß Claudiu

[rapster]

Vergessen zu sagen, ein rereadcfg funktioniert einwandfrei.

[Reinerlein]

Hi Claudiu,

der ist aber auch wirklich hartnäckig

Ich habe noch ein exit() dazugepackt, kannst du das noch mal probieren?

Danke schon mal...

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

sogar hartnäckiger als du denkst ...denn es geht leider immer noch nicht

Das komische ist allerdings wenn ich ein 'shutdown+restart' mache nachdem alles fertig geladen ist funktioniert das einwandrei.

Wenn ich allerdings mit dem 'shutdown+restart' warte bis das erste mal das hier geloggt wird (~60sec nach fhem start):

Code Auswählen Erweitern


2014.11.22 17:16:24 1: SONOS0: Connection accepted from localhost:45131


Erhalte ich den Bind failed error

Gruß Claudiu

[Reinerlein]

Hi Claudiu,

sorry für das gestochere, aber ich habe wirklich keine Idee, was der Grund sein könnte...

Ich habe jetzt noch den Selektor leer gemacht... Aber ob das hilft??
Irgendwie fühlt es sich so an, als würde irgendwas das Beenden und freigeben des Ports verhindern...

Grüße
Reinerlein

[rapster]

Hi Reinerlein,

leider nicht geholfen

Nachdem das Bind Problem aufgetreten ist, kann ich auch erst nach ~1min Sonos durch einen shutdown+restart zum starten überreden, derweil tritt das Problem dauerhaft weiter auf.

Wenn du irgendwas benötigst was evtl. helfen könnte der Sache auf die Spur zu kommen, gib bescheid.

Gruß Claudiu