Sonos: Neue Version vom 20.6.2017

Begonnen von Reinerlein, 20 Juni 2017, 14:02:19

Vorheriges Thema - Nächstes Thema

zap

#45
Seit dem letzten Update schmiert bei mir das SONOS Modul regelmäßig ab. Eine Steuerung der Player ist danach nicht mehr möglich. Ich muss FHEM neu starten. Hier einige Logmeldungen dazu:


readingsUpdate(d_sonhome,MusicServicesList,{'223' => {'IconRoundURL' => 'http://sonos-logo.ws.sonos.com/57095/57095-72x72.png','ResolutionSubstitution' => undef,'ServiceType' => '57095','Name' => 'RauteMusik.FM','Resolution' => undef,'Capabilities' => '513','SMAPI' => 'https://sonos-smapi.rautemusik.fm/smapi','PromoText' => ' Erlebe dutzende ko

#
# Rest gekürzt

missed to call readingsBeginUpdate first.
2017.06.29 08:34:38 1: stacktrace:
2017.06.29 08:34:38 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9519)
2017.06.29 08:34:38 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1237)
2017.06.29 08:34:38 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.29 08:34:38 1:     main::CallFn                        called by fhem.pl (686)


Update: Ok, sehe gerade ich bin nicht der Einzige mit diesem Fehler. Dann warte ich mal ab.

2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

Fixel2012

Muss mich leider nochmals melden, in mein Log ist voll mit Meldungen obwohl verbose den Sonos Moduls auf 0 ist.

Komischerweise habe ich gar keine Probleme mit dem Modul, es läuft bei mir einwandfrei (es stürzt nichts ab und bleibt nichts hängen), allerdings habe ich die nervigen Log Einträge.


Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
2017.06.29 11:48:45 1: Perfmon: possible freeze starting at 11:48:44, delay is 1.857

Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
2017.06.29 12:48:46 1: Perfmon: possible freeze starting at 12:48:44, delay is 2.123
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.


Habe die Meldungen leider dauerhaft über den ganzen Tag verteilt.

Ist es möglich die Meldungen zu unterdrücken?

Danke schon mal!

Gruß,
Fixel
Fhem 5.8 auf Raspi 3, HMLAN und 868MHz CUL mit einigen Komponenten, Z-Wave Rollladenaktoren, Tablet UI, 433 MHz CUL mit Baumarktsteckdosen und Temp Sensoren, Amazon Echo, Echo Dot, 2x SONOS  play1, 1x SONOS Connect AMP,  presence, HUE, Lightify

DeeSPe

Zitat von: Fixel2012 am 29 Juni 2017, 13:57:47
Muss mich leider nochmals melden, in mein Log ist voll mit Meldungen obwohl verbose den Sonos Moduls auf 0 ist.

Komischerweise habe ich gar keine Probleme mit dem Modul, es läuft bei mir einwandfrei (es stürzt nichts ab und bleibt nichts hängen), allerdings habe ich die nervigen Log Einträge.


Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
2017.06.29 11:48:45 1: Perfmon: possible freeze starting at 11:48:44, delay is 1.857

Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
2017.06.29 12:48:46 1: Perfmon: possible freeze starting at 12:48:44, delay is 2.123
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4000 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4024 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4048 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4072 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4096 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4120 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4168 thread 1.
Renewal of subscription failed with error: 500 Can't connect to 192.168.1.24:1400 at ./FHEM/00_SONOS.pm line 4192 thread 1.


Habe die Meldungen leider dauerhaft über den ganzen Tag verteilt.

Ist es möglich die Meldungen zu unterdrücken?

Danke schon mal!

Gruß,
Fixel

Das Problem habe ich leider auch und bisher keine Möglichkeit gefunden das zu unterdrücken.
Die bei mir angemeckerte IP ist die IP meines Sonos-Master.

Gruß
Dan
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert, 98_serviced

Als kleine Unterstützung für meine Programmierungen könnt ihr mir gerne einen Kaffee spendieren: https://buymeacoff.ee/DeeSPe

Fixel2012

#48
Zitat von: DeeSPe am 29 Juni 2017, 14:45:31
Das Problem habe ich leider auch und bisher keine Möglichkeit gefunden das zu unterdrücken.
Die bei mir angemeckerte IP ist die IP meines Sonos-Master.

Gruß
Dan

Wie erkenne ich einen Sonos Master?

Bei mir ist es die IP meines ConnectAMP, den schalte ich mit einer Funksteckdose, weil der selbst im Leerlauf wärme produziert.

Da er die meiste zeit aus ist, ist es klar das Fhem den Player nicht erreichen kann. Vielleicht hört es auf wenn der Player wieder an ist...

EDIT: Nach einem Neustart des Sonos Moduls, ist der Master nun ein Player, der dauerhaft an ist. Ich hoffe die Fehlermeldungen sind somit weg.
Fhem 5.8 auf Raspi 3, HMLAN und 868MHz CUL mit einigen Komponenten, Z-Wave Rollladenaktoren, Tablet UI, 433 MHz CUL mit Baumarktsteckdosen und Temp Sensoren, Amazon Echo, Echo Dot, 2x SONOS  play1, 1x SONOS Connect AMP,  presence, HUE, Lightify

Lorenz

Zitat von: DeeSPe am 29 Juni 2017, 14:45:31
Das Problem habe ich leider auch und bisher keine Möglichkeit gefunden das zu unterdrücken.
Die bei mir angemeckerte IP ist die IP meines Sonos-Master.

Gruß
Dan
Ich hatte auch dieses Problem. Habe vorhin die Devices der Player gelöscht und neu anlegen lassen - damit sieht es momentan besser aus, allerdings noch keine Langzeiterfahrung.

Gruß Lorenz
. . . . . .
Fhem auf NUC7i3BNH, Raspberry Pi B und B+, Raspberry Pi 2 B, Peripherie: FB7490, 1-Wire, Homematic, FS20, Lampen, Briefkasten, Klingel, Sonos, GardenaSmart, Unifi, Gaszähler an GPIO, Stromzähler EFR SGM-C4, Heizung Buderus GBH 172, Alarmanlage EMA und BMA von Bosch

Nobby1805

Hallo Reiner,

nein, das Problem ist mit dem erweiterten Logging noch nicht wieder aufgetreten, aber schau dir mal folgende Sequenz an2017.06.29 17:48:23.491 0: SONOS0: Aufruf von ReadingsBeginUpdate RINCON_000E58C1DE0A01400_MR HASH(0x3288314) 2017-06-29 17:48:23
2017.06.29 17:48:23.493 0: SONOS0: Aufruf von ReadingsEndUpdate RINCON_000E58C1DE0A01400_MR HASH(0x3288314) 2017-06-29 17:48:23
2017.06.29 17:48:24.089 0: SONOS0: Aufgerufen BulkUpdateIfChanged HASH(0x3288314) numberOfTracks 48 numberOfTracks: 48

da kommt das Update nach dem EndUpdate ??

Gruß Norbert
FHEM-Featurelevel: 6.2   (fhem.pl:28227/2023-11-29) auf Windows 10 Pro mit Strawberry Perl 5.32.1.1-32bit
TabletUI: 2.7.15
IO: 2xHMLAN(0.965)|HMUSB2(0.967)

sTaN

Zitat von: sTaN am 25 Juni 2017, 21:17:56
Ich schließe mich auch mal den Fehlermeldungen an.
Nach heutigem FHEM Update erhalte ich auf der Startseite folgende Ausgabe:

Messages collected while initializing FHEM:
configfile: Usage: define readingsGroup +
Usage: define readingsGroup +
Usage: define readingsGroup +


Ansonsten folgende SONOS spezifische Fehlermeldungen:

2017.06.25 20:44:01 1: readingsUpdate(Sonos_Bad,currentStreamAudio,) missed to call readingsBeginUpdate first.
2017.06.25 20:44:01 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:44:01 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:44:01 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (1224)
2017.06.25 20:44:01 1: stacktrace:
2017.06.25 20:44:01 1: readingsUpdate(Sonos_Bad,currentTrackPositionSec,95) missed to call readingsBeginUpdate first.
2017.06.25 20:44:01 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:44:01 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:44:01 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (1224)
2017.06.25 20:44:01 1: stacktrace:
2017.06.25 20:44:01 1: readingsUpdate(Sonos_Bad,currentTrackPosition,0:01:35) missed to call readingsBeginUpdate first.
2017.06.25 20:44:01 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:44:01 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:44:01 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1237)
2017.06.25 20:44:01 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9519)
2017.06.25 20:44:01 1: stacktrace:
2017.06.25 20:44:01 1: readingsUpdate(Sonos_Bad,currentTrackURI,x-sonos-spotify:spotify%3atrack%3a788Fpm2mKElTdRnRPtzSgW?sid=9&flags=8224&sn=1) missed to call readingsBeginUpdate first.
2017.06.25 20:43:35 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:43:35 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:43:35 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1237)
2017.06.25 20:43:35 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9519)
2017.06.25 20:43:35 1: stacktrace:
2017.06.25 20:43:35 1: readingsUpdate(Sonos_Bad,currentStreamAudio,) missed to call readingsBeginUpdate first.
2017.06.25 20:43:35 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:43:35 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:43:35 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (1224)
2017.06.25 20:43:35 1: stacktrace:
2017.06.25 20:43:35 1: readingsUpdate(Sonos_Bad,currentTrackPositionSec,69) missed to call readingsBeginUpdate first.
2017.06.25 20:43:34 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:43:34 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:43:34 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (1224)
2017.06.25 20:43:34 1: stacktrace:
2017.06.25 20:43:34 1: readingsUpdate(Sonos_Bad,currentTrackPosition,0:01:09) missed to call readingsBeginUpdate first.
2017.06.25 20:43:34 1:     main::CallFn                        called by fhem.pl (686)
2017.06.25 20:43:34 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.25 20:43:34 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1237)
2017.06.25 20:43:34 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9519)
2017.06.25 20:43:34 1: stacktrace:
2017.06.25 20:43:34 1: readingsUpdate(Sonos_Bad,currentTrackURI,x-sonos-spotify:spotify%3atrack%3a788Fpm2mKElTdRnRPtzSgW?sid=9&flags=8224&sn=1) missed to call readingsBeginUpdate first.


Gleiche Meldungen bei meinen Sonos im Wohnzimmer und Schlafzimmer

EDIT: Ich schließe mich gleich mal inoma an. Auch ich habe meine Player über FHEM gelöscht und wollte sie über den autocreate neu anlegen lassen. Nachdem Löschen hängt FHEM mit folgendem Fehler im Logfile:

2017.06.25 21:19:11 1: PERL WARNING: Deep recursion on subroutine "main::SONOS_getSonosPlayerByUDN" at ./FHEM/00_SONOS.pm line 9870.
2017.06.25 21:19:11 1: PERL WARNING: Deep recursion on subroutine "main::SONOS_Log" at ./FHEM/00_SONOS.pm line 9619.


Gruß
sTaN

Nachdem ich nach den ganzen Fehlern, nochmals Sonos inkl. Player komplett aus der fhem.cfg entfernt hatte schien es zunächst zu funktionieren. Aber die letzten Tage haben sich die gleichen Fehlermeldungen wieder gehäuft und Zack die Player waren disapeared. Der Sonos selbst zeigte den status disconnected. Habe Sonos attribute disabled = 1 gesetzt und anschließend gelöscht. Nun erhalte ich folgenden Feher:

Can't call method "kill" on an undefined value at ./FHEM/00_SONOS.pm line 9960, <$client> line 5.

Wo finde ich den die alte Sonos.pm, die vor dem 20.06.2017 noch funktioniert hat? Reicht es, wenn ich die einfach zurück tausche?
Momentan ist die aktuele pm leider nutzlos für mich, was extrem schade ist. Würde auch gern noch mehr unterstützen aber weiß nicht wie.

LG sTaN
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

Nobby1805

Hallo Reiner,

so, jetzt ist das Problem unmittelbar nach einem Neustart von FHEM, ich hatte wieder Logs geändert, aufgetreten
Ich bin der Meinung, dass von beginUpdate bis endUpdate alles richtig aussieht , überall die selbe Hashadresse 2017.06.30 16:49:46.962 0: SONOS0: Aufruf 1255 von ReadingsBeginUpdate RINCON_000E58C1DE0A01400_MR HASH(0x328c8d4) 2017-06-30 16:49:46
2017.06.30 16:49:47.589 1: readingsUpdate(Sonos_Schlafzimmer,AlarmList,{'85' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '07:50:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'57' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '08:40:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '00:30:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'37' => {'Recurrence_Monday' => 1,'Repeat' => 0,'Recurrence_Thursday' => 1,'StartTime' => '06:28:00','Recurrence_Friday' => 1,'Recurrence_Wednesday' => 1,'Recurrence_Once' => 0,'Recurrence_Tuesday' => 1,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '02:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 0,'Volume' => '21'},'48' => {'Recurrence_Monday' => 1,'Repeat' => 0,'Recurrence_Thursday' => 1,'StartTime' => '08:56:00','Recurrence_Friday' => 1,'Recurrence_Wednesday' => 1,'Recurrence_Once' => 0,'Recurrence_Tuesday' => 1,'Recurrence_Sunday' => 1,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '00:45:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 1,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'83' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '07:00:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'38' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '06:45:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 0,'Volume' => '25'}}) missed to call readingsBeginUpdate first.
2017.06.30 16:49:47.590 1: stacktrace:
2017.06.30 16:49:47.590 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9560)
2017.06.30 16:49:47.590 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1242)
2017.06.30 16:49:47.591 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.30 16:49:47.591 1:     main::CallFn                        called by fhem.pl (686)
2017.06.30 16:49:47.599 0: SONOS0: Aufruf 9547 von BulkUpdateIfChanged HASH(0x328c8d4) AlarmList {'85' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '07:50:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'57' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '08:40:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '00:30:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'37' => {'Recurrence_Monday' => 1,'Repeat' => 0,'Recurrence_Thursday' => 1,'StartTime' => '06:28:00','Recurrence_Friday' => 1,'Recurrence_Wednesday' => 1,'Recurrence_Once' => 0,'Recurrence_Tuesday' => 1,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '02:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 0,'Volume' => '21'},'48' => {'Recurrence_Monday' => 1,'Repeat' => 0,'Recurrence_Thursday' => 1,'StartTime' => '08:56:00','Recurrence_Friday' => 1,'Recurrence_Wednesday' => 1,'Recurrence_Once' => 0,'Recurrence_Tuesday' => 1,'Recurrence_Sunday' => 1,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '00:45:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 1,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'83' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '07:00:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 1,'Volume' => '25'},'38' => {'Recurrence_Monday' => 0,'Repeat' => 0,'Recurrence_Thursday' => 0,'StartTime' => '06:45:00','Recurrence_Friday' => 0,'Recurrence_Wednesday' => 0,'Recurrence_Once' => 1,'Recurrence_Tuesday' => 0,'Recurrence_Sunday' => 0,'ProgramURI' => 'x-sonosapi-stream:s100198?sid=254&flags=32','IncludeLinkedZones' => '0','Duration' => '01:00:00','RoomUUID' => 'RINCON_000E58C1DE0A01400','Recurrence_Saturday' => 0,'Enabled' => '0','ProgramMetaData' => '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="R:0/0/0" parentID="R:0/0" restricted="true"><dc:title>1LIVE - Das junge Radio des WDR.</dc:title><upnp:class>object.item.audioItem.audioBroadcast</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">SA_RINCON65031_</desc></item></DIDL-Lite>','Shuffle' => 0,'Volume' => '25'}}
2017.06.30 16:49:47.601 1: readingsUpdate(Sonos_Schlafzimmer,AlarmListIDs,37,38,48,57,83,85) missed to call readingsBeginUpdate first.
2017.06.30 16:49:47.601 1: stacktrace:
2017.06.30 16:49:47.602 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9560)
2017.06.30 16:49:47.602 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1242)
2017.06.30 16:49:47.602 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.30 16:49:47.602 1:     main::CallFn                        called by fhem.pl (686)
2017.06.30 16:49:47.604 0: SONOS0: Aufruf 9547 von BulkUpdateIfChanged HASH(0x328c8d4) AlarmListIDs 37,38,48,57,83,85
2017.06.30 16:49:47.606 1: readingsUpdate(Sonos_Schlafzimmer,AlarmListVersion,RINCON_000E58A376D201400:144) missed to call readingsBeginUpdate first.
2017.06.30 16:49:47.606 1: stacktrace:
2017.06.30 16:49:47.606 1:     main::readingsBulkUpdate            called by ./FHEM/00_SONOS.pm (9560)
2017.06.30 16:49:47.607 1:     main::SONOS_readingsBulkUpdateIfChanged called by ./FHEM/00_SONOS.pm (1242)
2017.06.30 16:49:47.607 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.06.30 16:49:47.607 1:     main::CallFn                        called by fhem.pl (686)
2017.06.30 16:49:47.608 0: SONOS0: Aufruf 9547 von BulkUpdateIfChanged HASH(0x328c8d4) AlarmListVersion RINCON_000E58A376D201400:144
2017.06.30 16:49:47.612 1: PERL WARNING: Use of uninitialized value $tstmp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 1278.
2017.06.30 16:49:47.613 0: SONOS0: Aufruf 1271 von ReadingsEndUpdate RINCON_000E58C1DE0A01400_MR HASH(0x328c8d4)

Die vorletzte Zeile bzgl. der initialisierten Variablen $tstmp beim End-Update zeigt übrigens, dass der Eintrag .updateTimestamp im Hash wirklich fehlt was ja auch der Grund für die Fehlermeldung im BulkUpdate ist.
Wer löscht diesen Eintrag? (Außer wie es gewollt ist im EndUpdate) Leider schaffe ich es nicht, an diversen Stellen im Sonos-Modul den Wert zu loggen ... Perl war nie meine Lieblingssprache und wird es wohl auch nie werden

Gruß Nobby
FHEM-Featurelevel: 6.2   (fhem.pl:28227/2023-11-29) auf Windows 10 Pro mit Strawberry Perl 5.32.1.1-32bit
TabletUI: 2.7.15
IO: 2xHMLAN(0.965)|HMUSB2(0.967)

Nobby1805

Hallo Reiner,

mein Log hat es noch nicht gezeigt ... aber mir ist einen Idee gekommen ...#

Neuerdings werden ja auch im 21_SONOSPLAYER Updates gemacht ... und wenn so ein Update kommt während im 00_SONOS zwar das BeginUpdate aufgerufen wurde aber noch nicht alle Updates durchgeführt worden sind, dann setzt das EndUpdate im SONSOPLAYER die Marke zurück

Spätestens wenn mein Log dies nachweisen oder widerlegen kann melde ich mich wieder

Gruß Nobby
FHEM-Featurelevel: 6.2   (fhem.pl:28227/2023-11-29) auf Windows 10 Pro mit Strawberry Perl 5.32.1.1-32bit
TabletUI: 2.7.15
IO: 2xHMLAN(0.965)|HMUSB2(0.967)

Reinerlein

Hi Nobby,

das wäre dann möglich, wenn der Read-Prozess im Sonos.pm zwischen zwei (oder mehreren) TCP-Paketen unterbrochen werden würde. Eigentlich sende ich vom SubProzess aus alles in einem Rutsch (es wird erst gesammelt, und dann auf einen Schlag zum Senden freigegeben), sodass eigentlich genau keine Unterbrechung erfolgen sollte (Fhem läuft ja nur Singlethreaded)...

Ich verwende die sekündliche Aktualisierung ja auch :)
Und es gab auch vorher Updates, allerdings nur bei Befehlsaufrufen wie AddMember oder Wifi oder so.

Aber mal schauen, was rauskommt...

Grüße
Reiner

zap

Jetzt habe ich plötzlich auch die "Can't Connect" Meldungen. Würde es wieder funktionieren, wenn ich auf die alte Version zurück gehe oder gibt es da Kompatibilitätsprobleme?


Renewal of subscription failed with error: 500 Can't connect to 192.168.1.68:1400 at ./FHEM/00_SONOS.pm line 4144 thread 1
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

awel

#56
Zitat von: sTaN am 30 Juni 2017, 13:14:09
Nachdem ich nach den ganzen Fehlern, nochmals Sonos inkl. Player komplett aus der fhem.cfg entfernt hatte schien es zunächst zu funktionieren. Aber die letzten Tage haben sich die gleichen Fehlermeldungen wieder gehäuft und Zack die Player waren disapeared.

Ich habe dieselbe Erfahrung und SONOS inzwischen mehrfach neu installiert. Nach der letzten Neuinstallation der Sonos-Komponenten lief es zwei Tage fehlerfrei, dann hatten die Player ohne Änderungen an FHEM den Wert disapeared. Im LOG fand ich:
2017.06.30 22:00:10 3: dwd_getalerts return value: Keine Warnmeldung für die gesuchte Region vorhanden.
Out of memory!
Perl exited with active threads:
2 running and unjoined
1 finished and unjoined
0 running and detached
2017.06.30 22:41:36 1: localhost:4711 disconnected, waiting to reappear (Sonos)
2017.06.30 22:43:07 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2017.06.30 22:43:14 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
(dwd ist die GDS-Komponente für den Deutschen Wetterdienst)
Danach waren die Player bis zum Neustart von FHEM "disapeared". Die SONOS-Player laufen mit der aktuellen Firmware-Version 7.3 (Build 36442130), FHEM läuft auf einem RASPI.

Ich werde jetzt auch wieder auf die alten Versionen der FHEM-Sonos-Module zurücksetzen.
Wäre es bei den aktuellen Problemen mit SONOS nicht sinnvoller, wieder die alten, funktionierenden Versionen in die Verteilung einzubinden?

Vielen Dank für Deine Mühen, Reiner
vG Achim

Nachtrag / edit:
Gerade habe ich im GDS-Wiki folgenden Hinweis gefunden:
ZitatBekannte Probleme:
Das GDS-Modul wurde mittlerweile auf "non-blocking" umgeschrieben, führt aber dennoch hin und wieder zu Meldungen einzelner Nutzer, dass FHEM "einfriert" (nichts macht), während auf die Rückmeldung von, z. B., einem FTP-Transfer ("get [gdsName] conditionsmap" etc.) gewartet wird. Das kann bei Timing-kritischen Bestandteilen zu Problemen führen, weil Events nicht mitbekommen werden, die Ansteuerung von Geräten nicht funktioniert, etc.

Gibt es da evtl. Gemeinsamkeiten? Benutzen diejenigen, die Probleme mit den neuen SONOS-Versionen haben, alle auch das GDS-Modul oder ähnlich arbeitende Module?

Reinerlein

#57
Hi Achim,

das habe ich auch schon gedacht, bin mir aber nicht sicher wie dieses Nonblocking genau arbeitet...
Es würde im Sonos-Modul auf jeden Fall ein Problem geben, wenn der Read-Aufruf, der die Daten vom SubProzess entgegennimmt, unterbrochen werden würde. Dann wäre auch die Sache mit den fehlenden beginUpdates zumindest theoretisch erklärbar :)

Das Sonos-Modul ist durch die SubProzess-Abkopplung zunächst mal Nonblocking (in Bezug auf Fhem), muss aber in einem Rutsch die Daten an Fhem loswerden (sozusagen atomar wegen der Bulkupdate-Geschichte), also dort Blocking, aber eben nur die Datenübertragung (was bei einigen Readings aber auch echt viel werden kann :) ).

Ich schaue mal wegen Nonblocking, wie das arbeitet...

EDIT: Blocking arbeitet über die Telnet-Schnittstelle, sollte also nicht dazwischenfunken, da es erst verarbeitet wird, wenn die zentrale Schleife wieder dran ist (was erst *nach* meinem Read-Aufruf erfolgen wird)...

Grüße
Reiner

zap

Zitat von: Reinerlein am 01 Juli 2017, 11:02:08
Das Sonos-Modul ist durch die SubProzess-Abkopplung zunächst mal Nonblocking (in Bezug auf Fhem), muss aber in einem Rutsch die Daten an Fhem loswerden (sozusagen atomar wegen der Bulkupdate-Geschichte), also dort Blocking, aber eben nur die Datenübertragung (was bei einigen Readings aber auch echt viel werden kann :) ).

Ich hatte bei meinem Modul auch Timing-Probleme mit dem Datenaustausch zwischen SubProzess und FHEM. Gelöst habe ich es durch die Verwendung von Threads und shared memory Queues. Dadurch wird die Datenübertragung zwischen SubThread und FHEM asynchron. In FHEM wird in Read() dann auch immer nur eine bestimmte Menge Daten aus der Queue gelesen und die Reading aktualisiert. Der Rest folgt dann beim nächsten Read() Aufruf.
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

Nobby1805

#59
Hallo Reiner,

Zitat von: Nobby1805 am 30 Juni 2017, 18:09:20
... und wenn so ein Update kommt während im 00_SONOS zwar das BeginUpdate aufgerufen wurde aber noch nicht alle Updates durchgeführt worden sind, dann setzt das EndUpdate im SONSOPLAYER die Marke zurück
ich habe das mal weiter gedacht und bin dann auf die Idee gekommen, dass bei einem "dazwischen kommenden" Update ja beim BeginUpdate die Marke schon gesetzt sein muss ... also habe ich dort eine Prüfung eingebaut die dann eine Meldung ausgibt ...

Schon beim Neustart das FHEM kam diese Meldung das erste Mal ... und  seit dem schon mehrfach ...

Beim Nachschauen in der Source habe ich dann gefunden, dass die verwendeten SingleUpdates in die Sequenz BeginUpdate, BulkUpdate, EndUpdate aufgelöst werden und dadurch dann das Problem auslösen können2017.07.01 13:09:52.470 0: SONOS0: Aufruf 1272 ReadingsBeginUpdate undef HASH(0x24b792c) 2017-07-01 13:09:52
2017.07.01 13:09:52.476 1: readingsBeginUpdate(Sonos) doppelter Aufruf 2017-07-01 13:09:52
2017.07.01 13:09:52.476 1: stacktrace:
2017.07.01 13:09:52.477 1:     main::readingsBeginUpdate           called by fhem.pl (4491)
2017.07.01 13:09:52.477 1:     main::readingsSingleUpdate          called by ./FHEM/00_SONOS.pm (1742)
2017.07.01 13:09:52.477 1:     main::SONOS_Read                    called by fhem.pl (3412)
2017.07.01 13:09:52.477 1:     main::CallFn                        called by fhem.pl (686)
2017.07.01 13:09:52.488 0: SONOS0: Aufruf 1745 readingsSingleUpdate HASH(0x24b792c) LastProcessAnswer 2017-07-01 13:09:52
2017.07.01 13:09:52.636 0: SONOS0: Aufruf 1289 ReadingsEndUpdate   undef HASH(0x24b792c)


Bisher ist allerdings der andere Fehler in Folge noch nicht aufgetreten, aber warten wir mal ab ...

Gruß Nobby
FHEM-Featurelevel: 6.2   (fhem.pl:28227/2023-11-29) auf Windows 10 Pro mit Strawberry Perl 5.32.1.1-32bit
TabletUI: 2.7.15
IO: 2xHMLAN(0.965)|HMUSB2(0.967)