State incompletely restored when streaming via optical input

[kalbfuss]

I have noticed that the state is not correctly/completely restored by the teufel_raumfeld.snapshot/restore service combination, when streaming sound via the optical input.

Steps for reproduction:

1. Play radio station via TuneIn
2. Set source to optical input (television)
3. Create snapshot via teufel_raumfeld.snapshot
4. Apply various changes, e.g. play message via TTS
5. Restore state via teufel_raumfeld.restore

After step 5, the Raumfeld media player should be streaming sound from the optical input again. Instead, it continues to play the radio station.
I am using a Teufel Cinebar Lux with firmware v2.15.1. The Teufel Raumfeld integration is installed with version 71cdd42.

[B5r1oJ0A9G]

Thanks for the feedback!

I could imagine that the use of optical input requires some missing attributes in the data structure. As I do not have a soundbar to test I cannot reproduce it on my end it. It could help to have some DEBUG log information from teufel_raumfeld. See: Wiki, Debugging information.

[kalbfuss]

Good morning B5r1oJ0A9G,
Thanks for your response and apologies for my late reply. My Teufel Raumfeld integration broke with the update to Home Assistant 2022.4.7. I noticed today that a new alpha version is available and installed it immediately. Teufel devices seem to be back online. I am going to test for a couple more days and if successful plan to provide the additional debug information as requested.

[B5r1oJ0A9G]

The integration is fixed again. If you @kalbfuss , or someone else, can provide debug information, I could take a look.

[kalbfuss]

I confirm that the teufel_raumfeld integration works again with Home Assistant 2023.7.3. It is so much fun, when the radio turns on automatically in the morning after I entered the kitchen. @B5r1oJ0A9G Thank you so much for this!
I am going to do some testing regarding state restoration when I find the time.

[kalbfuss]

Here we go:

2023-07-23 10:02:41.083 DEBUG (MainThread) [custom_components.teufel_raumfeld] media_player.py->async_play_media: media_id=media-source://tts/cloud?message=Liebe+Kinder,+h%C3%B6rt+mir+bitte+kurz+zu..+Falls+ihr+zur+ersten+Stunde+Schule+habt,+dann+ist+es+Zeit+zu+gehen.
2023-07-23 10:02:41.092 WARNING (MainThread) [homeassistant.helpers.frame] Detected integration that calls media_source.async_resolve_media without passing an entity_id. Please report issue for media_source using this method at homeassistant/components/media_source/__init__.py, line 151: report("calls media_source.async_resolve_media without passing an entity_id")
2023-07-23 10:02:41.095 DEBUG (MainThread) [custom_components.teufel_raumfeld] media_player.py->async_play_media: self._rooms=['Cinebar Lux'], play_uri=http://192.168.178.16:8123/api/tts_proxy/adf67701f817a8f44eb8272ca509dcb7fff5cc8f_de-de_e09b5a0968_cloud.audiooutput.mp3
2023-07-23 10:02:41.688 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '2' out of '16' attempts for transport state update
2023-07-23 10:03:04.005 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '2' out of '16' attempts for transport state update
2023-07-23 10:03:04.356 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '3' out of '16' attempts for transport state update
2023-07-23 10:03:04.734 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '4' out of '16' attempts for transport state update
2023-07-23 10:03:05.112 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '5' out of '16' attempts for transport state update
2023-07-23 10:03:05.501 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '6' out of '16' attempts for transport state update
2023-07-23 10:03:05.862 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '7' out of '16' attempts for transport state update
2023-07-23 10:03:06.246 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '8' out of '16' attempts for transport state update
2023-07-23 10:03:06.633 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '9' out of '16' attempts for transport state update
2023-07-23 10:03:06.989 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '10' out of '16' attempts for transport state update
2023-07-23 10:03:07.387 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '11' out of '16' attempts for transport state update
2023-07-23 10:03:07.777 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '12' out of '16' attempts for transport state update
2023-07-23 10:03:08.164 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '13' out of '16' attempts for transport state update
2023-07-23 10:03:08.545 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '14' out of '16' attempts for transport state update
2023-07-23 10:03:08.926 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '15' out of '16' attempts for transport state update
2023-07-23 10:03:09.327 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '16' out of '16' attempts for transport state update
2023-07-23 10:03:13.234 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '2' out of '16' attempts for transport state update
2023-07-23 10:03:13.629 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '3' out of '16' attempts for transport state update
2023-07-23 10:03:14.023 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '4' out of '16' attempts for transport state update
2023-07-23 10:03:14.371 DEBUG (MainThread) [custom_components.teufel_raumfeld] Starting attempt '5' out of '16' attempts for transport state update
2023-07-23 10:05:33.813 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.898 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.898 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.898 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Unsupported Object ID: 0/Spotify
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Building of playable URI for media type 'object.container' not needed or not implemented
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Unsupported Object ID: 0/Zones
2023-07-23 10:05:33.899 DEBUG (MainThread) [custom_components.teufel_raumfeld] Unsupported Object ID: 0/Renderers

[B5r1oJ0A9G]

In regards to:

2023-07-23 10:02:41.092 WARNING (MainThread) [homeassistant.helpers.frame] Detected integration that calls media_source.async_resolve_media without passing an entity_id. Please report issue for media_source using this method at homeassistant/components/media_source/__init__.py, line 151: report("calls media_source.async_resolve_media without passing an entity_id")

It has been fixed with: 72cac9b

To follow-up on the actual issue, the question is how the input source like optical or non-optical input could be determined and set... Once we figure that out, we should be able to implement it being saved to and restored from a snapshot easily.

[B5r1oJ0A9G]

In release 0.1.14a1 support for "announce" is implemented (See: https://www.home-assistant.io/integrations/media_player/). Alongside with this, hassfeld will log the snapshot data:

2023-07-23 18:22:14.533 DEBUG (MainThread) [hassfeld] __init__.py->async_save_zone: Creating snapshot: 'snap[['Küche', 'Wohnzimmer']]' = '{'uri': 'http://10.0.107.12:8888/stream.flac', 'metadata': '<?xml version="1.0"?>\n<DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:raumfeld="urn:schemas-raumfeld-com:meta-data/raumfeld" xmlns:pv="http://www.pv.com/pvns/"><item parentID="0/Line In" restricted="1" id="0/Line In/uuid%3A92270b01-bbf4-4ffe-b4b6-b2047bcd63e0"><upnp:class>object.item.audioItem.audioBroadcast.lineIn</upnp:class><raumfeld:section>Line In</raumfeld:section><dc:title>Speaker Wohnzimmer</dc:title><raumfeld:name>Line In</raumfeld:name><res protocolInfo="http-get:*:audio/x-flac:*">http://10.0.107.12:8888/stream.flac</res></item></DIDL-Lite>\n', 'abs_time': '00:00:16', 'fii_par': '&fii=0', 'volume': 24, 'mute': False}'

Before we invesitate how to switch the optical input, I'd like to check whether there might be something wrong in the URI. In case you update to the version 0.1.14a1, could you please listen to the optical input, after some time (>=10 seconds) send a TTS event and send back the logged line similar to the one above? Below you'll find an example for such a TTS event (remember to change the entity_id)

service: tts.google_translate_say
data:
  entity_id: media_player.group_kuche_wohnzimmer
  message: >-
    This is a test to fix the problem of incomplete status recovery when
    streaming via optical input.