Sonos "Error: 500 read timeout at" im LogFile

[staengls]

Hallo!
Ich habe seit einigen Wochen eine Sonos-Box in meine Fhem Umgebung eingebunden. Es funktioniert eigentlich alles.
Wie ich dann wieder einmal in das Logfile geschaut habe, musste ich aber feststellen, dass ein Sonos Fehler das Log zumüllt. Er kommt ungefähr alle 1-5 Minuten...
Der Zeile lautet:

Loading device description failed with error: 500 read timeout at ./FHEM/00_SONOS.pm line 3747 thread 1.

Ich habe jetzt schon einiges gegoogelt und probiert. Kann das Problem aber leider nicht lösen. Hat jemand einen Hinweis für mich?

Mein Fhem läuft auf einem Pi.

LG
Stefan

[dev0]

Und eine Fehlermeldung mit einer IP Adresse taucht nicht auf?

[staengls]

Nein, keine IP Adresse. Schaut ungefähr so aus im Log

[dev0]

Ich gehe mal davon aus, dass Dein FHEM halbwegs aktuell ist. Wenn Sonos sonst funktioniert, dann könnte ein weiteres Gerät im Netz stören. Mit Wireshark oder tcpdump könnte man herausfinden ob es so ist.
Den Loglevel auf verbose 5 zu stellen könnte Dir vielleicht auch helfen...

[staengls]

Ja, FHEM ist uptodate.

Mit verbose 5 sieht es dann so aus:

2016.10.21 08:05:44 3: SONOS0: Connection accepted from localhost:41558
2016.10.21 08:05:44 5: SONOS0: Received: 'hello'
2016.10.21 08:05:44 5: SONOS0: Received: 'goaway'
2016.10.21 08:05:44 4: SONOS0: Got correct Answer from Subprocess...
Loading device description failed with error: 500 read timeout at ./FHEM/00_SONOS.pm line 3747 thread 1.
2016.10.21 08:05:53 4: SONOS2: IsAlive-Event UDN=RINCON_B8E937E6194201400_MR
2016.10.21 08:05:53 4: SONOS2: SONOS_Client_Data_Retreive(RINCON_B8E937E6194201400_MR, reading, location, ) -> http://192.168.1.121:1400/xml/device_description.xml
2016.10.21 08:05:53 5: SONOS2: Location: http://192.168.1.121:1400/xml/device_description.xml
2016.10.21 08:05:53 5: SONOS2: PingType: syn
2016.10.21 08:05:53 4: SONOS2: 192.168.1.121 is alive
Loading device description failed with error: 500 read timeout at ./FHEM/00_SONOS.pm line 3747 thread 1.
2016.10.21 08:06:16 3: SONOS0: Connection accepted from localhost:41574
2016.10.21 08:06:16 5: SONOS0: Received: 'hello'
2016.10.21 08:06:16 4: SONOS0: Got correct Answer from Subprocess...
2016.10.21 08:06:16 5: SONOS0: Received: 'goaway'
2016.10.21 08:06:23 4: SONOS2: IsAlive-Event UDN=RINCON_B8E937E6194201400_MR
2016.10.21 08:06:23 4: SONOS2: SONOS_Client_Data_Retreive(RINCON_B8E937E6194201400_MR, reading, location, ) -> http://192.168.1.121:1400/xml/device_description.xml
2016.10.21 08:06:23 5: SONOS2: Location: http://192.168.1.121:1400/xml/device_description.xml
2016.10.21 08:06:23 5: SONOS2: PingType: syn
2016.10.21 08:06:23 4: SONOS2: 192.168.1.121 is alive
Loading device description failed with error: 500 read timeout at ./FHEM/00_SONOS.pm line 3747 thread 1.

Da kann ich auch keinen Hinweis entdecken.
Wireshark habe ich mir zwar schon einmal angesehen, aber da kommt so viel daher bei dem ich mich nicht auskenne... Wonach müsste ich da suchen?

[dev0]

Du müßtest nach upnp traffic Ausschau halten, der in dem Moment aufläuft, in dem der Fehler aufgezeichnet wird.

'192.168.1.121' ist ein Sonos Gerät oder etwas Anderes?

[CQuadrat]

Hallo Zusammen,

ich muss auch schon länger eine ähnliche häufig auftretende Fehlermeldung beobachten:
https://forum.fhem.de/index.php/topic,10033.msg383750.html#msg383750

Ich habe mittlerweile leider nur herausfinden können, dass diese Meldungen nur autauchen, wenn mein Firmen-Notebook zuhause im Netz hängt.


Viele Grüße

Christoph

[staengls]

Ich habe zwar versucht mit dem WireShark etwas herauszufinden. War dann aber doch zu kompliziert für mich.
Ich habe daher empirisch mein Netz abgesteckt und geschaut wann der Fehler wieder auftritt.
Ich konnte dadurch immer mehr einschränken und weiß jetzt, dass der Fehler nur auftritt, wenn der HMLAN Adapter im Netz ist.

Habt ihr da noch eine Idee, was ich da jetzt machen kann?

@CQuadrat: Hast du auch einen HMLAN Adapter? Wenn ja, kannst du mal schauen ob das bei dir auch der Verursacher ist?

@dev0: Ja, die 192.168.1.121 ist die Sonos1

LG
Stefan

[staengls]

Ich habe heute noch ein paar Versuche gemacht. Nach einem Update der Sonos.pm und Sonosplayer.pm habe ich das Problem leider noch immer.
Interessant ist aber die Auswirkung der verbose-Einsellungen. Bei verbose 3 kommen ständig Meldungen dass die Connection acceptiert ist. Diese möchte ich aber nicht im 30 Sekunden-Takt in meinem Log stehen haben. Wieder zurückgestellt auf verbose 2 kommt die Meldung mit dem read timeout. Siehe Anhang.
Das ist doch eigenartig, oder? Wenn ich verbose kleiner stelle und dann eine Meldung auftaucht, die vorher nicht da ist...
Vielleicht hat doch noch jemand eine Idee dazu. Sonst muss ich die Sonos wieder aus dem System schmeißen. Möchte ich aber eigentlich auch nicht.

[Kurt77]

Wenn Sonos sonst funktioniert, dann könnte ein weiteres Gerät im Netz stören.

Und genau so ein 'störendes' Gerät habe ich. Wenn ich meinen Laptop einschalte, setzt die Sonos-Wiedergabe aus. Laufender Betrieb bzw. Ausschalten des Laptops macht keine Probleme.
Was aber tue ich jetzt gegen den Störenfried?
Danke und Gruß,
Kurt

[staengls]

Ich habe im Code jetzt in der Fehlerzeile ein try catch eingebaut, um das read timeout abzufangen. Jetzt habe ich zumindest kein zugemülltes Log mehr:

Code Auswählen Erweitern


eval {
$SONOS_Controlpoint = UPnP::ControlPoint->new(SearchPort => 0, SubscriptionPort => 0, SubscriptionURL => '/fhemmodule', MaxWait => 30, UsedOnlyIP => \%usedonlyIPs, IgnoreIP => \%ignoredIPs);
$SONOS_Search = $SONOS_Controlpoint->searchByType('urn:schemas-upnp-org:device:ZonePlayer:1', \&SONOS_Discover_Callback);
try{
$SONOS_Controlpoint->handle;
};
catch{
SONOS_Log undef, 2, "Error during UPnP-Handling: $@";
SONOS_StopControlPoint();
}


Vielleicht kann da mal ein "richtiger" Programmierer drüberschauen...

[iHome]

Zwar schon älterer Tread aber Fehlermeldung immer noch aktuell. Habe gleiche meldung welche auf das 00_SONOS.pm führt. Die IP davor ist jedoch die von meinem Samsung-TV. An diesem ist eine Sonos-Beam angeschlossen, wird jedoch separat von FHEM abgefragt?! Ob das ein Zusammenhang hat?

Code Auswählen Erweitern

Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.
Loading device description failed with error: 500 read timeout (Location: http://192.168.90.236:9197/dmr) at ./FHEM/00_SONOS.pm line 2432 thread 1.

Was den Port 9197 und /dmr angeht hat FHEM das automatisch ausgelesen...
Einschränkung konnte ich bisher keine feststellen sind halt nur die nervigen Logeinträge

[juemuc]

Hallo,

einfach ip über ignoredIPs am Sonos-Device ausschließen und schon hast Du Ruhe 

Viele Grüße
Jürgen