Sonos Play1 soll TV-Sound abspielen und ggf Rückmeldung

Begonnen von aherby, 07 November 2014, 22:14:51

Vorheriges Thema - Nächstes Thema

aherby

Hallo,

ich versuche mich gerade an folgender Problematik:

Über einen Taster soll einen Play1 zum abspielen vom TV-Sound (von der Sonos Soundbar) gebracht werden.
Das geht ja über das Gruppieren von Play1 zur Soundbar. Aber wie frage ich ab ob die Soundbar gerade das "TV-Programm"
wiedergibt ? Wie lautet der Befehl um die Soundbar auf TV umzuschalten?
Und wie bekomme ich über die Speak-Funktion eine Rückmeldung, dass die Soundbar nicht aktiv auf die TV-Wiedergabe eingeschaltet ist?

Jemand eine Idee?

Danke

FHEM 6.0 auf Raspberry Pi 4b 4GB, RaspberryMatic auf Raspi3b mit Charly-Funkmodul, ZigeeBridge mt deCONZ... . Homematic mittels HMCCU, Sonos 3xS1, 1xS6 (Play5 in der 2te Generation), 1xS9 (Soundbar), 1x SonosSub
1-Wire® to I2C host interface with ESD mit DS18B/S20.

Reinerlein

Hallo aherby,

im Reading "currentTrackURI" sollte das erkennbar sein. Ich vermute, daß es mit "x-sonos-htastream:" beginnt...

Kannst du mir mal den Inhalt von "playerType" der PlayBar nennen, der fehlt mir noch im Code :-)
Es fehlt nämlich noch eine Rück-Aktivierung auf den TV-Eingang nach einem Speak...

Danke schon mal...
Reinerlein

Fennek

Hallo Reinerlein,

ich antworte mal.

Der playerType ist S9.

Grüße Andreas
FHEM Cubietruck mit 50GB SSD
HMLAN: TC,VD,DN,DIM,SW,SEC,TH
HUEBridge, HUEDevice:LCT,LLC
Sonos: 5xPL1,2xPB,2xSUB
iBeacon's

Reinerlein

Hi Andreas,

danke für die Info. Hat die Playbar noch andere Hardware-Eingänge ausser dem SPDIF, oder ist das der einzigste?

Danke schon mal für die Info...
Reinerlein

Fennek

Hi Reinerlein,

nein die Playbar hat nur SPDIF als Eingang, leider.

Grüße
FHEM Cubietruck mit 50GB SSD
HMLAN: TC,VD,DN,DIM,SW,SEC,TH
HUEBridge, HUEDevice:LCT,LLC
Sonos: 5xPL1,2xPB,2xSUB
iBeacon's

aherby

Hallo Reinerlein, hallo Andreas,

sorry ich war mit der Zeit etwas knapp und daher hier nicht anwesend.

Wie Andreas schon geschrieben hat ist der PlayerTyp : S9
und leider hat die Sonos Playbar nur einen optischen Eingang.
Wenn ich die Tage die Multimedia-Steuerung /-Versorgung ändere
muss ich mal schauen ob noch ein optischer Switch vor die Playbar kommt.
Dummerweise ist dieser so konstruiert, dass er nur Töne ,,weiterleitet"
wenn der Switch mit Strom versorgt ist. Aber naja von nichts kommt nicht.

Kann ich noch irgendwie unterstützen?

Gruß
FHEM 6.0 auf Raspberry Pi 4b 4GB, RaspberryMatic auf Raspi3b mit Charly-Funkmodul, ZigeeBridge mt deCONZ... . Homematic mittels HMCCU, Sonos 3xS1, 1xS6 (Play5 in der 2te Generation), 1xS9 (Soundbar), 1x SonosSub
1-Wire® to I2C host interface with ESD mit DS18B/S20.

Reinerlein

Hallo aherby,

naja, ein Teil deiner Frage ist ja beantwortet: Du erkennst das am "x-sonos-htastream:", ob die Playbar den TV-Eingang wiedergibt.

Ich baue jetzt noch ein, dass man auch auf den Eingang mit Fhem umschalten kann... Da fehlte mir ja noch die Kennung für...

Grüße
Reinerlein

rapster

#7
Hallo Reinerlein,

schonmal ein dickes Danke von mir im vorraus für die Einbindung des TV Kanals der Playbar. (Rückschaltung nach durchsage)

Falls du hierzu noch irgend etwas benötigst, bitte bescheid geben, das Feature vermisse ich dringend  ;)


Gruß Claudiu


EDIT:
Habe gesehen du hast in der DEV-Version bereits den SPDIF Eingang eingebaut, diese schmiert bei mir leider nur direkt nach dem Start mit dieser Fehlermeldung ab  :-\
root@fhem:~>Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 167, <$fh> line 3.
Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 168, <$fh> line 3.
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3410.
Current: "fhem.pl", gPath: "./FHEM"
Smartmatch is experimental at FHEM/00_SONOS.pm line 3410.
Current: "FHEM/00_SONOS.pm", gPath: ""
2014.11.17 00:37:13 1: SONOS0: FHEM/00_SONOS.pm is listening to Port 4711
2014.11.17 00:37:20 1: SONOS0: Connection accepted from localhost:55691
2014.11.17 00:37:22 3: SONOS1: UPnP-Thread gestartet.
Odd number of elements in hash assignment at FHEM/lib/UPnP/ControlPoint.pm line 30, <$client> line 6.
2014.11.17 00:37:22 1: SONOS2: Restore-Thread gestartet. Warte auf Arbeit...
2014.11.17 00:37:22 2: SONOS1: Discover Sonosplayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR' is already defined and will only be updated
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Bad' is now updated
2014.11.17 00:37:22 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000235" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000236" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000237" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000238" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000239" and Timeout="86400s"
2014.11.17 00:37:22 3: SONOS1: Discover: End of discover-event for "Bad".
2014.11.17 00:37:22 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR' is already defined and will only be updated
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
2014.11.17 00:37:22 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000198" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000199" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000200" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000201" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000202" and Timeout="86400s"
2014.11.17 00:37:22 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
2014.11.17 00:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 00:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2014.11.17 00:37:22 2: SONOS1: Discover Sonosplayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR' is already defined and will only be updated
2014.11.17 00:37:22 2: SONOS1: SonosPlayer 'Kueche' is now updated
2014.11.17 00:37:22 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000192" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000193" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000194" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000195" and Timeout="86400s"
2014.11.17 00:37:22 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000196" and Timeout="86400s"
2014.11.17 00:37:22 3: SONOS1: Discover: End of discover-event for "Kueche".
2014.11.17 00:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
2014.11.17 00:37:22 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2014.11.17 00:37:22 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:22 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:22 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Kueche".
2014.11.17 00:37:23 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Bad".
2014.11.17 00:37:23 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 00:37:23 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Schlafzimmer".
Wide character in send at FHEM/00_SONOS.pm line 5128, <$client> line 6.
Perl exited with active threads:
        2 running and unjoined
        0 finished and unjoined
        0 running and detached

Reinerlein

Hallo Claudiu,

da hast du noch nicht ganz den letzten Stand ;D
Ich hatte die Dev-Version im anderem Thread bekannt gegeben, und dort auch gleich ein paar Fehlermeldungen eingefangen, und mittlerweile auch bereits korrigiert.
Z.B. ist genau das wide-character-Problem behoben, dass immer kam, wenn ein Titel einen Umlaut enthielt...

Probier mal die aktuellste Version.

Mit

update all http://fhem.lmsoft.de/sonos_dev/controls_sonos.txt
aktualisieren.

Grüße
Reinerlein

rapster

 ;D Das hat sich ja dann tatsächlich irgendwie überschnitten, vorhin zwar erst das update auf dev ausprobiert (mit dem selben Befehl), aber jetzt hat es geklappt!

Auch die Rückschaltung auf SPDIF funtkioniert 1A, und das log ist sauber!  8)

Danke für deine Mühe!

Gruß Claudiu

Reinerlein

Hi Claudiu,

schön, dann kann ich das mit dem SPDIF Rückschalten als getestet ansehen.
Kannst du bitte noch kurz versuchen, auf einem anderen Player den TV-Ton wiederzugeben?

set <SONOSPLAYER> PlayURI <FHEMPLAYBARNAME>

Dann wäre das auch erledigt. Ich habe diese Komponenten ja leider nicht zur Hand...
Da sollte dann auch angezeigt werden, dass die Wiedergabe von einem Eingang eines anderen Players geliefert wird.

Danke schon mal.

Grüße
Reinerlein

rapster

#11
Hi Reinerlein,

Das hat leider nicht funktioniert :-(
Wenn die Playbar auf SPDIF läuft und ich den Befehl absetze, wird lediglich auf dem anderen Player der momentan ausgewählte Titel von der Playlist abgespielt.

Im stdout Log erhalte ich dabei folgendes nach "set Sonos_Bad PlayURI Sonos_Kueche" (Sonos_Bad = Play1, Sonos_Kueche = Playbar aktuell auf SPDIF-Eingang):
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.17 02:46:01 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 02:46:01 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2014.11.17 02:46:02 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 02:46:02 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".


Falls ich hier noch was testen kann gib bescheid.

Gruß Claudiu


EDIT:
Ich sehe grad das Problem: Wide character in send at FHEM/00_SONOS.pm line 5128, <$client> line 17.
Perl exited with active threads:
        2 running and unjoined
        0 finished and unjoined
        0 running and detached

ist leider auch noch nicht behoben  :-\  (dann war ich vorhin doch schon auf der aktuellen dev)

Habe grad extra nochmal meine Playlist von vorhin durchgeklickt, und sobald ich den Titel Elastic Heart - From "The Hunger Games: Catching Fire"/Soundtrack abspiele, schmiert der Perl Prozess direkt ab.

Das Fhem-Log wird anschließend hiermit geflutet:
2014.11.17 03:04:07.213 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.213 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.213 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.213 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.


Nachdem ich einen anderen Titel auf dem Player auswähle und ein "shutdown restart" mache funktioniert erstmal alles wieder.

Mitch

Habe gerade einen Update auf Sonos Dev gemacht und nun wird mein Log auch geflutet mit
SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.

Was kann ich da machen?
FHEM im Proxmox Container

Reinerlein

Hallo Claudiu, hallo Mitch,

ich habe gerade vor ein paar Minuten eine Aktualisierung des Dev-Bereichs durchgeführt. Diese Wide-Character bringen mich noch zur Verzweiflung :-[

Jetzt sollte das (mit Glück) durch sein. Ich konnte das mit dem Catching-Fire Titel dank Spotify nachvollziehen.
Bei mir ging das auch nicht, weiss aber nicht genau, an welchem Sonderzeichen es nun gescheitert war.
Jetzt geht es bei mir. Es kann aber sein, dass bei anderen die Umlaute nicht sauber angezeigt werden. Diese bitte melden.

@Claudiu: Starte bitte mal die Wiedergabe des TV-Tons auf einem anderen Player mit dem Original-Controller, und sende mir mal das komplette Listing (mittels "list Sonos_Bad" z.B.) des entsprechenden Sonos-Devices zu. Irgendwas matcht da meine regulären Ausdrücke nicht richtig...
Danke schon mal

Grüße
Reinerlein

Mitch

Jetzt scheinen die Fehlermeldungen weg zu sein, Danke.
FHEM im Proxmox Container

rapster

Hi Reinerlein,

list Sonos_Bad (Gruppiert mit Playbar auf Channel TV/SPDIF:
Internals:
   CFGFN      ./FHEM/sonos.cfg
   CHANGED
   DEF        RINCON_000E58C74E4801400_MR
   NAME       Sonos_Bad
   NR         352
   STATE      PLAYING =>  'Gruppenwiedergabe' vom Album 'Kueche'
   TYPE       SONOSPLAYER
   UDN        RINCON_000E58C74E4801400_MR
   Readings:
     2014-11-17 00:42:47   AlarmRunning    0
     2014-11-17 15:00:58   AlarmRunningID
     2014-11-17 00:42:45   Balance         0
     2014-11-17 00:42:48   Bass            -1
     2014-11-17 07:37:29   CrossfadeMode   0
     2014-11-17 00:42:48   DailyIndexRefreshTime 04:00:00
     2014-11-17 00:42:47   HeadphoneConnected 0
     2014-11-17 00:42:48   Loudness        1
     2014-11-17 00:42:47   Mute            0
     2014-11-17 07:37:29   Repeat          0
     2014-11-17 07:37:29   Shuffle         0
     2014-11-17 00:42:47   SleepTimer      off
     2014-11-17 00:55:44   SleepTimerVersion 0
     2014-11-17 00:42:48   Treble          1
     2014-11-17 08:05:06   Volume          8
     2014-11-17 15:19:40   ZoneGroupID     RINCON_000E58B7AF1401400:__
     2014-11-17 15:19:40   ZonePlayerUUIDsInGroup RINCON_000E58B7AF1401400,RINCON_000E58C74E4801400
     2014-11-17 15:19:40   currentAlbum    Kueche
     2014-11-17 15:19:40   currentAlbumArtURI ./www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png
     2014-11-17 15:19:40   currentAlbumArtist PLAYING
     2014-11-17 15:00:58   currentArtist
     2014-11-17 15:19:40   currentNormalAudio 1
     2014-11-17 15:00:58   currentOriginalTrackNumber
     2014-11-17 15:19:40   currentSender
     2014-11-17 15:00:58   currentSenderCurrent
     2014-11-17 15:00:58   currentSenderInfo
     2014-11-17 15:19:40   currentStreamAudio
     2014-11-17 15:19:40   currentTitle    Gruppenwiedergabe
     2014-11-17 07:37:29   currentTrack    1
     2014-11-17 15:19:40   currentTrackDuration
     2014-11-17 15:19:40   currentTrackURI x-rincon:RINCON_000E58B7AF1401400
     2014-11-17 15:00:56   fieldType
     2014-11-17 15:19:40   infoSummarize1   'Gruppenwiedergabe' vom Album 'Kueche'
     2014-11-17 15:19:40   infoSummarize2  PLAYING =>  'Gruppenwiedergabe' vom Album 'Kueche'
     2014-11-17 08:05:06   infoSummarize3  Lautstaerke: 8 ~ Ton An ~ Balance: Mitte ~ Kein Kopfhoerer
     2014-11-17 15:00:58   infoSummarize4
     2014-11-17 00:42:45   location        http://192.168.1.150:1400/xml/device_description.xml
     2014-11-17 15:00:58   nextAlbum
     2014-11-17 07:37:29   nextAlbumArtURI ./www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png
     2014-11-17 15:00:58   nextAlbumArtist
     2014-11-17 15:00:58   nextArtist
     2014-11-17 15:00:58   nextOriginalTrackNumber
     2014-11-17 15:00:58   nextTitle
     2014-11-17 15:00:58   nextTrackDuration
     2014-11-17 15:19:40   nextTrackURI
     2014-11-17 15:19:40   numberOfTracks  1
     2014-11-17 00:42:45   playerType      S1
     2014-11-17 15:00:56   presence        appeared
     2014-11-17 00:42:48   roomIcon        bathroom
     2014-11-17 00:42:45   roomName        Bad
     2014-11-17 00:42:45   saveRoomName    Bad
     2014-11-17 00:42:45   serialNum       00-0E-58-C7-4E-48:C
     2014-11-17 00:42:45   softwareRevision 5.2
     2014-11-17 15:19:40   state           PLAYING =>  'Gruppenwiedergabe' vom Album 'Kueche'
     2014-11-17 15:19:40   transportState  PLAYING
Attributes:
   generateInfoSummarize1 <NormalAudio><Artist prefix="(" suffix=")"/><Title prefix=" '" suffix="'" ifempty="[Keine Musikdatei]"/><Album prefix=" vom Album '" suffix="'"/></NormalAudio> <StreamAudio><Sender suffix=":"/><SenderCurrent prefix=" '" suffix="' -"/><SenderInfo prefix=" "/></StreamAudio>
   generateInfoSummarize2 <TransportState/><InfoSummarize1 prefix=" => "/>
   generateInfoSummarize3 <Volume prefix="Lautstaerke: "/><Mute instead=" ~ Kein Ton" ifempty=" ~ Ton An" emptyval="0"/> ~ Balance: <Balance ifempty="Mitte" emptyval="0"/><HeadphoneConnected instead=" ~ Kopfhoerer aktiv" ifempty=" ~ Kein Kopfhoerer" emptyval="0"/>
   getAlarms  1
   group      Bad
   icon       icoSONOSPLAYER_icon-S1.png
   minVolume  0
   model      Sonos_S1
   room       Sonos
   stateVariable InfoSummarize2
   webCmd     Play:Pause:Previous:Next:VolumeD:VolumeU:MuteT


list Sonos_Kueche (Playbar im Eingang SPDIF):
Internals:
   CFGFN      ./FHEM/sonos.cfg
   DEF        RINCON_000E58B7AF1401400_MR
   NAME       Sonos_Kueche
   NR         346
   STATE      PLAYING =>  'SPDIF-Wiedergabe' vom Album 'Kueche'
   TYPE       SONOSPLAYER
   UDN        RINCON_000E58B7AF1401400_MR
   Readings:
     2014-11-17 00:42:48   AlarmRunning    0
     2014-11-17 15:00:56   AlarmRunningID
     2014-11-17 00:42:47   Balance         0
     2014-11-17 00:42:48   Bass            1
     2014-11-17 00:42:48   CrossfadeMode   0
     2014-11-17 00:42:48   DailyIndexRefreshTime 04:00:00
     2014-11-17 00:42:48   HeadphoneConnected 0
     2014-11-17 00:42:48   Loudness        1
     2014-11-17 02:39:21   Mute            0
     2014-11-17 00:42:48   Repeat          0
     2014-11-17 00:42:48   Shuffle         0
     2014-11-17 00:42:48   SleepTimer      off
     2014-11-17 00:55:45   SleepTimerVersion 0
     2014-11-17 00:42:48   Treble          0
     2014-11-17 02:28:45   Volume          13
     2014-11-17 10:40:28   ZoneGroupID     RINCON_000E58B7AF1401400:__
     2014-11-17 15:19:40   ZoneGroupName   Kueche + 1
     2014-11-17 15:19:40   ZonePlayerUUIDsInGroup RINCON_000E58B7AF1401400,RINCON_000E58C74E4801400
     2014-11-17 15:18:08   currentAlbum    Kueche
     2014-11-17 01:02:53   currentAlbumArtURI ./www/images/default/SONOSPLAYER/Sonos_Kueche_AlbumArt.png
     2014-11-17 15:18:08   currentAlbumArtist PLAYING
     2014-11-17 15:18:08   currentArtist
     2014-11-17 00:42:48   currentNormalAudio 1
     2014-11-17 15:00:56   currentOriginalTrackNumber
     2014-11-17 15:00:56   currentSender
     2014-11-17 15:00:56   currentSenderCurrent
     2014-11-17 15:00:56   currentSenderInfo
     2014-11-17 15:00:56   currentStreamAudio
     2014-11-17 15:18:08   currentTitle    SPDIF-Wiedergabe
     2014-11-17 00:42:48   currentTrack    1
     2014-11-17 15:18:08   currentTrackDuration
     2014-11-17 15:18:08   currentTrackURI x-sonos-htastream:RINCON_000E58B7AF1401400:spdif
     2014-11-17 15:00:55   fieldType
     2014-11-17 15:18:08   infoSummarize1   'SPDIF-Wiedergabe' vom Album 'Kueche'
     2014-11-17 15:18:08   infoSummarize2  PLAYING =>  'SPDIF-Wiedergabe' vom Album 'Kueche'
     2014-11-17 02:39:21   infoSummarize3  Lautstaerke: 13 ~ Ton An ~ Balance: Mitte ~ Kein Kopfhoerer
     2014-11-17 15:00:56   infoSummarize4
     2014-11-17 00:42:47   location        http://192.168.1.149:1400/xml/device_description.xml
     2014-11-17 15:00:56   nextAlbum
     2014-11-17 01:02:53   nextAlbumArtURI ./www/images/default/SONOSPLAYER/Sonos_Kueche_NextAlbumArt.png
     2014-11-17 15:00:56   nextAlbumArtist
     2014-11-17 15:00:56   nextArtist
     2014-11-17 15:00:56   nextOriginalTrackNumber
     2014-11-17 15:00:56   nextTitle
     2014-11-17 15:00:56   nextTrackDuration
     2014-11-17 15:00:56   nextTrackURI
     2014-11-17 01:02:53   numberOfTracks  1
     2014-11-17 00:42:47   playerType      S9
     2014-11-17 15:00:55   presence        appeared
     2014-11-17 00:42:48   roomIcon        kitchen
     2014-11-17 00:42:47   roomName        Kueche
     2014-11-17 00:42:47   saveRoomName    Kueche
     2014-11-17 00:42:47   serialNum       00-0E-58-B7-AF-14:7
     2014-11-17 00:42:47   softwareRevision 5.2
     2014-11-17 15:18:08   state           PLAYING =>  'SPDIF-Wiedergabe' vom Album 'Kueche'
     2014-11-17 15:18:08   transportState  PLAYING
Attributes:
   generateInfoSummarize1 <NormalAudio><Artist prefix="(" suffix=")"/><Title prefix=" '" suffix="'" ifempty="[Keine Musikdatei]"/><Album prefix=" vom Album '" suffix="'"/></NormalAudio> <StreamAudio><Sender suffix=":"/><SenderCurrent prefix=" '" suffix="' -"/><SenderInfo prefix=" "/></StreamAudio>
   generateInfoSummarize2 <TransportState/><InfoSummarize1 prefix=" => "/>
   generateInfoSummarize3 <Volume prefix="Lautstaerke: "/><Mute instead=" ~ Kein Ton" ifempty=" ~ Ton An" emptyval="0"/> ~ Balance: <Balance ifempty="Mitte" emptyval="0"/><HeadphoneConnected instead=" ~ Kopfhoerer aktiv" ifempty=" ~ Kein Kopfhoerer" emptyval="0"/>
   getAlarms  1
   group      Kueche
   icon       icoSONOSPLAYER_icon-S9.png
   minVolume  0
   model      Sonos_S9
   room       Sonos
   stateVariable InfoSummarize2
   webCmd     Play:Pause:Previous:Next:VolumeD:VolumeU:MuteT


Bin grad nicht zuhause, d.H. der Eingang TV/SPDIF ist zwar gewählt, der Fernseher spielt allerdings grad nichts ab (denke sollte aber an den Readings nicht ändern?)
Ansonsten kann ich heute Abend gerne nochmal nachschauen.

Und Catching Fire wird jetzt auch sauber abgespielt, Danke Dir!  ;D

Reinerlein

Hi Claudiu,

das sieht (leider) alles so aus, wie ich es erwarten würde.

Kannst du mal den LogLevel des Sonos-Moduls (am Sonos-Device) auf 5 stellen, und die Konsolenausgabe posten, die du erhältst, wenn du folgendes bei nicht gruppierten Playern ausführst:

set Sonos_Bad PlayURI Sonos_Kueche

Es ist dabei egal, was die Playbar gerade macht, das sollte immer gehen (Man kann ja den TV-Ton woanders hören, auch wenn die Playbar still ist oder was anderes wiedergibt :-)
Ich interessiere mich für etwaige Fehlermeldungen nach Ausführung der obigen Anweisung. Irgendwas muss ihn stören, und ich weiss noch nicht was...

Vielen Dank schon mal für deine Unterstützung...

Grüße
Reinerlein

rapster

#17
Hi Reinerlein,

ich probiere das später sobald ich zuhause bin, allerdings falls ich dich richtig verstanden habe ist das so nicht richtig.
Auf anderen Playern lässt sich der SPDIF (TV) Eingang der Playbar nur durch eine Gruppe abspielen, und auch nur wenn die Playbar gerade ebenfalls den SPDIF abspielt.

Wenn ich der TV-Gruppe anschließend die Playbar wegnehme, verschwindet auch der TV-Eingang am zweiten Player und er schaltet auf [keine Musikdatei].

Zumindest ist das so mit dem Sonos-Controller  ;)

Gruß Claudiu

Reinerlein

Hi Claudiu,

ok, wieder was gelernt :) Ich kenne das Ding ja nur theoretisch. Aber genau das kann das Problem sein.
Bei normalen AV-Eingängen kann man das ja einfach beliebig wiedergeben.

Wenn das mit dem SPDIF auf diese Weise nicht gehen sollte, dann muss man wahrscheinlich eine Sequenz ausführen (oder zumindest sicherstellen, dass die Playbar gerade TV wiedergibt):
1. Playbar auf SPDIF schalten
2. Gruppe mit Playbar bilden

Ginge auch, das müssen wir jetzt nur feststellen, dann kann ich diesen Schritt automatisieren...

Nur um sicherzugehen:
Du hast also nicht in dem Original-Controller einen Eingang unter der Eingänge-Auflistung, der deinem TV entspricht, und den du einfach wiedergeben kannst? Dort tauchen nur die "normalen" Audio-Eingänge der anderen Player auf?

Danke schon mal...

Grüße
Reinerlein

P.S.: Nicht falsch verstehen, ich glaube dir, aber auch nicht jeder Anwender hat sein Sonos schon genauestens untersucht :-)

rapster

Jup genau dieses Vorgehen ist richtig (1. Playbar auf SPDIF schalten, 2. Gruppe mit Playbar bilden)
Allerdings, wenn die Playbar mit einem anderen Player gruppiert ist (auf anderem Input), hat die Gruppe einen TV-Eingang zu Auswahl.

Nein, auf dem 2. Player habe ich keinen TV-Eingang.

Kein Thema, habs vorhin auch erst nochmal am Controller geprüft bevor ichs geschrieben hab, weil ich mir selber nicht mehr sicher war  ;D

Gruß Claudiu

rapster

So mal die Logs nach Absenden des Befehls "set Sonos_Bad PlayURI Sonos_Kueche" mit verbose 5.


stdout:
2014.11.17 17:34:48 5: SONOS0: Received: 'DoWork:RINCON_000E58C74E4801400_MR:playURI:x-sonos-htastream:RINCON_000E58B7AF1401400:spdif'
2014.11.17 17:34:48 4: SONOS1: ProxyObject exists: UPnP::ControlPoint::ControlProxy=HASH(0x7f7e8c5aa4b0)
2014.11.17 17:34:48 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, reading, UserID_Spotify, -) -> SA_RINCON2311_X_%23Svc2311-0-Token
2014.11.17 17:34:48 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, reading, UserID_Napster, -) -> DEFAULT
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
2014.11.17 17:34:48 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, def, NAME, RINCON_000E58C74E4801400_MR) -> Sonos_Bad
2014.11.17 17:34:48 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:34:48 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 17:34:48 4: SONOS1: Transport-Event: All correct with this service-call till now. UDN='uuid:RINCON_000E58C74E4801400_MR'
2014.11.17 17:34:48 4: SONOS1: Transport-Event: GroundURL: http://192.168.1.150:1400
2014.11.17 17:34:48 4: SONOS1: Transport-Event: LastChange: <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/"><InstanceID val="0"><TransportState val="STOPPED"/><CurrentPlayMode val="NORMAL"/><CurrentCrossfadeMode val="0"/><NumberOfTracks val="0"/><CurrentTrack val="0"/><CurrentSection val="0"/><CurrentTrackURI val=""/><CurrentTrackDuration val="0:00:00"/><CurrentTrackMetaData val=""/><r:NextTrackURI val=""/><r:NextTrackMetaData val=""/><r:EnqueuedTransportURI val=""/><r:EnqueuedTransportURIMetaData val=""/></InstanceID></Event>
2014.11.17 17:34:48 4: SONOS1: Transport-Event: CurrentTrackMetaData:
2014.11.17 17:34:48 4: SONOS1: Transport-Event: Normal erkannt!
2014.11.17 17:34:48 4: SONOS1: Transport-Event: NextTrackMetaData:
2014.11.17 17:34:48 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".



fhem.log
2014.11.17 17:34:48.081 5: SW: 446f576f726b3a52494e434f4e5f30303045353843373445343830313430305f4d523a706c61795552493a782d736f6e6f732d68746173747265616d3a52494e434f4e5f30303045353842374146313430313430303a73706469660d0a
2014.11.17 17:34:48.883 5: SONOS0: Received from UPnP-Server: 'DoWorkAnswer:RINCON_000E58C74E4801400_MR:LastActionResult:PlayURI: Error!'
2014.11.17 17:34:48.883 4: SONOS0: DoWorkAnswer arrived for Sonos_Bad->LastActionResult: 'PlayURI: Error!'
2014.11.17 17:34:48.885 5: SONOS0: Received from UPnP-Server: 'GetReadingsToCurrentHash:RINCON_000E58C74E4801400_MR:1'
2014.11.17 17:34:48.885 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TransportState:STOPPED'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'SetCurrent:CrossfadeMode:0'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NumberOfTracks:0'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Track:0'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackURI:'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackDuration:0:00:00'
2014.11.17 17:34:48.886 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:0::http://192.168.1.150:1400'
2014.11.17 17:34:48.886 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png');
2014.11.17 17:34:48.887 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:34:48.887 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png'!
2014.11.17 17:34:48.887 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NormalAudio:1'
2014.11.17 17:34:48.888 5: SONOS0: Received from UPnP-Server: 'SetCurrent:AlbumArtist:STOPPED'
2014.11.17 17:34:48.888 5: SONOS0: Received from UPnP-Server: 'SetCurrent:nextTrackURI:'
2014.11.17 17:34:48.888 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:1::http://192.168.1.150:1400'
2014.11.17 17:34:48.888 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png');
2014.11.17 17:34:48.889 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:34:48.889 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png'!
2014.11.17 17:34:48.889 5: SONOS0: Received from UPnP-Server: 'CurrentBulkUpdate:RINCON_000E58C74E4801400_MR'



Und hier noch die Logs wenn ich den SPDIF über den Sonos Controller gruppiere.

stdout
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, def, NAME, RINCON_000E58C74E4801400_MR) -> Sonos_Bad
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:36:20 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 17:36:20 4: SONOS1: Transport-Event: All correct with this service-call till now. UDN='uuid:RINCON_000E58C74E4801400_MR'
2014.11.17 17:36:20 4: SONOS1: Transport-Event: GroundURL: http://192.168.1.150:1400
2014.11.17 17:36:20 4: SONOS1: Transport-Event: LastChange: <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/"><InstanceID val="0"><TransportState val="PLAYING"/><CurrentPlayMode val="NORMAL"/><CurrentCrossfadeMode val="0"/><NumberOfTracks val="1"/><CurrentTrack val="1"/><CurrentSection val="0"/><CurrentTrackURI val="x-rincon:RINCON_000E58B7AF1401400"/><CurrentTrackDuration val=""/><CurrentTrackMetaData val=""/><r:NextTrackURI val=""/><r:NextTrackMetaData val=""/><r:EnqueuedTransportURI val=""/><r:EnqueuedTransportURIMetaData val=""/><PlaybackStorageMedium val="NETWORK"/><AVTransportURI val="x-rincon:RINCON_000E58B7AF1401400"/><AVTransportURIMetaData val=""/><CurrentTransportActions val="Play, Stop"/><r:CurrentValidPlayModes val="CROSSFADE"/></InstanceID></Event>
2014.11.17 17:36:20 4: SONOS1: Transport-Event: CurrentTrackMetaData:
2014.11.17 17:36:20 4: SONOS1: Transport-Event: Normal erkannt!
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, roomName, RINCON_000E58B7AF1401400) -> Kueche
2014.11.17 17:36:20 4: SONOS1: Transport-Event: NextTrackMetaData:
2014.11.17 17:36:20 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, def, NAME, RINCON_000E58B7AF1401400_MR) -> Sonos_Kueche
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:36:20 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 17:36:20 4: SONOS1: ZoneGroupTopology-Event: All correct with this service-call till now. UDN='uuid:RINCON_000E58B7AF1401400_MR'
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, ZonePlayerUUIDsInGroup, ) -> RINCON_000E58B7AF1401400
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, ZoneGroupID, ) -> RINCON_000E58B7AF1401400:__
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, fieldType, ) ->
2014.11.17 17:36:20 4: SONOS1: Retrieved TopoType:
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, ZoneGroupName, ) -> Kueche
2014.11.17 17:36:20 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, def, NAME, RINCON_000E58C74E4801400_MR) -> Sonos_Bad
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:36:20 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 17:36:20 4: SONOS1: ZoneGroupTopology-Event: All correct with this service-call till now. UDN='uuid:RINCON_000E58C74E4801400_MR'
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, reading, ZonePlayerUUIDsInGroup, ) -> RINCON_000E58C74E4801400
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, reading, ZoneGroupID, ) -> RINCON_000E58C74E4801400:__
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, reading, fieldType, ) ->
2014.11.17 17:36:20 4: SONOS1: Retrieved TopoType:
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, reading, ZoneGroupName, ) -> Bad
2014.11.17 17:36:20 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, def, NAME, RINCON_B8E93752FD2401400_MR) -> Sonos_Schlafzimmer
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:36:20 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 17:36:20 4: SONOS1: ZoneGroupTopology-Event: All correct with this service-call till now. UDN='uuid:RINCON_B8E93752FD2401400_MR'
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, reading, ZonePlayerUUIDsInGroup, ) -> RINCON_B8E93752FD2401400
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, reading, ZoneGroupID, ) -> RINCON_B8E93752FD2401400:__
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, reading, fieldType, ) ->
2014.11.17 17:36:20 4: SONOS1: Retrieved TopoType:
2014.11.17 17:36:20 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_B8E93752FD2401400_MR, reading, ZoneGroupName, ) -> Schlafzimmer
2014.11.17 17:36:20 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 17:36:23 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, def, NAME, RINCON_000E58C74E4801400_MR) -> Sonos_Bad
2014.11.17 17:36:23 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58C74E4801400_MR, attr, disable, 0) -> DEFAULT
2014.11.17 17:36:23 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 17:36:23 4: SONOS1: Transport-Event: All correct with this service-call till now. UDN='uuid:RINCON_000E58C74E4801400_MR'
2014.11.17 17:36:23 4: SONOS1: Transport-Event: GroundURL: http://192.168.1.150:1400
2014.11.17 17:36:23 4: SONOS1: Transport-Event: LastChange: <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/"><InstanceID val="0"><TransportState val="PLAYING"/><CurrentPlayMode val="NORMAL"/><CurrentCrossfadeMode val="0"/><NumberOfTracks val="1"/><CurrentTrack val="1"/><CurrentSection val="0"/><CurrentTrackURI val="x-rincon:RINCON_000E58B7AF1401400"/><CurrentTrackDuration val=""/><CurrentTrackMetaData val=""/><r:NextTrackURI val=""/><r:NextTrackMetaData val=""/><r:EnqueuedTransportURI val=""/><r:EnqueuedTransportURIMetaData val=""/></InstanceID></Event>
2014.11.17 17:36:23 4: SONOS1: Transport-Event: CurrentTrackMetaData:
2014.11.17 17:36:23 4: SONOS1: Transport-Event: Normal erkannt!
2014.11.17 17:36:23 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_000E58B7AF1401400_MR, reading, roomName, RINCON_000E58B7AF1401400) -> Kueche
2014.11.17 17:36:23 4: SONOS1: Transport-Event: NextTrackMetaData:
2014.11.17 17:36:23 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Loading device description failed with error: 200 OK at FHEM/00_SONOS.pm line 2281 thread 1.



fhem.log
2014.11.17 17:36:20.069 5: SONOS0: Received from UPnP-Server: 'GetReadingsToCurrentHash:RINCON_000E58C74E4801400_MR:1'
2014.11.17 17:36:20.070 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TransportState:PLAYING'
2014.11.17 17:36:20.070 5: SONOS0: Received from UPnP-Server: 'SetCurrent:CrossfadeMode:0'
2014.11.17 17:36:20.071 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NumberOfTracks:1'
2014.11.17 17:36:20.071 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Track:1'
2014.11.17 17:36:20.071 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackURI:x-rincon:RINCON_000E58B7AF1401400'
2014.11.17 17:36:20.071 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackDuration:'
2014.11.17 17:36:20.071 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:0::http://192.168.1.150:1400'
2014.11.17 17:36:20.072 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png');
2014.11.17 17:36:20.072 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:36:20.073 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png'!
2014.11.17 17:36:20.073 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NormalAudio:1'
2014.11.17 17:36:20.073 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Album:Kueche'
2014.11.17 17:36:20.073 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Title:Gruppenwiedergabe'
2014.11.17 17:36:20.074 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Artist:'
2014.11.17 17:36:20.074 5: SONOS0: Received from UPnP-Server: 'SetCurrent:AlbumArtist:PLAYING'
2014.11.17 17:36:20.074 5: SONOS0: Received from UPnP-Server: 'SetCurrent:nextTrackURI:'
2014.11.17 17:36:20.074 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:1::http://192.168.1.150:1400'
2014.11.17 17:36:20.074 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png');
2014.11.17 17:36:20.075 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:36:20.075 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png'!
2014.11.17 17:36:20.076 5: SONOS0: Received from UPnP-Server: 'CurrentBulkUpdate:RINCON_000E58C74E4801400_MR'
2014.11.17 17:36:20.171 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:undef:ZoneGroupState:<ZoneGroups><ZoneGroup Coordinator="RINCON_B8E93752FD2401400" ID="RINCON_000E58C74E4801400:68"><ZoneGroupMember UUID="RINCON_B8E93752FD2401400" Location="http://192.168.1.104:1400/xml/device_description.xml" ZoneName="Schlafzimmer" Icon="x-rincon-roomicon:masterbedroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="20" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup><ZoneGroup Coordinator="RINCON_000E58B7AF1401400" ID="RINCON_000E58B7AF1401400:40"><ZoneGroupMember UUID="RINCON_000E58C74E4801400" Location="http://192.168.1.150:1400/xml/device_description.xml" ZoneName="Bad" Icon="x-rincon-roomicon:bathroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="39" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/><ZoneGroupMember UUID="RINCON_000E58B7AF1401400" Location="http://192.168.1.149:1400/xml/device_description.xml" ZoneName="Kueche" Icon="x-rincon-roomicon:kitchen" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="38" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup></ZoneGroups>'
2014.11.17 17:36:20.201 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58B7AF1401400_MR:ZonePlayerUUIDsInGroup:RINCON_000E58B7AF1401400,RINCON_000E58C74E4801400'
2014.11.17 17:36:20.203 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58B7AF1401400_MR:ZoneGroupID:RINCON_000E58B7AF1401400:__'
2014.11.17 17:36:20.203 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58B7AF1401400_MR:fieldType:'
2014.11.17 17:36:20.204 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58B7AF1401400_MR:ZoneGroupName:Kueche + 1'
2014.11.17 17:36:20.205 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:undef:ZoneGroupState:<ZoneGroups><ZoneGroup Coordinator="RINCON_B8E93752FD2401400" ID="RINCON_000E58C74E4801400:68"><ZoneGroupMember UUID="RINCON_B8E93752FD2401400" Location="http://192.168.1.104:1400/xml/device_description.xml" ZoneName="Schlafzimmer" Icon="x-rincon-roomicon:masterbedroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="20" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup><ZoneGroup Coordinator="RINCON_000E58B7AF1401400" ID="RINCON_000E58B7AF1401400:40"><ZoneGroupMember UUID="RINCON_000E58B7AF1401400" Location="http://192.168.1.149:1400/xml/device_description.xml" ZoneName="Kueche" Icon="x-rincon-roomicon:kitchen" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="38" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/><ZoneGroupMember UUID="RINCON_000E58C74E4801400" Location="http://192.168.1.150:1400/xml/device_description.xml" ZoneName="Bad" Icon="x-rincon-roomicon:bathroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="39" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup></ZoneGroups>'
2014.11.17 17:36:20.236 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58C74E4801400_MR:ZonePlayerUUIDsInGroup:RINCON_000E58B7AF1401400,RINCON_000E58C74E4801400'
2014.11.17 17:36:20.237 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58C74E4801400_MR:ZoneGroupID:RINCON_000E58B7AF1401400:__'
2014.11.17 17:36:20.238 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_000E58C74E4801400_MR:fieldType:'
2014.11.17 17:36:20.239 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:undef:ZoneGroupState:<ZoneGroups><ZoneGroup Coordinator="RINCON_000E58B7AF1401400" ID="RINCON_000E58B7AF1401400:40"><ZoneGroupMember UUID="RINCON_000E58B7AF1401400" Location="http://192.168.1.149:1400/xml/device_description.xml" ZoneName="Kueche" Icon="x-rincon-roomicon:kitchen" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="38" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/><ZoneGroupMember UUID="RINCON_000E58C74E4801400" Location="http://192.168.1.150:1400/xml/device_description.xml" ZoneName="Bad" Icon="x-rincon-roomicon:bathroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="39" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup><ZoneGroup Coordinator="RINCON_B8E93752FD2401400" ID="RINCON_000E58C74E4801400:68"><ZoneGroupMember UUID="RINCON_B8E93752FD2401400" Location="http://192.168.1.104:1400/xml/device_description.xml" ZoneName="Schlafzimmer" Icon="x-rincon-roomicon:masterbedroom" Configuration="1" SoftwareVersion="28.1-82291" MinCompatibleVersion="26.0-00000" LegacyCompatibleVersion="24.0-0000" BootSeq="20" WirelessMode="0" ChannelFreq="2437" BehindWifiExtender="0" WifiEnabled="1"/></ZoneGroup></ZoneGroups>'
2014.11.17 17:36:20.269 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_B8E93752FD2401400_MR:ZonePlayerUUIDsInGroup:RINCON_B8E93752FD2401400'
2014.11.17 17:36:20.270 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_B8E93752FD2401400_MR:ZoneGroupID:RINCON_B8E93752FD2401400:__'
2014.11.17 17:36:20.270 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_B8E93752FD2401400_MR:fieldType:'
2014.11.17 17:36:20.270 5: SONOS0: Received from UPnP-Server: 'ReadingsSingleUpdateIfChanged:RINCON_B8E93752FD2401400_MR:ZoneGroupName:Schlafzimmer'
2014.11.17 17:36:23.177 5: SONOS0: Received from UPnP-Server: 'GetReadingsToCurrentHash:RINCON_000E58C74E4801400_MR:1'
2014.11.17 17:36:23.178 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TransportState:PLAYING'
2014.11.17 17:36:23.178 5: SONOS0: Received from UPnP-Server: 'SetCurrent:CrossfadeMode:0'
2014.11.17 17:36:23.178 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NumberOfTracks:1'
2014.11.17 17:36:23.179 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Track:1'
2014.11.17 17:36:23.179 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackURI:x-rincon:RINCON_000E58B7AF1401400'
2014.11.17 17:36:23.179 5: SONOS0: Received from UPnP-Server: 'SetCurrent:TrackDuration:'
2014.11.17 17:36:23.179 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:0::http://192.168.1.150:1400'
2014.11.17 17:36:23.179 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png');
2014.11.17 17:36:23.180 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:36:23.180 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_AlbumArt.png'!
2014.11.17 17:36:23.180 5: SONOS0: Received from UPnP-Server: 'SetCurrent:NormalAudio:1'
2014.11.17 17:36:23.181 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Album:Kueche'
2014.11.17 17:36:23.181 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Title:Gruppenwiedergabe'
2014.11.17 17:36:23.181 5: SONOS0: Received from UPnP-Server: 'SetCurrent:Artist:'
2014.11.17 17:36:23.181 5: SONOS0: Received from UPnP-Server: 'SetCurrent:AlbumArtist:PLAYING'
2014.11.17 17:36:23.181 5: SONOS0: Received from UPnP-Server: 'SetCurrent:nextTrackURI:'
2014.11.17 17:36:23.182 5: SONOS0: Received from UPnP-Server: 'ProcessCover:RINCON_000E58C74E4801400_MR:1::http://192.168.1.150:1400'
2014.11.17 17:36:23.182 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./www/images/default/fhemicon.png', './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png');
2014.11.17 17:36:23.182 4: SONOS0: Couldn't retrieve file "./www/images/default/fhemicon.png" via web. Trying to copy directly...
2014.11.17 17:36:23.182 4: SONOS0: Identical filecontent for './www/images/default/SONOSPLAYER/Sonos_Bad_NextAlbumArt.png'!
2014.11.17 17:36:23.183 5: SONOS0: Received from UPnP-Server: 'CurrentBulkUpdate:RINCON_000E58C74E4801400_MR'


Gruß Claudiu

rapster

#21
Nur so ganz nebenbei, ich habe das gruppieren des SPDIF der Playbar bis her noch nie benötigt  ;D

Was ist denn eigentlich der Standard verbose-Wert beim Sonos-Dev, 3 ? (Habs auf die schnelle nicht gefunden im Wiki)


Wegen dem wide character Problem nochmal, es kann ja passieren dass das Sonos-Modul mal "abraucht", lässt es sich aber evtl. verhindern dass anschließend im Fhem log pro Millisekunde >5 neue Zeilen geschrieben werden?
Falls man das sonst mal nicht mitbekommt läuft die Festplatte rucki zucki voll, hatte gestern Abend nach paar Minuten testen bereits ein mehrere hundert MB großes Fhem.log  :-\

Fhem.log von gestern:
2014.11.17 03:04:07.213 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.
2014.11.17 03:04:07.214 1: SONOS0: Nothing could be read from TCP-Channel (the first level) even though the Read-Function was called.


Gruß Claudiu

Reinerlein

Hi Claudiu,

danke für die Logs. Leider meldet der Sonosplayer (Bad) einfach nur einen Fehler und keine weiteren Hinweise, ob es einen anderen Weg gäbe.
Ich denke, ich würde es darauf beschränken, dass man den SPDIF-Eingang nur von sich selbst wählen kann.
Geht das folgende bei dir?

set Sonos_Kueche PlayURI Sonos_Kueche
Er sollte dann ja eigentlich seinen eigenen TV-Eingang als Abspielquelle wählen...

Zu dem Log:
Ich habe da noch etwas eingebaut, was diese Unmenge an Logs verhindern soll. Ich weiss aber noch nichts zur Wirksamkeit :-)

Grüße
Reinerlein

P.S. Standard für Verbose gibt es keinen richtigen. Ich verwende 3. Dann bekomme ich noch einiges mit, und nicht zuviele Mitteilungen. Manche stellen das aber auf 0 um Ruhe zu haben...

rapster

Hi Reinerlein,

OK, 3 sah für mich auch vernünftig aus :-)

Jup der Befehl funktioniert, und er schaltet wie erwartet auf den TV Eingang. Das ist evtl. sogar mal ganz nützlich :-)

Ja diese Beschränkung sollte denke ich auch in 99,9% aller Fälle ausreichen.
Falls man SPDIF auf einem anderen Player (mit) ausgeben will funktioniert das ja hervorragend über AddMember (set <Playbar> PlayURI <Playbar>;; set <Playbar> AddMember <andererPlayer>)
Ich denke anders wird es auch nicht funktionieren, da diese Vorgehensweise ja genau so auch im original Sonos Controller durchgeführt werden muss.

Hoffe dass das mit dem Log allerdings klappt, so ein Linux mit keinem freien Speicher mehr, verhällt sich ja manchmal doch etwas komisch  ;D

Gruß Claudiu

Reinerlein

Hi Claudiu,

ich habe die Dev-Version mal aktualisiert.
Wenn man jetzt den TV-Eingang eines anderen Players (der Playbar) per PlayURI starten möchte, macht er jetzt die beiden Schritte automatisch:
- An der Playbar den TV-Eingang wählen
- Eine Gruppenwiedergabe bei dem gewünschten Player (und der gewünschten Lautstärke) mit der Playbar starten
Das war doch einfacher als erwartet...

Kannst du das noch kurz testen? Dann sind wir mit dem Thema auch durch, und ich lasse dich erstmal in Ruhe :-)

Grüße
Reinerlein

rapster

funzt 1A!  8)
- Eingang schaltet von der aktuell gespielten Musik auf TV um, Gruppe wird erstellt => TV wird auf Playbar + anderem Player ausgegeben.


Allerdings... ist mir das bereits heute Nachmittag aufgefallen, ich weiss nicht woher das kommt, allerdings bilde ich mir ein das Verhalten war gestern noch nicht so.

Nach einem shutdown+restart von fhem, bzw. nach einem Reboot der ganzen Kiste, bleibt das Sonos Modul bei allen Devices auf dem Status "initialized" stehen und es werden keine aktuellen Informationen von den Devices angezeigt.
Erst wenn man irgend eine Befehl ausführt, z.B. MuteT, VolumeD,... werden alle Devices nach ~4sec  geladen (der Befehl allerdings nicht ausgeführt), und erst beim 2. absetzen des Befehls wird er nun auch ausgeführt. 

Gruß Claudiu

Reinerlein

Hi Claudiu,

schön, dann haben wir das mit der Playbar jetzt durch.

Zu dem initialized-Thema:
Bei mir läuft das z.B. auf einem Raspberry Pi. Der ist nicht so schnell. Bei meinen vier Sonos-Komponenten dauert das ingesamt lockere 30-45 Sekunden bis alles fertig erkannt wurde und in Fhem eingetragen wurde.
Bis dahin steht dann dieses initialized und wird Stück für Stück angepasst. Erst danach geht auch eine Steuerung des jeweiligen Players...
Da hilft es auch, das Log kleiner zu halten, da es auf der SD-Karte Zeit kostet es wegzuschreiben...

Außerdem muss man natürlich longpoll aktiviert haben, um die Aktualisierung auf der Oberfläche direkt zu sehen :-)

Grüße
Reinerlein

rapster

Hi Reinerlein,

hmm, dass wird aber denk ich bei mir nicht das Problem sein.

1. Habe ich bereits einmal >5min gewartet, und egal wann (auch direkt nach Fhem start) ich eine Aktion ausführe, 4sec später sind die Devices da.
2. Glaube ich das es mit der Version von gestern Abend noch funktionierte :-)
3. Läuft Fhem bei mir auf einer VM (ESXi) mit relativ schneller i7 CPU und einer Samsung 840Pro SSD als Storage.
4. Sollte doch longpoll per default aktiviert sein oder? (Geändert habe ich es zumindest nicht). Alternativ sollte doch ein F5 das selbe bewirken?

Hast du vll. einen Tipp woran das sonst liegen könnte?

Gruß Claudiu

Reinerlein

Hi Claudiu,

ok, das klingt nicht nach Perfomanceproblemen bei der Hardware und ja, longpoll sollte aktiv sein und ja, F5 hat die gleiche Wirkung :-)

Du kannst zum Testen mal mehrere Konsolenfenster nebeneinander machen.
In einem Fenster ein "tail -f" für die Konsolenausgabe des Subprozesses. Im nächsten Fenster ein "tail -f" auf der Fhem-Logdatei.
Außerdem noch ein Browserfenster oder Telnet-Fenster für den Fhem-Restart.

Bei Loglevel 3 sieht man gut, wenn er mit der Erkennung anfängt, wo verzögerungen sind, und wann es bei fhem landet. Vielleicht sieht man dabei was er so alles tut...

Grüße
Reinerlein

rapster

Hi Reinerlein,

Konsolen standen schon zufällig genau so bereit  ;D

Nach Fhem Start ohne eine Aktion zu betätigen:

fhem.log
2014.11.17 20:27:21.541 1: Including fhem.cfg
2014.11.17 20:27:21.586 2: eventTypes: loaded 5731 events from ./log/eventTypes.txt
2014.11.17 20:27:21.587 1: Including ./FHEM/connectionConfig.cfg
2014.11.17 20:27:21.592 3: telnetPort: port 23 opened
2014.11.17 20:27:21.626 3: WEB: port 443 opened
2014.11.17 20:27:21.665 3: WEBphone: port 8084 opened
2014.11.17 20:27:21.665 3: WEBtablet: port 8085 opened
2014.11.17 20:27:21.667 1: Including ./FHEM/CUL_VCCU.cfg
2014.11.17 20:27:21.676 3: Opening CUL1 device /dev/ttyACM0
2014.11.17 20:27:21.773 3: Setting CUL1 baudrate to 9600
2014.11.17 20:27:21.774 3: CUL1 device opened
2014.11.17 20:27:21.895 3: CUL1: Possible commands: BbCFiAZEGMKUYRTVWXefmltux
2014.11.17 20:27:21.946 2: Switched CUL1 rfmode to HomeMatic
2014.11.17 20:27:22.050 1: Including ./FHEM/actionDetector.cfg
2014.11.17 20:27:22.050 1: Including ./FHEM/HMinfo.cfg
2014.11.17 20:27:22.070 1: Including ./FHEM/devices.cfg
2014.11.17 20:27:22.134 1: Including ./FHEM/svgPlots.cfg
2014.11.17 20:27:22.150 1: Including ./FHEM/residents.cfg
2014.11.17 20:27:22.167 1: Including ./FHEM/geofancy.cfg
2014.11.17 20:27:22.171 3: Registering GEOFANCY geofancy for URL /geo...
2014.11.17 20:27:22.173 1: Including ./FHEM/dashboard.cfg
2014.11.17 20:27:22.182 1: Including ./FHEM/ignoreDevices.cfg
2014.11.17 20:27:22.184 1: Including ./FHEM/sonos.cfg
2014.11.17 20:27:22.366 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 sekunden darauf...
2014.11.17 20:27:30.367 3: Opening Sonos device localhost:4711
2014.11.17 20:27:30.368 3: Sonos device opened
2014.11.17 20:27:30.380 1: Including ./FHEM/pushover.cfg
2014.11.17 20:27:30.383 1: Including ./FHEM/notify.cfg
2014.11.17 20:27:30.383 1: Including ./FHEM/TEST.cfg
2014.11.17 20:27:30.400 1: Including ./log/fhem.save
2014.11.17 20:27:30.478 1: statefile: Reading Sonos_Bad->LastActionResult must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Bad->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Kueche->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Schlafzimmer->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
2014.11.17 20:27:30.483 2: Error messages while initializing FHEM: statefile: Reading Sonos_Bad->LastActionResult must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Bad->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Kueche->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Schlafzimmer->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
2014.11.17 20:27:30.483 0: Server started with 178 defined entities (version $Id: fhem.pl 6913 2014-11-08 10:32:44Z rudolfkoenig $, os linux, user root, pid 2027)
2014.11.17 20:27:35.401 3: Device CUL_HM_HM_SEC_RHS_238E26 added to ActionDetector with 028:00 time
2014.11.17 20:27:35.411 3: Device dg_wz_fensterkontakt_links added to ActionDetector with 000:50 time
2014.11.17 20:27:35.413 3: Device dg_wz_fensterkontakt_rechts added to ActionDetector with 000:50 time
2014.11.17 20:27:35.415 3: Device dg_wz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 20:27:35.424 3: Device dg_wz_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 20:27:35.429 3: Device og_bz_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 20:27:35.431 3: Device og_bz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 20:27:35.439 3: Device og_bz_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 20:27:35.446 3: Device og_ez_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 20:27:35.449 3: Device og_ez_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 20:27:35.458 3: Device og_ez_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 20:27:35.465 3: Device og_schlieserschnittstelle added to ActionDetector with 028:00 time
2014.11.17 20:27:35.467 3: Device og_sz_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 20:27:35.469 3: Device og_sz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 20:27:35.478 3: Device og_sz_wandthermostat added to ActionDetector with 000:10 time


stdout
Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 167, <$fh> line 3.
Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 168, <$fh> line 3.
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3435.
Current: "fhem.pl", gPath: "./FHEM"
Smartmatch is experimental at FHEM/00_SONOS.pm line 3435.
Current: "FHEM/00_SONOS.pm", gPath: ""
2014.11.17 20:27:22 1: SONOS0: FHEM/00_SONOS.pm is listening to Port 4711
2014.11.17 20:27:30 1: SONOS0: Connection accepted from localhost:54568



...Rest im nächsten Beitrag...

rapster


Nachdem ich mal eine Aktion (MuteT) angeklickt habe:

> fhem.log bleibt leer (verbose 3)

stdout:
2014.11.17 20:29:44 3: SONOS1: UPnP-Thread gestartet.
Odd number of elements in hash assignment at FHEM/lib/UPnP/ControlPoint.pm line 30, <$client> line 7.
2014.11.17 20:29:44 1: SONOS2: Restore-Thread gestartet. Warte auf Arbeit...
2014.11.17 20:29:44 3: SONOS1: ProxyObject does not exists
2014.11.17 20:29:44 2: SONOS1: Discover Sonosplayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
2014.11.17 20:29:44 2: SONOS1: SonosPlayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR' is already defined and will only be updated
2014.11.17 20:29:44 2: SONOS1: SonosPlayer 'Bad' is now updated
2014.11.17 20:29:44 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000539" and Timeout="86400s"
2014.11.17 20:29:44 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000540" and Timeout="86400s"
2014.11.17 20:29:44 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000541" and Timeout="86400s"
2014.11.17 20:29:44 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000542" and Timeout="86400s"
2014.11.17 20:29:44 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000543" and Timeout="86400s"
2014.11.17 20:29:44 3: SONOS1: Discover: End of discover-event for "Bad".
2014.11.17 20:29:44 2: SONOS1: Discover Sonosplayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
2014.11.17 20:29:45 2: SONOS1: SonosPlayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR' is already defined and will only be updated
2014.11.17 20:29:45 2: SONOS1: SonosPlayer 'Kueche' is now updated
2014.11.17 20:29:45 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000480" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000481" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000482" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000483" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000484" and Timeout="86400s"
2014.11.17 20:29:45 3: SONOS1: Discover: End of discover-event for "Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 7.
2014.11.17 20:29:45 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR' is already defined and will only be updated
2014.11.17 20:29:45 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
2014.11.17 20:29:45 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000480" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000481" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000482" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000483" and Timeout="86400s"
2014.11.17 20:29:45 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000484" and Timeout="86400s"
2014.11.17 20:29:45 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Kueche".
2014.11.17 20:29:45 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Bad".
2014.11.17 20:29:45 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Schlafzimmer".
2014.11.17 20:29:45 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Schlafzimmer".


Scheint so als ob der UPnP-Thread erst nach der ersten Aktion gestartet wird, das war gestern noch definitiv anders  :-\

Gruß

Reinerlein

Hi Claudiu,

das ist auch definitiv nicht normal... Kannst du den ersten Schritt (also wo er nicht fertig macht) mit Loglevel 5 posten (oder auch per PN)...
Da erkennt man vielleicht, was er genau erwartet oder ähnliches. Er scheint ja zumindest keine Fehlermeldung zu geben...

Grüße
Reinerlein

rapster

Hi Reinerlein,

hier mal die logs, Fhem verbose 3, Sonos verbose 5

Soll ich fhem auch auf verbose 5 setzen?

fhem.log:
2014.11.17 22:17:16.603 1: Including fhem.cfg
2014.11.17 22:17:16.648 2: eventTypes: loaded 5750 events from ./log/eventTypes.txt
2014.11.17 22:17:16.649 1: Including ./FHEM/connectionConfig.cfg
2014.11.17 22:17:16.653 3: telnetPort: port 23 opened
2014.11.17 22:17:16.688 3: WEB: port 443 opened
2014.11.17 22:17:16.726 3: WEBphone: port 8084 opened
2014.11.17 22:17:16.727 3: WEBtablet: port 8085 opened
2014.11.17 22:17:16.729 1: Including ./FHEM/CUL_VCCU.cfg
2014.11.17 22:17:16.738 3: Opening CUL1 device /dev/ttyACM0
2014.11.17 22:17:17.741 3: Setting CUL1 baudrate to 9600
2014.11.17 22:17:17.742 3: CUL1 device opened
2014.11.17 22:17:17.863 3: CUL1: Possible commands: BbCFiAZEGMKUYRTVWXefmltux
2014.11.17 22:17:17.914 2: Switched CUL1 rfmode to HomeMatic
2014.11.17 22:17:18.017 1: Including ./FHEM/actionDetector.cfg
2014.11.17 22:17:18.017 1: Including ./FHEM/HMinfo.cfg
2014.11.17 22:17:18.036 1: Including ./FHEM/devices.cfg
2014.11.17 22:17:18.100 1: Including ./FHEM/svgPlots.cfg
2014.11.17 22:17:18.115 1: Including ./FHEM/residents.cfg
2014.11.17 22:17:18.132 1: Including ./FHEM/geofancy.cfg
2014.11.17 22:17:18.136 3: Registering GEOFANCY geofancy for URL /geo...
2014.11.17 22:17:18.139 1: Including ./FHEM/dashboard.cfg
2014.11.17 22:17:18.148 1: Including ./FHEM/ignoreDevices.cfg
2014.11.17 22:17:18.150 1: Including ./FHEM/sonos.cfg
2014.11.17 22:17:18.330 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 sekunden darauf...
2014.11.17 22:17:26.331 3: Opening Sonos device localhost:4711
2014.11.17 22:17:26.332 3: Sonos device opened
2014.11.17 22:17:26.347 1: Including ./FHEM/pushover.cfg
2014.11.17 22:17:26.350 1: Including ./FHEM/notify.cfg
2014.11.17 22:17:26.350 1: Including ./FHEM/TEST.cfg
2014.11.17 22:17:26.367 1: Including ./log/fhem.save
2014.11.17 22:17:26.443 1: statefile: Reading Sonos_Bad->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Kueche->LastActionResult must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Kueche->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
Reading Sonos_Schlafzimmer->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
2014.11.17 22:17:26.448 2: Error messages while initializing FHEM: statefile: Reading Sonos_Bad->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Kueche->LastActionResult must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Kueche->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem. Reading Sonos_Schlafzimmer->presence must not be used out of statefile. This is not an error! This happens due to restrictions of Fhem.
2014.11.17 22:17:26.448 0: Server started with 178 defined entities (version $Id: fhem.pl 6913 2014-11-08 10:32:44Z rudolfkoenig $, os linux, user root, pid 2243)
2014.11.17 22:17:26.449 5: SONOS0: Received from UPnP-Server: ''This is UPnP-Server calling''
2014.11.17 22:17:26.449 5: SONOS0: MainTrigger()-Line: 'This is UPnP-Server calling'
2014.11.17 22:17:27.334 5: SW: 536574446174613a536f6e6f733a353a6e6f6e653a536f6e6f735f4261642c536f6e6f735f4b75656368652c536f6e6f735f5363686c61667a696d6d65723a52494e434f4e5f30303045353843373445343830313430305f4d522c52494e434f4e5f30303045353842374146313430313430305f4d522c52494e434f4e5f42384539333735324644323430313430305f4d520a
2014.11.17 22:17:27.336 5: SONOS0: SetValues:SONOS:INTERVAL=30|targetSpeakFileHashCache=1|targetSpeakFileTimestamp=0|targetSpeakDir=%2Fopt%2Ffhem%2FSonosSpeak|NAME=Sonos|targetSpeakURL=%5C%5C192.168.1.12%5CSonosSpeak|UserID_Spotify=SA_RINCON2311_X_%2523Svc2311-0-Token
2014.11.17 22:17:27.336 5: SW: 53657456616c7565733a534f4e4f533a494e54455256414c3d33307c746172676574537065616b46696c654861736843616368653d317c746172676574537065616b46696c6554696d657374616d703d307c746172676574537065616b4469723d2532466f70742532466668656d253246536f6e6f73537065616b7c4e414d453d536f6e6f737c746172676574537065616b55524c3d2535432535433139322e3136382e312e3132253543536f6e6f73537065616b7c5573657249445f53706f746966793d53415f52494e434f4e323331315f585f2532353233537663323331312d302d546f6b656e0a
2014.11.17 22:17:27.338 5: SONOS0: SetValues:RINCON_000E58C74E4801400_MR:Balance=0|ZoneGroupName=Bad|location=http%3A%2F%2F192.168.1.150%3A1400%2Fxml%2Fdevice_description.xml|Mute=0|NAME=Sonos_Bad|SleepTimerVersion=0|minVolume=0|Loudness=1|Bass=-1|roomName=Bad|Volume=5|ZoneGroupID=RINCON_000E58C74E4801400%3A__|Treble=1|ZonePlayerUUIDsInGroup=RINCON_000E58C74E4801400|getAlarms=1|HeadphoneConnected=0|roomIcon=bathroom
2014.11.17 22:17:27.338 5: SW: 53657456616c7565733a52494e434f4e5f30303045353843373445343830313430305f4d523a42616c616e63653d307c5a6f6e6547726f75704e616d653d4261647c6c6f636174696f6e3d687474702533412532462532463139322e3136382e312e31353025334131343030253246786d6c2532466465766963655f6465736372697074696f6e2e786d6c7c4d7574653d307c4e414d453d536f6e6f735f4261647c536c65657054696d657256657273696f6e3d307c6d696e566f6c756d653d307c4c6f75646e6573733d317c426173733d2d317c726f6f6d4e616d653d4261647c566f6c756d653d357c5a6f6e6547726f757049443d52494e434f4e5f30303045353843373445343830313430302533415f5f7c547265626c653d317c5a6f6e65506c617965725555494473496e47726f75703d52494e434f4e5f30303045353843373445343830313430307c676574416c61726d733d317c4865616470686f6e65436f6e6e65637465643d307c726f6f6d49636f6e3d62617468726f6f6d0a
2014.11.17 22:17:27.341 5: SONOS0: SetValues:RINCON_000E58B7AF1401400_MR:ZoneGroupName=Kueche|location=http%3A%2F%2F192.168.1.149%3A1400%2Fxml%2Fdevice_description.xml|NAME=Sonos_Kueche|Mute=0|Balance=0|Bass=1|Treble=0|ZoneGroupID=RINCON_000E58B7AF1401400%3A__|Volume=14|roomName=Kueche|HeadphoneConnected=0|getAlarms=1|ZonePlayerUUIDsInGroup=RINCON_000E58B7AF1401400|roomIcon=kitchen|SleepTimerVersion=0|minVolume=0|Loudness=1
2014.11.17 22:17:27.341 5: SW: 53657456616c7565733a52494e434f4e5f30303045353842374146313430313430305f4d523a5a6f6e6547726f75704e616d653d4b75656368657c6c6f636174696f6e3d687474702533412532462532463139322e3136382e312e31343925334131343030253246786d6c2532466465766963655f6465736372697074696f6e2e786d6c7c4e414d453d536f6e6f735f4b75656368657c4d7574653d307c42616c616e63653d307c426173733d317c547265626c653d307c5a6f6e6547726f757049443d52494e434f4e5f30303045353842374146313430313430302533415f5f7c566f6c756d653d31347c726f6f6d4e616d653d4b75656368657c4865616470686f6e65436f6e6e65637465643d307c676574416c61726d733d317c5a6f6e65506c617965725555494473496e47726f75703d52494e434f4e5f30303045353842374146313430313430307c726f6f6d49636f6e3d6b69746368656e7c536c65657054696d657256657273696f6e3d307c6d696e566f6c756d653d307c4c6f75646e6573733d310a
2014.11.17 22:17:27.343 5: SONOS0: SetValues:RINCON_B8E93752FD2401400_MR:roomIcon=masterbedroom|getAlarms=1|ZonePlayerUUIDsInGroup=RINCON_B8E93752FD2401400|HeadphoneConnected=0|Volume=92|roomName=Schlafzimmer|ZoneGroupID=RINCON_B8E93752FD2401400%3A__|Treble=0|Bass=0|Loudness=1|minVolume=0|SleepTimerVersion=0|Mute=0|NAME=Sonos_Schlafzimmer|location=http%3A%2F%2F192.168.1.104%3A1400%2Fxml%2Fdevice_description.xml|ZoneGroupName=Schlafzimmer|Balance=0
2014.11.17 22:17:27.343 5: SW: 53657456616c7565733a52494e434f4e5f42384539333735324644323430313430305f4d523a726f6f6d49636f6e3d6d6173746572626564726f6f6d7c676574416c61726d733d317c5a6f6e65506c617965725555494473496e47726f75703d52494e434f4e5f42384539333735324644323430313430307c4865616470686f6e65436f6e6e65637465643d307c566f6c756d653d39327c726f6f6d4e616d653d5363686c61667a696d6d65727c5a6f6e6547726f757049443d52494e434f4e5f42384539333735324644323430313430302533415f5f7c547265626c653d307c426173733d307c4c6f75646e6573733d317c6d696e566f6c756d653d307c536c65657054696d657256657273696f6e3d307c4d7574653d307c4e414d453d536f6e6f735f5363686c61667a696d6d65727c6c6f636174696f6e3d687474702533412532462532463139322e3136382e312e31303425334131343030253246786d6c2532466465766963655f6465736372697074696f6e2e786d6c7c5a6f6e6547726f75704e616d653d5363686c61667a696d6d65727c42616c616e63653d300a
2014.11.17 22:17:27.345 5: SW: 53746172745468726561640a
2014.11.17 22:17:31.370 3: Device CUL_HM_HM_SEC_RHS_238E26 added to ActionDetector with 028:00 time
2014.11.17 22:17:31.380 3: Device dg_wz_fensterkontakt_links added to ActionDetector with 000:50 time
2014.11.17 22:17:31.382 3: Device dg_wz_fensterkontakt_rechts added to ActionDetector with 000:50 time
2014.11.17 22:17:31.383 3: Device dg_wz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 22:17:31.392 3: Device dg_wz_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 22:17:31.397 3: Device og_bz_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 22:17:31.399 3: Device og_bz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 22:17:31.407 3: Device og_bz_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 22:17:31.414 3: Device og_ez_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 22:17:31.416 3: Device og_ez_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 22:17:31.425 3: Device og_ez_wandthermostat added to ActionDetector with 000:10 time
2014.11.17 22:17:31.431 3: Device og_schlieserschnittstelle added to ActionDetector with 028:00 time
2014.11.17 22:17:31.434 3: Device og_sz_fensterkontakt added to ActionDetector with 000:50 time
2014.11.17 22:17:31.436 3: Device og_sz_heizkoerper added to ActionDetector with 000:10 time
2014.11.17 22:17:31.444 3: Device og_sz_wandthermostat added to ActionDetector with 000:10 time


stdout:
>Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 167, <$fh> line 3.
Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 168, <$fh> line 3.
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3435.
Current: "fhem.pl", gPath: "./FHEM"
Smartmatch is experimental at FHEM/00_SONOS.pm line 3435.
Current: "FHEM/00_SONOS.pm", gPath: ""
2014.11.17 22:17:18 1: SONOS0: FHEM/00_SONOS.pm is listening to Port 4711
2014.11.17 22:17:26 1: SONOS0: Connection accepted from localhost:54835
2014.11.17 22:17:27 5: SONOS0: Received: 'SetValues:SONOS:INTERVAL=30|targetSpeakFileHashCache=1|targetSpeakFileTimestamp=0|targetSpeakDir=%2Fopt%2Ffhem%2FSonosSpeak|NAME=Sonos|targetSpeakURL=%5C%5C192.168.1.12%5CSonosSpeak|UserID_Spotify=SA_RINCON2311_X_%2523Svc2311-0-Token'


Danke dir!, Gruß Claudiu

Reinerlein

Hi Claudiu,

hmmm... das Problem ist eine fehlende Datenübertragung zur Initialisierung (Ich übertrage noch eine Sequenz "SetData", die ich im Empfangslog überhaupt nicht sehe).
Dazu ist mir dir Log-Ausgabe von DevIo_SimpleWrite() aufgefallen (das sind die Zeilen mit "SW " am Anfang).
Dort sollte im Normalfall ausgegeben werden, was übertragen werden wird. Hier scheint eine Ausgabe im Hex-Format zu erfolgen, was eigentlich nur der Fall sein sollte, wenn der dritte Parameter boolsch true gesetzt wurde. Ich tue das nicht, und übertrage immer eine 0 an der Stelle.

Ich habe bei mir den Code von SimpleWrite überprüft, und es steht so, wie ich es erwarte (und bei mir geht es ja auch).
Hier mal die kleine Sub-Prozedur von meinem Codestand:

sub
DevIo_SimpleWrite($$$)
{
  my ($hash, $msg, $ishex) = @_;
  return if(!$hash);

  my $name = $hash->{NAME};
  Log3 ($name, 5, $ishex ? "SW: $msg" : "SW: ".unpack("H*",$msg));

  $msg = pack('H*', $msg) if($ishex);
  $hash->{USBDev}->write($msg)    if($hash->{USBDev});
  syswrite($hash->{TCPDev}, $msg) if($hash->{TCPDev});
  syswrite($hash->{DIODev}, $msg) if($hash->{DIODev});
  select(undef, undef, undef, 0.001);
}
Sieht die bei dir anders aus? Wird die irgendwie durch ein anderes Modul vielleicht überschrieben?
-> Ich sehe gerade, dass diese Log-Ausgabe genau falsch herum geschrieben ist. Da kann man sich also nicht drauf verlassen... Aber die Variable $msg wird, zumindest hier, im korrekten Fall umgewandelt...

Kannst du deine Fhem-Konfiguration verringern, sodass im großen und ganzen nur Sonos drin ist?
Wie läuft es dann?

Grüße
Reinerlein

rapster

#34
Uff, das Problem scheint ja doch nicht so trivial wie gedacht...

Also die DevIo_SimpleWrite() sieht bei mir genau so aus, meine DevIo.pm => 6980 2014-11-15

Aus der fhem.cfg habe ich alles bis auf Sonos rausgeschmissen, hat aber leider nicht geholfen.

Ich habe jetzt nochmal mit Fhem verbose 5 und Sonos verbose 5 logs gemacht (mit sauberer fhem.cfg)

Verstehe grad nicht warum das nicht funktioniert, hab auch mal Sonos-Stable probiert, hier funktioniert es aber auch nicht.

die fhem.log im Anhang, sonos stdout hat sich nicht viel getan:
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3435.
Current: "fhem.pl", gPath: "./FHEM"
Smartmatch is experimental at FHEM/00_SONOS.pm line 3435.
Current: "FHEM/00_SONOS.pm", gPath: ""
2014.11.18 00:15:34 1: SONOS0: FHEM/00_SONOS.pm is listening to Port 4711
2014.11.18 00:15:42 1: SONOS0: Connection accepted from localhost:40577
2014.11.18 00:15:42 5: SONOS0: Received: 'DoWork:undef:setVerbose:5'
2014.11.18 00:15:43 5: SONOS0: Received: 'SetData:Sonos:5:none:Sonos_Bad,Sonos_Kueche,Sonos_Schlafzimmer:RINCON_000E58C74E4801400_MR,RINCON_000E58B7AF1401400_MR,RINCON_B8E93752FD2401400_MR'
2014.11.18 00:15:43 5: SONOS0: Received: 'SetValues:SONOS:targetSpeakDir=%2Fopt%2Ffhem%2FSonosSpeak|UserID_Spotify=SA_RINCON2311_X_%2523Svc2311-0-Token|targetSpeakFileTimestamp=0|targetSpeakURL=%5C%5C192.168.1.12%5CSonosSpeak|targetSpeakFileHashCache=1|NAME=Sonos|INTERVAL=30'


Ich bin mir nur fast sicher dass es gestern Abend noch funktionierte, nur was hätte sich seit dem ändern können?

EDIT:
Ich habe eben mal mein VM-Backup von Gestern Nacht 2:00 Uhr gebootet, hier funktioniert noch alles, auch nach einspielen der aktuellen Sonos-Dev

Ich prüfe mal Morgen was evtl. heute übern Tag schief gelaufen ist, das ist sehr merkwürdig.

Reinerlein

Hi Claudiu,

kann es das Attribut "verbose" am Sonos-Device sein?

Das hast du doch bestimmt erst später zum Testen gesetzt. Wenn es nicht gesetzt wird, wird automatisch der globale-verbose-Wert verwendet...

Grüße
Reinerlein

rapster

Moin Reinerlein :-)

Tatsächlich, das wars!  :o

Glaub auf die Idee wäre ich jetzt nie gekommen, hätte jetzt eine Konfig nach der anderen zerpflückt  ;D

Danke dir!!

Gruß Claudiu

Reinerlein

Hi Claudiu,

ok, dann schaue ich mir das mal an.

Das Modul versucht Attribute beim Setzen direkt an den Subprozess zu übertragen. Das darf er aber erst, wenn der Subprozess fertig mit initialisieren ist...

Danke fürs Testen..

Grüße
Reinerlein

rapster

Hi Reinerlein,

mal a Sache wenn du mal vll. etwas Zeit hast..

Wie verhällt es sich eigentlich mit dieser 8 Sekunden Pause beim fhem Start?

Muss diese wirklich hardcodiert auf 8 Sekunden stehen, oder lässt sich das Modul nicht insofern anpassen, dass die Verarbeitung dynamisch fortgesetzt wird sobald der UPnP-Server gefunden wurde, da ja der gesamte Fhem start hierdurch doch in die Länge gezogen wird?


2014.11.18 06:39:33.479 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 sekunden darauf...
2014.11.18 06:39:41.480 3: Opening Sonos device localhost:4711



Gruß Claudiu

rapster

Und evtl. noch eine Sache die mir aufgefallen ist  ;)

sobald man in fhem ein "rereadcfg", bzw. "reload ..." durchführt oder die fhem.cfg abspeichert, wandert das Sonos Modul in den Status "initialized".

Auch wenn man den Fhem Prozess stopt, sieht man dass das Sonos Modul weiter ausgeführt wird, und nach dem Fhem Start nichtmehr mit hochkommt:
root@fhem:~>service fhem stop
Stopping FHEM...
root@fhem:~>ps -ef | grep perl
root      2936     1  0 08:54 ?        00:00:06 perl FHEM/00_SONOS.pm 4711 3
root      3071  3022  0 09:54 pts/1    00:00:00 grep perl
root@fhem:~>service fhem start
Starting FHEM...
Process ID: 3081
root@fhem:~>Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 167, <$fh> line 3.
Smartmatch is experimental at ./FHEM/10_RESIDENTS.pm line 168, <$fh> line 3.
Smartmatch is experimental at ./FHEM/00_SONOS.pm line 3435.
Current: "fhem.pl", gPath: "./FHEM"
root@fhem:~>


Erst wenn man den (alten) Sonos Perl Prozess per SIGTERM abschießt, fängt sich das Modul wieder und baut eine Verbindung auf. (Fhem muss nach dem SIGTERM nicht neu gestartet werden)

root@fhem:~>kill 2936
root@fhem:~>Smartmatch is experimental at FHEM/00_SONOS.pm line 3435.
Current: "FHEM/00_SONOS.pm", gPath: ""
2014.11.18 09:59:08 1: SONOS0: FHEM/00_SONOS.pm is listening to Port 4711
kill 29362014.11.18 09:59:15 1: SONOS0: Connection accepted from localhost:55470                                     service fhem start2014.11.18 09:59:16 3: SONOS1: UPnP-Thread gestartet.
Odd number of elements in hash assignment at FHEM/lib/UPnP/ControlPoint.pm line 30, <$client> line 6.
2014.11.18 09:59:16 1: SONOS2: Restore-Thread gestartet. Warte auf Arbeit...
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Discover Sonosplayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Schlafzimmer' (S1) Software Revision 5.2 with ID 'RINCON_B8E93752FD2401400_MR' is already defined and will only be updated
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Schlafzimmer' is now updated
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000624" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000625" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000626" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000627" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_B8E93752FD2401400_sub0000000628" and Timeout="86400s"
2014.11.18 09:59:17 3: SONOS1: Discover: End of discover-event for "Schlafzimmer".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Discover Sonosplayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Bad' (S1) Software Revision 5.2 with ID 'RINCON_000E58C74E4801400_MR' is already defined and will only be updated
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Bad' is now updated
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000116" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000117" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000118" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000119" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58C74E4801400_sub0000000120" and Timeout="86400s"
2014.11.18 09:59:17 3: SONOS1: Discover: End of discover-event for "Bad".
2014.11.18 09:59:17 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Schlafzimmer".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Schlafzimmer".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Discover Sonosplayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR'
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Kueche' (S9) Software Revision 5.2 with ID 'RINCON_000E58B7AF1401400_MR' is already defined and will only be updated
2014.11.18 09:59:17 2: SONOS1: SonosPlayer 'Kueche' is now updated
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000124" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Rendering-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000125" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: Alarm-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000126" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000127" and Timeout="86400s"
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 2: SONOS1: DeviceProperties-Service-subscribing successful with SID="uuid:RINCON_000E58B7AF1401400_sub0000000128" and Timeout="86400s"
2014.11.18 09:59:17 3: SONOS1: Discover: End of discover-event for "Kueche".
2014.11.18 09:59:17 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Bad".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Bad".
2014.11.18 09:59:17 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Schlafzimmer".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:17 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:17 3: SONOS1: Event: Received Transport-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:17 3: SONOS1: Event: End of Transport-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:17 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Bad".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:18 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: Received Alarm-Event for Zone "Sonos_Kueche".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.18 09:59:18 3: SONOS1: Event: End of Alarm-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:18 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:18 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:18 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:18 3: SONOS1: Event: Received DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: End of DeviceProperties-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Kueche".
2014.11.18 09:59:18 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Bad".
2014.11.18 09:59:18 3: SONOS1: Event: Received Rendering-Event for Zone "Sonos_Schlafzimmer".
2014.11.18 09:59:18 3: SONOS1: Event: End of Rendering-Event for Zone "Sonos_Schlafzimmer".
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
root@fhem:~>


Gibt es hierfür einen Workaround oder fällt dir evtl. eine Lösung hierfür ein?

Gruß Claudiu

Reinerlein

Hi Claudiu,

mehrere Sachen:
- Man kann jetzt (erst aktualisieren!) beim Define als letzten Parameter hinter dem Interval eine Waittime in Sekunden angeben. Standardmäßig wird dort eine 8 angenommen (die einem guten Wert für einen Rapsberry Pi entspricht), und beliebig verändert werden. Wählt man ihn zu kurz, kann es sein, dass die Verbindung erst zum nächsten Prüfzyklus der TCP-Verbindung steht (ich meine das sind 60s).
- Das mit dem verbose bleibt ein komisches Verhalten bei dir :-) Ich konnte es nicht nachstellen, und im Code sieht das auch gut aus, und sollte eigentlich nicht das bei dir vorhandene Szenario ergeben. Da bin ich momentan echt überfragt...
- Das mit rereadcfg und co. habe ich damals schon ausführlich untersucht. Leider konnte ich keine machbare Lösung finden, und gebe (wie auch Rudi selbst) allgemein die Empfehlung ab, nur "shutdown restart" zu verwenden. Dort klappt das Beenden und Neustarten des Subprozesses Ordnungsgemäß...

Grüße
Reinerlein

rapster

#41
Hi Reinerlein,

mensch du bist ja super flott ;)

- Funzt super, und bin vollkommen zufrieden mit dieser Lösung  :D
  Wenn ich als Waittime 1 eingebe funktioniert alles perfekt.
  Wenn ich als Waittime 0 eingebe startet Sonos wie du sagtest nach ~60 sec
  Nur mit Werten <1 (wie 0.5) scheint es nicht zu klappen (es wird nicht gewartet, wie 0), oder muss ich hier den Wert anderst angeben?
2014.11.18 12:56:01.691 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 0.5 sekunden darauf...
2014.11.18 12:56:01.692 3: Opening Sonos device localhost:4711


- Hm, ja wirklich seltsam, ist aber auch nicht wirklich schlimm, hatte ja verbose sowieso auf 3 gesetzt (scheint auch default zu sein) und zur Fehlerbehebung falls mal verbose 5 benötigt wird, funktioniert der Workaroung ja temporär auch.
  > evtl. sollte auf dieses Problem nur im Wiki hingewiesen werden, falls noch jemand hierauf stößt?

- OK, habe meistens sowieso restart benutzt (in meiner fhem.cfg sind nur includes drin).
  Und nachdem Fhem jetzt nurnoch ~5 Sekunden (incl. Sonos Geräte einlesen) zum starten braucht ( - 7 Sek durch Sonos-Waittime ;) ) ist das auch sehr erträglich.

Nochmal ein dickes Danke von mir für deine Mühe!!

Gruß Claudiu

Reinerlein

Hi Claudiu,

so noch ein Nachtrag zur Waittime.
Da stand vorher ein einfaches Sleep, welches nur ganze Zahlen konnte. Ich habe dort nun ein select() hingepackt, welches auch Kommazahlen beherrscht.
Man kann jetzt also bequem 0.1 Sekunden einstellen, die übrigens auf meinem Test-Windows-System auch vollkommen ausreichen...

Grüße
Reinerlein

rapster

Hi Reinerlein,

danke, das klappt wunderbar!

0.1 Sekunden haben bei mir zwar nicht gereicht, ich habe es jetzt mal auf 0.5 gestellt, hier scheint alles super zu starten  :D

Gruß Claudiu

rapster

#44
Hi Reinerlein,

zur Info...

Zitat- Das mit rereadcfg und co. habe ich damals schon ausführlich untersucht. Leider konnte ich keine machbare Lösung finden, und gebe (wie auch Rudi selbst) allgemein die Empfehlung ab, nur "shutdown restart" zu verwenden. Dort klappt das Beenden und Neustarten des Subprozesses Ordnungsgemäß...

Habe (für mich zumindest) für das Problem dass das Sonos-Modul nach einem rereadcfg, speichern von fhem.cfg u.ä. nicht mehr hoch kommt ein Workaround gebaut.

Durch ein einfaches notify welches auf dieses Ereignis den alten Sonos-Prozess beendet. (Es wird ja automatisch ein neuer gestartet).
define ntfy_sonosRereadcfg notify global:REREADCFG { `kill \$(ps aux | grep 00_[S]ONOS | awk '{print \$2}')` }

Funktioniert bei mir zumindest einwandfrei, und das Sonos-Modul ist nach einem rereadcfg wieder voll einsatzbereit  :D


> Oder siehst du irgendwelche Bedenken die gegen diese Lösung sprechen?


Gruß Claudiu

Reinerlein

Hi Claudiu,

damit hast du mich natürlich auf eine Idee gebracht. Das Sonos-Modul kann ja auch selber auf ein "rereadcfg"-Event reagieren... und tut es jetzt auch :)
Damals gab es dieses "Event" einfach noch nicht...

Wenn es ein Rereadcfg mitbekommt, wird die Verbindung zm Subprozess sauber getrennt, und kann danach auch sauber wieder aufgenommen werden. Wenn es keine anderweitigen Störungen gab, läuft es danach normal weiter (ausser, das sich in der Log-Ausgabe des Subprozesses die Threadnummern erhöhen)...

Leider ist dein Notify jetzt für diesen Fall nicht mehr soo wichtig ;D
Aber die Idee war dagegen sehr wichtig, danke nochmal.

Grüße
Reinerlein

rapster

#46
Hi Reinerlein,

super dass ich dir damit eine kleine Idee liefern konnte  :D

Nur leider funktioniert das bei mir nicht  :-X
Nach einem rereadcfg erhalte ich das hier:

fhem.log:
...
2014.11.19 12:57:01.418 1: Including ./FHEM/sonos.cfg
2014.11.19 12:57:01.919 3: Opening Sonos device localhost:4711
2014.11.19 12:57:01.919 3: Sonos device opened
2014.11.19 12:57:01.923 1: Including ./FHEM/TEST.cfg
2014.11.19 12:57:01.929 1: Including ./log/fhem.save
2014.11.19 12:57:01.998 0: SONOS0: Detecting rereadcfg. Restart Sonos-Subprocess...
2014.11.19 12:57:03.000 3: Opening Sonos device localhost:4711
2014.11.19 12:57:03.001 3: Sonos device opened
...


Und das hier im stdout:
2014.11.19 12:57:00 3: SONOS0: Disconnecting client...
2014.11.19 12:57:00 3: SONOS0: Trying to kill Sonos_Thread...
2014.11.19 12:57:00 3: SONOS0: Trying to kill PlayerRestore_Thread...
2014.11.19 12:57:00 1: SONOS2: Restore-Thread wurde beendet.
2014.11.19 12:57:01 3: SONOS1: Controlpoint-Listener wurde beendet.
2014.11.19 12:57:01 2: SONOS1: Error during UPnP-Handling:
2014.11.19 12:57:01 3: SONOS1: UPnP-Thread wurde beendet.
2014.11.19 12:57:02 1: SONOS0: Connection accepted from localhost:37296
2014.11.19 12:57:02 1: SONOS0: Connection accepted from localhost:37297
2014.11.19 12:57:02 3: SONOS0: Disconnecting client...
2014.11.19 12:57:04 1: SONOS0: Connection accepted from localhost:37298
2014.11.19 12:57:04 3: SONOS0: Disconnecting client...
2014.11.19 12:57:06 1: SONOS0: Connection accepted from localhost:37299
2014.11.19 12:57:06 3: SONOS0: Disconnecting client...
2014.11.19 12:58:04 1: SONOS0: Connection accepted from localhost:37300
2014.11.19 12:58:34 1: SONOS0: Connection accepted from localhost:37301
2014.11.19 12:59:04 1: SONOS0: Connection accepted from localhost:37302
2014.11.19 12:59:34 1: SONOS0: Connection accepted from localhost:37303
2014.11.19 13:00:04 1: SONOS0: Connection accepted from localhost:37304
2014.11.19 13:00:34 1: SONOS0: Connection accepted from localhost:37305
2014.11.19 13:01:04 1: SONOS0: Connection accepted from localhost:37306
2014.11.19 13:01:34 1: SONOS0: Connection accepted from localhost:37307
2014.11.19 13:02:04 1: SONOS0: Connection accepted from localhost:37308
2014.11.19 13:02:34 1: SONOS0: Connection accepted from localhost:37311
2014.11.19 13:03:04 1: SONOS0: Connection accepted from localhost:37312
2014.11.19 13:03:34 1: SONOS0: Connection accepted from localhost:37313
2014.11.19 13:04:04 1: SONOS0: Connection accepted from localhost:37314
2014.11.19 13:04:34 1: SONOS0: Connection accepted from localhost:37315
2014.11.19 13:05:04 1: SONOS0: Connection accepted from localhost:37316
2014.11.19 13:05:34 1: SONOS0: Connection accepted from localhost:37317
2014.11.19 13:06:04 1: SONOS0: Connection accepted from localhost:37318
2014.11.19 13:06:34 1: SONOS0: Connection accepted from localhost:37319
2014.11.19 13:07:04 1: SONOS0: Connection accepted from localhost:37320
2014.11.19 13:07:34 1: SONOS0: Connection accepted from localhost:37321
2014.11.19 13:08:04 1: SONOS0: Connection accepted from localhost:37322
2014.11.19 13:08:34 1: SONOS0: Connection accepted from localhost:37323
2014.11.19 13:09:04 1: SONOS0: Connection accepted from localhost:37324


Nachdem ich den Sonos-Prozess abschieße gehts dann wieder, erhalte aber obwohl es funktioniert weiterhin diese Meldungen im stdout (Nach receiving der ganzen Events):
2014.11.19 13:16:13 1: SONOS0: Connection accepted from localhost:37407
2014.11.19 13:16:43 1: SONOS0: Connection accepted from localhost:37408
2014.11.19 13:17:13 1: SONOS0: Connection accepted from localhost:37409


Hast du vll. noch eine Idee woran es jetzt liegen könnte?

Danke und Gruß Claudiu

Reinerlein

Hi Claudiu,

also die Sache mit den "Connection accepted"-Meldungen ist gerade normal. Ich bin gerade dabei ein Feature einzubauen, welches "verschwundene" oder nicht mehr reagierende Subprozesse aus Sicht von Fhem erkennen soll.
Dazu baue ich in Intervallen eine Verbindung auf, frage etwas ab, und werte das Ergebnis aus. Auf Subprozess-Seite landet dann genau diese Verbindungsmeldung im Log.
Das ist noch nicht ganz fertig, geht aber schon mal in die gewünschte Richtung...

Zu dem rereadcfg-Problem: Schade :-\
Bei mir sieht das gut aus. Aber irgendwie scheint dein System ja gerne anders zu reagieren (siehe Verbose-Problematik). Da muss ich also noch mal ran...

Grüße
Reinerlein

rapster

#48
Hi Reinerlein,

OK, gib bescheid sobald du was zum testen für mich hast  8) ;)

Ich (wir) haben die Sonos-Dev (von vorhin) bei einem Kollegen auf seinem Raspberry ausprobiert, hier hat es funktioniert.
Er erhält allerdings auch anschließend dauerhaft die Connection accepted messages.

Habe gesehen du hast wieder ein Update rausgebracht.
Leider wieder keine Funktion bei mir, sondern das Problem das der UPnP Thread irgendein error bringt nach einem rereadcfg:
Ich habe vorsichtshalber auch die Waittime mal wieder auf 8 gesetzt, leider ohne Erfolg.
Aber ist zumindest noch kompatibel zu meinem Notify ;D

2014.11.19 18:02:50 3: SONOS0: Disconnecting client...
2014.11.19 18:02:50 3: SONOS0: Trying to kill Sonos_Thread...
2014.11.19 18:02:50 3: SONOS0: Trying to kill PlayerRestore_Thread...
2014.11.19 18:02:50 1: SONOS2: Restore-Thread wurde beendet.
2014.11.19 18:02:51 3: SONOS1: Controlpoint-Listener wurde beendet.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
Odd number of elements in hash assignment at /usr/share/perl5/IO/Socket/IP.pm line 352, <$client> line 6.
2014.11.19 18:02:51 2: SONOS1: Error during UPnP-Handling:
2014.11.19 18:02:51 3: SONOS1: UPnP-Thread wurde beendet.
2014.11.19 18:02:52 1: SONOS0: Connection accepted from localhost:38633
2014.11.19 18:02:52 3: SONOS0: Disconnecting client...
2014.11.19 18:02:54 1: SONOS0: Connection accepted from localhost:38634
2014.11.19 18:02:54 1: SONOS0: Connection accepted from localhost:38635
2014.11.19 18:02:54 3: SONOS0: Disconnecting client...
2014.11.19 18:02:56 1: SONOS0: Connection accepted from localhost:38636
2014.11.19 18:02:56 3: SONOS0: Disconnecting client...
2014.11.19 18:03:56 1: SONOS0: Connection accepted from localhost:38637



Danke und Gruß Claudiu

Reinerlein

Hi Claudiu,

ich habe noch eine Kleingkeit angepasst. Irgendwie komme ich dem Problem auf deiner Maschine aber nicht wirklich näher...
Die Kommunikation sieht eigentlich recht gut aus. Eigentlich sollte da auch nix verwirrendes für irgendwelche Plattfomen dran sein...

Kannst du noch mal kurz einen Test machen?

Danke schon mal...

Grüße
Reinerlein

rapster

Hi Reinerlein,

was auch immer du angepasst hast, diese Kleinigkeit scheints ausgemacht zu haben! ;)

Jedenfalls funktioniert es jetzt einwandfrei, das Modul "erholt" sich selbstständig nach einem rereadcfg!

Auch die logs sehen in meinen Augen OK aus..
Im Anhang mal das fhem-log + stdout mit allem nach dem rereadcfg.


Danke für deine Mühe!, glaub dieses feature/fix wird so einigen freuen  :D (hatte man ja doch öfter was über dieses Problem gelesen).


Dass er das hier immer noch bringt ist gewollt, oder?

2014.11.20 00:52:45 1: SONOS0: Connection accepted from localhost:41049
2014.11.20 00:53:15 1: SONOS0: Connection accepted from localhost:41050
2014.11.20 00:53:45 1: SONOS0: Connection accepted from localhost:41051

Da ja rein rechnerisch Port 65.535 nach knappen 9 Tagen erreicht wird, was passiert dann? ;D


Gruß Claudiu

Reinerlein

Hi Claudiu,

schön, das es jetzt geht :)

Kurze Erklärung:
Der Subprozess meldet sich mit einer Begrüßung. Diesen String hatte ich im Fhem-Modul aber nie weggelesen. In deiner Perl-Implementierung scheinen ihn die nicht abgeholten Daten gestört zu haben...

Zu der Portnummer: Die wird ja vom Betriebsystem zufällig ausgesucht, und nach dem Versuch sauber wieder freigegeben. Das ganze geht also irgendwann woanders weiter.
Mich wundert sowieso, dass das so monoton aufsteigend ist. Da zerbrechen sich viele Sicherheitsexperten den Kopf darüber, dass genau das ein Problem sein könnte, und trotzdem ist es noch so implementiert...
Naja, soll uns egal sein. Das entscheidet das Betriebssystem :)

Grüße
Reinerlein

yetiman

Hi Reinerlein,

seit dem letzten Dev Update schnappt sich das Sonos Modul die komplette CPU von meinem RaPi :-((

fhem      2405 10.5  8.4  43456 37676 pts/0    R    09:28   0:44 perl fhem.pl fhem.cfg
fhem      2411 87.4  6.3  49812 28392 pts/0    Rl   09:29   6:00 perl FHEM/00_SONOS.pm 4711 3
root      2471  0.0  0.2   4460  1136 pts/0    R+   09:35   0:00 ps aux


Ingo

Reinerlein

Hi Ingo,

Himmel, du hast recht. Da habe ich gar nicht drauf geachtet :-[
Ich schaue mir das an, danke für den Hinweis.

Grüße
Reinerlein

rapster

Hi Reinerlein,

danke für den Hinweis worans lag.
Das mit den Ports klingt ja dann ok, sah nur echt komisch aus weils so sauber raufgezählt wird  ;)

Zu Ingo seinem Problem, das liegt nicht am Raspi, wenn man dem Prozess einige Ghz mehr gibt verschlingt er diese auch komplett merke ich grad  ;D
Mir ist aber aufgefallen dass dies nicht kontinuirlich auftritt, sondern ich denke immer passend zum eingestellten Intervall, und sich anschließend wieder normalisiert.

Gruß Claudiu

Reinerlein

Hi Claudiu,

ich bin da gerade dran... ich hatte heute z.B. auch das Problem, dass mein Fhem einfach aus war. Der Prozess war sang- und klanglos verstorben.
Das Problem meine ich gefunden zu haben: Die Ports wurden auf Client-Seite tatsächlich nicht wirklich geschlossen, sondern nur als zum schließen markiert.
Das habe ich schon angepasst, leider ändert es an den 100% nichts. Die treten sofort auf, wenn man eine neue Telnet-Verbindung mit dem Subprozess aufmacht, und bleiben dann auch da oben (trotz echten Portschließens)...

Aber ich bin guter Dinge :)

Grüße
Reinerlein

rapster

Hi Reinerlein,

Super!  8)
ja das Problem mit dem verstorbenen Fhem hatten Ingo und Ich auch, nach ~8Stunden ist Fhem einfach weg gewesen bei mir.

Danke dir, Gruß Claudiu

Reinerlein

Hallo zusammen,

ich habe eine neue Version im Dev-Bereich eingestellt.
Bitte alle, die bei sich die Dev-Version installiert haben, auf diese neue Version umstellen.

Hier ist das Problem mit der 100% CPU-Last behoben, und, was viel wichtiger ist, die Ports werden wieder freigegeben.
Ich denke letzteres war die Ursache für den Fhem-Abschied. Aber da weiss ich natürlich erst genaueres, wenn die 6-8 Stunden um sind :)

Grüße
Reinerlein

rapster

Hi Reinerlein,

danke, funktioniert soweit schonmal alles! :-)

Wir werden sehen wie es heute Abend aussieht  ;)

Gruß Claudiu

Reinerlein

Hallo zusammen,

nach knapp 10 Stunden Fhem-Betrieb ohne Ausfälle würde ich von meiner Seite aus sagen, dass das Absturzproblem vom Tisch ist.

Wenn bis nächste Woche keine größeren Dinge mehr auftauchen, dann würde ich diese Version auch gerne in den normalen Downloadbereich verschieben...

Also bitte noch testen :)

Grüße
Reinerlein

rapster

#60
Hi Reinerlein,

nach gut 14 Stunden Fhem-Betrieb schauts bei mir auch noch prima aus ;D

Zwar heut nicht wirklich viel in fhem "gebastelt", aber wir achten mal drauf ob uns noch was auffällt.
Im Moment schauts auf jedenfall Super aus, danke dir!

Das einzige was mir aufgefallen ist, dass ein rereadcfg mit dem notify welches den Subprozess direkt gekillt hat etwas schneller fertig war.
Das ist aber schon wieder jammern auf hohem Niveau, dass alles funktioniert ist mal das wichtigste  ;)

Denk auch dass wenn keine Probleme mehr auftreten, es wert wäre ein normales release draus zu machen, sind ja nun doch einige hilfreiche features hinzugekommen!


Gruß Claudiu


yetiman

Hi,

heute früh nur wieder Status "initialized".
Nur ein kompletter reboot des RaPi hat geholfen :-(

Ingo


Gesendet von iPhone mit Tapatalk

Reinerlein

#62
Hi Ingo,

hast du schon die Version von heute Nacht (irgendwann gegen 2:20Uhr) installiert?
Dort habe ich noch einiges mit den Events umgebaut, da ich es ja, wie geschrieben, falsch verstanden hatte :)

Grüße
Reinerlein

P.S.: Ich sehe gerade, dass da keine Nachricht von mir ist... ich bin aber der Meinung, eine geschrieben zu haben... komisch...

Edit: Hab es gefunden... war eine Antwort zu einem anderen Themenbeitrag... war auch schon spät ;D

yetiman

Nein, hätte ich noch nicht. Mach ich gleich.


Gesendet von iPhone mit Tapatalk

aherby

Hallo Reinerlein,

ein Test gestern hat einen positiven Effekt auf das Umschalten der Playbar auf den Eingang (TV) gebracht.
Danke dafür. es ist super wie schnell hier Lösungen geschaffen werden.

Ich weiß nicht ob das mit dem Songs-Modul-Update oder einem anderen Update zusammenhängt aber
sobald ich z.b. folgenden Befehl "define Radio.YouFM notify BT5_YouFM_Hr3.Short.* set Sonos_Wechselraum Volume 21 ;; set Sonos_Wechselraum PlayURI http://metafiles.gl-systemhaus.de/hr/youfm_2.m3u ;; set Sonos_Wechselraum Play" aufführe oder halt den Taster betätigt hängt sich der FHEM auf. Hat sich die Syntax geändert oder ist es einfach nur von mir schlecht ,,programmiert"?

Danke
FHEM 6.0 auf Raspberry Pi 4b 4GB, RaspberryMatic auf Raspi3b mit Charly-Funkmodul, ZigeeBridge mt deCONZ... . Homematic mittels HMCCU, Sonos 3xS1, 1xS6 (Play5 in der 2te Generation), 1xS9 (Soundbar), 1x SonosSub
1-Wire® to I2C host interface with ESD mit DS18B/S20.

Reinerlein

Hi aherby,

hmm.. so ohne Logs etwas schwierig zu sagen. Was ich auf jeden Fall sagen kann, ist, dass du einige Befehle zu viel hast:
PlayURI startet bereits die Wiedergabe, ein zusätzliches Play brauchst du nicht mehr...
Außerdem kannst du bei PlayURI direkt eine Lautstärke mitgeben.

Damit reduziert sich deine Befehlsfolge sowieso auf ein Element, und sollte hoffentlich funktionieren :)

Wenn es trotzdem schiefgeht, bitte die Logs durchschauen (und/oder posten). Tipps dazu gibt es auch auf der Wiki-Seite.

Grüße
Reinerlein