The problem

'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

What version of Home Assistant Core has the issue?

2023.3.2

What was the last working version of Home Assistant Core?

2023.2

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Sonos

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

Hey there @cgtobi, @jjlawren, mind taking a look at this issue as it has been labeled with an integration (sonos) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `sonos` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign sonos` Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

sonos documentation sonos source _{^{(message by IssueLinks)}}

Can you clarify the specific problem you're encountering and provide details/logs?

Sorry, missed the case description.

it happens after some time but is resolved only after reloading the integration.

happens on all sonos service calls

started when i added one additional symfonisk to my system and or de upgrade to 2023.3. Not sure tbh. Next to that i have a a quite big system (22 speakers) but all in the same vlan as sonos (unifi)

will try to generate a debug log when it happens. Btw where can i find the debug log when enabled?

Sonos app works without issues. And after reload of integration it is working for some period. But after x min it stops.

Error( but also happens by other servicecalls ( snapshot, restore etc)

🔉 Sonos Besturing: Choose at step 1: choice 4: Error executing script. Error for call_service at pos 1: Error calling SonosMediaPlayerEntity.media_stop on media_player.kantoor: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled 🔉 Sonos Besturing: Error executing script. Error for choose at pos 1: Error calling SonosMediaPlayerEntity.media_stop on media_player.kantoor: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

Hi just disconnected the newly added symfonisk v2 (speaker 22) so now only 21 in the system. And it seems now stable for several hours.

I will try to hard wire that speaker tomorrow to try if the issue comes back.

and ideas?

Large systems were not supported by the Sonos integration until https://github.com/home-assistant/core/pull/85411 was added in the 2023.2 release. However, that new functionality requires network setups which allow subscription callbacks from the Sonos devices to HA in order to work properly. Do you have errors or warnings in your logs regarding Sonos subscriptions failing?

Not i can see? Is this related to the port 1400 callbacks? I cant imagine since they are in the same vlan as has (unifi). I will reconnect no 22 and start testing again and monitor for these errors in de has log. Does debug logging need to be enabled to see these?

Maybe also good to mention, i use mostly cabled connections to my sonos devices only 3 + the newly added are connected to wifi (NOT sonosnet)

do i understand correctly that if you have a big system its better to configure the sonos integration via the manual fixed IPs?;

Example configuration.yaml entry with manually specified Sonos IP addresses

sonos: media_player: hosts:

192.0.2.25
192.0.2.26
192.0.2.27

took 30 min until it happenned again hereby part of the debug logging;

2023-03-05 09:08:52.973 DEBUG (SyncWorker_19) [soco.services] Received {'CONTENT-LENGTH': '347', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'EXT': '', 'Server': 'Linux UPnP/1.0 Sonos/71.1-38080 (ZPS14)', 'Connection': 'close'}, s:ClientUPnPError501</s:Fault></s:Body></s:Envelope> 2023-03-05 09:08:52.973 DEBUG (SyncWorker_19) [soco.services] Received status 500 from 192.168.1.157 2023-03-05 09:08:52.974 DEBUG (SyncWorker_19) [soco.services] Error b's:ClientUPnPError501</s:Fault></s:Body></s:Envelope>' 2023-03-05 09:08:52.974 DEBUG (SyncWorker_19) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.157) raised on 'GetZoneGroupState()' 2023-03-05 09:08:52.974 DEBUG (SyncWorker_19) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK) 2023-03-05 09:08:52.977 ERROR (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Serre: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled 2023-03-05 09:08:52.978 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Serre: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled 2023-03-05 09:08:52.979 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Error executing script. Error for choose at pos 1: Error calling SonosSpeaker.snapshot on Serre: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled 2023-03-05 09:08:52.981 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Error while executing automation automation.poort_besturing: Error calling SonosSpeaker.snapshot on Serre: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled 2023-03-05 09:09:01.193 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000106 2023-03-05 09:09:01.194 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000107 2023-03-05 09:09:01.194 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000109 2023-03-05 09:09:01.195 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000111 2023-03-05 09:09:01.196 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000108 2023-03-05 09:09:01.197 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_542A1B8FD63B01400_sub0000000110 2023-03-05 09:09:01.203 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/MediaServer/ContentDirectory/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000106 2023-03-05 09:09:01.204 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/AlarmClock/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000111 2023-03-05 09:09:01.204 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/MediaRenderer/AVTransport/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000109 2023-03-05 09:09:01.205 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/DeviceProperties/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000107 2023-03-05 09:09:01.205 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/ZoneGroupTopology/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000108 2023-03-05 09:09:01.206 DEBUG (MainThread) [soco.events_base] Renewed subscription to http://192.168.1.157:1400/MediaRenderer/RenderingControl/Event, sid: uuid:RINCON_542A1B8FD63B01400_sub0000000110 2023-03-05 09:09:01.370 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000504 2023-03-05 09:09:01.370 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000505 2023-03-05 09:09:01.371 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000506 2023-03-05 09:09:01.371 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000507 2023-03-05 09:09:01.372 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000503 2023-03-05 09:09:01.372 DEBUG (MainThread) [soco.events_base] Autorenewing subscription uuid:RINCON_347E5CF51F7201400_sub0000000508

but i dont see any subscription failing messages.

now testing by connecting speaker no. 22 wired (wifi disabled) not sure of this will help, but worth the try. Also tried fixing via yaml, but this is not helping the issue at hand. so rolled back to discovery mode.

Could a split in S1 and S2 Help?

In addition hardwired 2 additional speakers, which resulted that it was working without issues for a longer time but eventually same issue occurs. Could this be related to a timeout on a groupstate request, which result in not trying this again? Since again when reloading the sonos integration it is working fine again for some time.

The underlying problem is that polling for the "ZoneGroupState" (the complete view of the Sonos system's structure) on large systems fails as the Sonos firmware errors out when the payload gets over a certain size. It has no problem sending this payload over a subscription callback, however. We need to be careful to avoid making these polling calls on large systems as we know they'll likely fail. We do use a cache, but we obtain a lot of data from these ZoneGroupState payloads and it's possible we're unintentionally making a poll. We also clear this cache during regrouping operations, so perhaps that's what's leading to the poll request.

You may see this error intermittently depending on how many active speakers you have, but also the specific grouping of the speakers. Lots of individual ungrouped speakers will lead to more information in the payload and increase its size.

The debug log above looks like (all of) soco is in debug, but not homeassistant.components.sonos. A more targeted debug log config might look like this:

logger:
  default: info
  logs:
    homeassistant.components.sonos: debug
    soco.zonegroupstate: debug

One more question: besides the errors in the logs do you encounter any actual usability issues? It's unclear from your description.

Yeah i found indeed the payload issues as mentioned in #85411. Yes the services wont executed including tts is not played anymore once this happens but also restores and snapshots. Joining unjoining i dont use atm. And again its not being recovered

I will add that debug logging later today and reconnect the speaker to test again.

EDIT: I have the debug logs. What i can see is that first hour i got the same errors but the servicecalls work ( play tts etc) but at 11:25, The speakers are not responding anymore to the service calls (no TTS being played).

2023-03-06 11:21:17.046 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Slaapkamer from discovery
2023-03-06 11:21:17.061 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Garage from discovery
2023-03-06 11:21:17.096 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Serre from discovery
2023-03-06 11:21:17.168 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kinderkamer from discovery
2023-03-06 11:21:17.332 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Keuken from discovery
2023-03-06 11:21:17.344 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from discovery
2023-03-06 11:21:17.384 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Zolder from discovery
2023-03-06 11:21:17.432 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Subwoofer from discovery
2023-03-06 11:21:17.476 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Woonkamer from discovery
2023-03-06 11:21:17.506 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kantoor from discovery
2023-03-06 11:21:17.527 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Gang from discovery
2023-03-06 11:21:17.550 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Badkamer from discovery
2023-03-06 11:21:19.967 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Running automation actions
2023-03-06 11:21:19.968 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Running automation actions
2023-03-06 11:21:19.968 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Executing step call service
2023-03-06 11:21:22.524 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:21:22.524 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:21:33.901 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:21:37.517 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:21:37.517 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:21:52.525 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:21:52.525 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:21:53.981 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:22:07.520 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:22:07.520 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:22:13.969 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:22:22.546 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:22:22.547 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:22:33.901 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:22:37.524 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:22:37.524 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:22:52.538 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:22:52.538 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:22:53.895 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:23:07.532 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:23:07.532 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:23:13.888 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:23:17.049 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Serre from discovery
2023-03-06 11:23:17.062 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Woonkamer from discovery
2023-03-06 11:23:17.086 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Gang from discovery
2023-03-06 11:23:17.147 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Slaapkamer from discovery
2023-03-06 11:23:17.209 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kinderkamer from discovery
2023-03-06 11:23:17.313 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Garage from discovery
2023-03-06 11:23:17.342 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from discovery
2023-03-06 11:23:17.391 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kantoor from discovery
2023-03-06 11:23:17.410 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Zolder from discovery
2023-03-06 11:23:17.453 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Subwoofer from discovery
2023-03-06 11:23:17.534 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Keuken from discovery
2023-03-06 11:23:17.611 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Badkamer from discovery
2023-03-06 11:23:19.968 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Running automation actions
2023-03-06 11:23:19.969 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Running automation actions
2023-03-06 11:23:19.969 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Executing step call service
2023-03-06 11:23:22.540 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:23:22.540 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:23:31.194 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: climate waterflow_sensor ict_rack_temperatuur_controller, sending update
2023-03-06 11:23:31.194 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: switch waterflow_sensor waterflow_sensor_restart, sending update
2023-03-06 11:23:31.196 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor server_rack_temperatuur, sending update
2023-03-06 11:23:31.197 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor server_rack_luchtvochtigheid, sending update
2023-03-06 11:23:31.198 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor water_flow_lmin, sending update
2023-03-06 11:23:31.221 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor water_flow_lh, sending update
2023-03-06 11:23:31.223 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor total_dagelijks_water_verbruik_l, sending update
2023-03-06 11:23:31.223 INFO (MainThread) [homeassistant.components.mqtt.discovery] Component has already been discovered: sensor waterflow_sensor total_dagelijks_water_verbruik_m3, sending update
2023-03-06 11:23:33.957 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:23:37.523 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:23:37.523 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:23:52.571 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:23:52.571 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:23:55.001 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:24:07.603 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:24:07.603 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:24:09.676 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Running automation actions
2023-03-06 11:24:09.677 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Running automation actions
2023-03-06 11:24:09.677 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Executing step call service
2023-03-06 11:24:09.679 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Running automation actions
2023-03-06 11:24:09.679 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Executing step call service
2023-03-06 11:24:09.683 INFO (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Running script sequence
2023-03-06 11:24:09.684 INFO (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Executing step call service
2023-03-06 11:24:09.685 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Restarting
2023-03-06 11:24:09.692 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Running automation actions
2023-03-06 11:24:09.693 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Running automation actions
2023-03-06 11:24:09.693 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step device automation
2023-03-06 11:24:09.703 DEBUG (SyncWorker_29) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.169) raised on 'GetZoneGroupState()'
2023-03-06 11:24:09.703 DEBUG (SyncWorker_29) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-06 11:24:09.703 ERROR (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:09.705 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:09.705 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Error executing script. Error for choose at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:09.706 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Error while executing automation automation.poort_besturing: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:10.465 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Test condition state: True
2023-03-06 11:24:10.465 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step delay 0:03:00
2023-03-06 11:24:13.903 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:24:22.569 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:24:22.570 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:24:25.334 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:24:25.335 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:24:28.568 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Running automation actions
2023-03-06 11:24:28.568 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Executing step call service
2023-03-06 11:24:28.570 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Restarting
2023-03-06 11:24:28.573 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Running automation actions
2023-03-06 11:24:28.573 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Running automation actions
2023-03-06 11:24:28.574 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step device automation
2023-03-06 11:24:28.620 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Test condition state: True
2023-03-06 11:24:28.620 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step delay 0:03:00
2023-03-06 11:24:33.911 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:24:40.298 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:24:40.298 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:24:42.151 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Running automation actions
2023-03-06 11:24:42.152 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Running automation actions
2023-03-06 11:24:42.152 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Executing step call service
2023-03-06 11:24:42.158 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Running automation actions
2023-03-06 11:24:42.158 INFO (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Executing step call service
2023-03-06 11:24:42.161 INFO (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Running script sequence
2023-03-06 11:24:42.161 INFO (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Executing step call service
2023-03-06 11:24:42.162 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Restarting
2023-03-06 11:24:42.172 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Running automation actions
2023-03-06 11:24:42.175 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Running automation actions
2023-03-06 11:24:42.175 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step device automation
2023-03-06 11:24:42.181 DEBUG (SyncWorker_10) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.169) raised on 'GetZoneGroupState()'
2023-03-06 11:24:42.181 DEBUG (SyncWorker_10) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-06 11:24:42.182 ERROR (MainThread) [homeassistant.components.script.sonos_say] Sonos TTS script: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:42.184 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Choose at step 1: choice 1: Error executing script. Error for call_service at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:42.185 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Poort Besturing : Error executing script. Error for choose at pos 1: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:42.186 ERROR (MainThread) [homeassistant.components.automation.poort_besturing] Error while executing automation automation.poort_besturing: Error calling SonosSpeaker.snapshot on Dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:24:42.663 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Test condition state: True
2023-03-06 11:24:42.663 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step delay 0:03:00
2023-03-06 11:24:49.989 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Running automation actions
2023-03-06 11:24:49.989 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Running automation actions
2023-03-06 11:24:49.989 INFO (MainThread) [homeassistant.components.automation.cv_opentherm_besturing] 🌡️ 🔥 CV Opentherm Besturing: Choose at step 1: choice 1: Executing step call service
2023-03-06 11:24:50.547 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'TodayEnergy1b' when rendering '{{ value_json['ZbReceived']['0x9AB3']['dc']['TodayEnergy1b'] }}'
2023-03-06 11:24:50.549 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'TodayEnergy2b' when rendering '{{ value_json['ZbReceived']['0x9AB3']['dc']['TodayEnergy2b'] }}'
2023-03-06 11:24:50.848 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Running automation actions
2023-03-06 11:24:50.848 INFO (MainThread) [homeassistant.components.automation.triggers_camerascherm] 🎞️ Triggers CameraScherm: Executing step call service
2023-03-06 11:24:50.850 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Restarting
2023-03-06 11:24:50.856 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Running automation actions
2023-03-06 11:24:50.856 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Running automation actions
2023-03-06 11:24:50.856 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step device automation
2023-03-06 11:24:50.942 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Test condition state: True
2023-03-06 11:24:50.943 INFO (MainThread) [homeassistant.components.automation.camerascherm_besturing] 🎞️ Camerascherm besturing: Choose at step 1: choice 2: Executing step delay 0:03:00
2023-03-06 11:24:53.908 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:24:55.312 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Running automation actions
2023-03-06 11:24:55.312 INFO (MainThread) [homeassistant.components.automation.mqtt_publish_sensor_data] 📤 MQTT Publish sensor data : Executing step call service
2023-03-06 11:25:00.194 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Running automation actions
2023-03-06 11:25:00.194 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:01.375 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:01.950 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:02.522 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:03.018 DEBUG (SyncWorker_31) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.169) raised on 'GetZoneGroupState()'
2023-03-06 11:25:03.019 DEBUG (SyncWorker_31) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-06 11:25:03.020 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140223056094896] Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 192.168.1.169

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:25:03.123 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:03.708 INFO (MainThread) [homeassistant.components.automation.pvoutput_upload_5min] 📤  PVOutput Upload (5min): Executing step call service
2023-03-06 11:25:06.208 DEBUG (SyncWorker_32) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.169) raised on 'GetZoneGroupState()'
2023-03-06 11:25:06.208 DEBUG (SyncWorker_32) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-06 11:25:06.213 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140223056094896] Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 192.168.1.169

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:25:08.463 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from SonosSwitchEntity.send_command
2023-03-06 11:25:08.523 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from RenderingControl subscription

2023-03-06 11:25:11.076 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from SonosSwitchEntity.send_command
2023-03-06 11:25:11.106 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from RenderingControl subscription
2023-03-06 11:25:13.305 DEBUG (SyncWorker_3) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 192.168.1.169) raised on 'GetZoneGroupState()'
2023-03-06 11:25:13.306 DEBUG (SyncWorker_3) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-06 11:25:13.308 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140223056094896] Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 192.168.1.169

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.dressoir: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-06 11:25:13.877 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'dict object' has no attribute 'Temperature' when rendering '{{ value_json['ENERGY']['Temperature'] }}'
2023-03-06 11:25:17.104 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Dressoir from discovery
2023-03-06 11:25:17.111 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kantoor from discovery
2023-03-06 11:25:17.207 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Slaapkamer from discovery
2023-03-06 11:25:17.267 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Gang from discovery
2023-03-06 11:25:17.268 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Garage from discovery
2023-03-06 11:25:17.282 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Badkamer from discovery
2023-03-06 11:25:17.314 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Subwoofer from discovery
2023-03-06 11:25:17.316 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Kinderkamer from discovery
2023-03-06 11:25:17.364 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Woonkamer from discovery
2023-03-06 11:25:17.381 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Serre from discovery
2023-03-06 11:25:17.411 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Zolder from discovery
2023-03-06 11:25:17.467 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Keuken from discovery

is there a way to send you the full debug logs directly?

I have the same thing, my cause is that I have two houseId's running. One for Sonos S1 and one for Sonos S2.

Previously I handled this by using the Advanced use You can disable auto-discovery by specifying the Sonos IP addresses but it seems the last version now bypasses this disable auto-discovery breaking the Sonos integration when you have multiple households.

It seems there is an option in Soco to specify a household id, could that be a solution to add support for specifying a householdId. Or at enable the disable the auto check feature again upply a Sonos Household ID to restrict discovery to a specific household

@DagBertelsen that's a different issue, would you mind creating a separate issue?

@bartbakels my working theory is that there are lengths of time without activity that exceed the subscription renewal period (~20 minutes), which is also the current length of time we expire cache entries after. My guess is if you encounter this error and then regroup any speakers using the native Sonos app, then the HA integration would begin working again. Could you verify this behavior?

@jjlawren Sure, i just enabled the additional speaker. However just to be sure, i need to group or ungroup some speakers for this test via the app? to test it the servicecalls are responding again?

I will test and report back later today

We just need a subscription callback to happen to repopulate the cache so we can skip those polling calls again. It may work if you use HA to regroup, but you will likely hit the same error. Just using the native Sonos app would be easiest I'd think.

just confirmed, as soon as i start even something to play from sonos radio for example it is also working again, so we can presume your theory is correct. @jjlawren

Hello.

I too am having this same issue. 27 zones and all works fine fore maybe 10 minutes when i reload the sonos integration. after that i get the same error.

i enabled deboug log on the integration and triggered the issue.

if there is any way i can help out let me know. i can do any tests and try out any code as needed

Thanks

here is my log

2023-03-07 21:42:17.125 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-03-07 21:42:17.125 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration shelly which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-03-07 21:42:23.484 WARNING (MainThread) [homeassistant.helpers.frame] Detected integration that uses deprecated `async_get_registry` to access entity registry, use async_get instead. Please report issue to the custom integration author for shelly using this method at custom_components/shelly/__init__.py, line 356: await self.hass.helpers.entity_registry.async_get_registry()
2023-03-07 21:42:28.205 ERROR (MainThread) [metno] Access to https://aa015h6buqvih86i1.api.met.no/weatherapi/locationforecast/2.0/complete returned error 'ClientConnectorError'
2023-03-07 21:42:28.210 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Home' for met integration not ready yet: Update failed: ; Retrying in background
2023-03-07 21:42:32.853 WARNING (MainThread) [homeassistant.setup] Setup of lutron is taking over 10 seconds.
2023-03-07 21:42:33.600 ERROR (S4H-WebSocket) [websocket] 'NoneType' object has no attribute 'sock' - goodbye
2023-03-07 21:42:33.801 WARNING (SyncWorker_6) [pylutron] Occupancy Group not found for Area: Segundo Nivel; ID: 0
2023-03-07 21:42:33.806 WARNING (SyncWorker_6) [pylutron] Occupancy Group not found for Area: Dormitorio Master; ID: 0
2023-03-07 21:42:33.811 WARNING (SyncWorker_6) [pylutron] Occupancy Group not found for Area: Sotano; ID: 0
2023-03-07 21:42:33.813 WARNING (SyncWorker_6) [pylutron] Occupancy Group not found for Area: Primer Nivel; ID: 0
2023-03-07 21:42:46.855 WARNING (MainThread) [homeassistant.components.light] Setup of light platform lutron is taking over 10 seconds.
2023-03-07 21:44:41.508 ERROR (MainThread) [homeassistant.components.automation.bano_visita_estudio_play_music] BANO VISITA ESTUDIO - Play Music: Choose at step 7: default: Error executing script. Error for call_service at pos 1: Error calling SonosMediaPlayerEntity.play_media on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:41.513 ERROR (MainThread) [homeassistant.components.automation.bano_visita_estudio_play_music] BANO VISITA ESTUDIO - Play Music: Error executing script. Error for choose at pos 7: Error calling SonosMediaPlayerEntity.play_media on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:41.516 ERROR (MainThread) [homeassistant.components.automation.bano_visita_estudio_play_music] Error while executing automation automation.bano_visita_estudio_play_music: Error calling SonosMediaPlayerEntity.play_media on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:44.240 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140315931732832] Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 10.10.31.96

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:46.905 ERROR (MainThread) [homeassistant.components.automation.bano_visita_estudio_stop_music] BANO VISITA ESTUDIO - Stop Music: Error executing script. Error for call_service at pos 7: Error calling SonosMediaPlayerEntity.media_pause on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:46.908 ERROR (MainThread) [homeassistant.components.automation.bano_visita_estudio_stop_music] Error while executing automation automation.bano_visita_estudio_stop_music: Error calling SonosMediaPlayerEntity.media_pause on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:44:54.093 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140315860850464] Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 10.10.31.96

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:45:00.857 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140315860850464] Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 10.10.31.96

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:45:04.527 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140315860850464] Error calling SonosMediaPlayerEntity.media_next_track on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 10.10.31.96

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 477, in media_next_track
    self.coordinator.soco.next()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 769, in async_media_next_track
    await self.hass.async_add_executor_job(self.media_next_track)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_next_track on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
2023-03-07 21:45:54.387 DEBUG (SyncWorker_27) [soco.services] Request timeout set to 9.5
2023-03-07 21:45:54.387 DEBUG (SyncWorker_27) [soco.services] Sending GetZoneGroupState [] to 10.10.31.96
2023-03-07 21:45:54.388 DEBUG (SyncWorker_27) [soco.services] Sending {'Content-Type': 'text/xml; charset="utf-8"', 'SOAPACTION': 'urn:schemas-upnp-org:service:ZoneGroupTopology:1#GetZoneGroupState'}, <?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:GetZoneGroupState xmlns:u="urn:schemas-upnp-org:service:ZoneGroupTopology:1"/>
  </s:Body>
</s:Envelope>

2023-03-07 21:45:54.398 DEBUG (SyncWorker_27) [soco.services] Received {'CONTENT-LENGTH': '347', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'EXT': '', 'Server': 'Linux UPnP/1.0 Sonos/71.1-38080 (ZPS16)', 'Connection': 'close'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><s:Fault><faultcode>s:Client</faultcode><faultstring>UPnPError</faultstring><detail><UPnPError xmlns="urn:schemas-upnp-org:control-1-0"><errorCode>501</errorCode></UPnPError></detail></s:Fault></s:Body></s:Envelope>
2023-03-07 21:45:54.398 DEBUG (SyncWorker_27) [soco.services] Received status 500 from 10.10.31.96
2023-03-07 21:45:54.398 DEBUG (SyncWorker_27) [soco.services] Error b'<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><s:Fault><faultcode>s:Client</faultcode><faultstring>UPnPError</faultstring><detail><UPnPError xmlns="urn:schemas-upnp-org:control-1-0"><errorCode>501</errorCode></UPnPError></detail></s:Fault></s:Body></s:Envelope>'
2023-03-07 21:45:54.401 DEBUG (SyncWorker_27) [soco.zonegroupstate] Exception (UPnP Error 501 received: Action Failed from 10.10.31.96) raised on 'GetZoneGroupState()'
2023-03-07 21:45:54.402 DEBUG (SyncWorker_27) [soco.zonegroupstate] ZGT event fallback disabled (config.ZGT_EVENT_FALLBACK)
2023-03-07 21:45:54.403 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140315860850464] Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 157, in poll
    zgs = soco.zoneGroupTopology.GetZoneGroupState()["ZoneGroupState"]
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 206, in _dispatcher
    return self.send_command(action, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 514, in send_command
    self.handle_upnp_error(response.text)
  File "/usr/local/lib/python3.10/site-packages/soco/services.py", line 567, in handle_upnp_error
    raise SoCoUPnPException(
soco.exceptions.SoCoUPnPException: UPnP Error 501 received: Action Failed from 10.10.31.96

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 64, in wrapper
    result = funct(self, *args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/media_player.py", line 462, in media_play
    self.coordinator.soco.play()
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 142, in inner_function
    if not self.is_coordinator:
  File "/usr/local/lib/python3.10/site-packages/soco/core.py", line 482, in is_coordinator
    self.zone_group_state.poll(self)
  File "/usr/local/lib/python3.10/site-packages/soco/zonegroupstate.py", line 171, in poll
    raise NotSupportedException(
soco.exceptions.NotSupportedException: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 198, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1808, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1845, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 213, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 686, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 961, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 726, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/media_player/__init__.py", line 737, in async_media_play
    await self.hass.async_add_executor_job(self.media_play)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/sonos/helpers.py", line 78, in wrapper
    raise SonosUpdateError(message) from err
homeassistant.components.sonos.exception.SonosUpdateError: Error calling SonosMediaPlayerEntity.media_play on media_player.1_2_bano_estudio: 'GetZoneGroupState()' call fails on large Sonos systems and event fallback is disabled

Hi, I've also started having this same issue on 2023.4 - let me know if there's any logs or otherwise needed to help investigate. Thanks

any update on this issue, since planning to add additional sub. However that is part of a surround set, does this then also count into the total speakers which cause this issue?

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

Still relevant. This issue has not been resolved.

Indeed still an issue

Still an issue. Just received this today

Still an issue as of today.

do we have any specifics on if this is avoidable? By that I mean does #85411 only fall back when a timeout error happens/in systems 20+ speakers (meaning if one had <20 speakers it uses subscriptions still and may be more stable)? Do speaker 'sets' (like home theater or stereo pairs) count all individual speakers, or the group as a whole? I currently have 22 individual speakers in my home, across 13 'devices' (e.g. stereo pair is 1 device, sound bar + sub + rears is 1 device) and see this error too often for my liking. I could potentially drop 3 speakers from my setup if I wanted by replacing one of my home theater setups which would bring me to 19 speakers, but that would be a pretty big doing on my part to sell those speakers and replace with a 'traditional' receiver/speaker setup, so I'd really only like to go down that path if I can feel confident that it will result in solid stability for the remaining 19 speakers (12 'devices').

Still an issue for me. I have 16 rooms but 22 speakers so it looks like a stereo pair is 2 speakers and not 1 device. And a home theater is 4 speakers and not 1.

Each physical Sonos speaker or device counts towards the limit, including subs, those in pairs, or home theater surrounds.

As mentioned before, this is a limitation in the Sonos firmware. It looks like there's a hardcoded buffer size which cannot fit large payloads when many devices are in the system. We make the API request, but it chokes and returns an error. We need to rely purely on subscription callbacks for these setups (which is more efficient anyway). Safe caching strategies are always a little tricky.

I don't have enough devices to trigger this issue, but I might have thought of a way to address this in a simpler way than I had in mind before. Let me run some more tests locally to ensure there aren't any obvious regressions.

Happy to test it out for you. I have 24 devices right now.

On Sat, Dec 23, 2023 at 9:49 AM jjlawren @.***> wrote:

Each physical Sonos speaker or device counts towards the limit, including subs, those in pairs, or home theater surrounds.

As mentioned before, this is a limitation in the Sonos firmware. It looks like there's a hardcoded buffer size which cannot fit large payloads when many devices are in the system. We make the API request, but it chokes and returns an error. We need to rely purely on subscription callbacks for these setups (which is more efficient anyway). Safe caching strategies are always a little tricky.

I don't have enough devices to trigger this issue, but I might have thought of a way to address this in a simpler way than I had in mind before. Let me run some more tests locally to ensure there aren't any obvious regressions.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/89128#issuecomment-1868319004, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZBTI7C4FNUFDHCVO6MIO5TYK34PVAVCNFSM6AAAAAAVPEMJLGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNRYGMYTSMBQGQ . You are receiving this because you commented.Message ID: @.***>

Hi. I can also test. I have around 28 devices at a remote location but I can do it remotely

I've suggested an improvement to the ZoneGroupState caching strategy when subscriptions are active: https://github.com/SoCo/SoCo/pull/956.

This has not been merged into the library yet, but I've updated my custom_component repo which mirrors the built-in integration. This is based on the 2023.12.4 release but uses the SoCo library with the linked PR integrated.

To install it:

mkdir -p /config/custom_components
cd /config/custom_components
git clone --branch core-89128 https://github.com/jjlawren/sonos_custom_component.git sonos

Once you restart it should pick up the new code (with the fix) and you can test. You should see a warning like this on startup:

We found a custom integration sonos which has not been tested by Home Assistant.

I attempted but failed to install the custom component. Everything working as it was in home assistant, but no indication of custom sonos integration being used over the original. in checking logs this stuck out to me:

The custom integration 'sonos' does not have a version key in the manifest file and was blocked from loading. See https://developers.home-assistant.io/blog/2021/01/29/custom-integration-changes#versions for more details

edit: added my own version line to the manifest json file in custom_components/sonos and restarted. now seeing sonos as a custom component with no other issues to report yet. I'll let this ride for a while and see if I have issues, will report back in a day or two.

Good catch, updated the custom component repo with a version.

Installed this morning and get this in the logs and still get the large network error:

2023-12-28 09:28:08.469 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration sonos which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-12-28 09:28:08.469 ERROR (SyncWorker_2) [homeassistant.loader] The custom integration 'sonos' does not have a version key in the manifest file and was blocked from loading. See https://developers.home-assistant.io/blog/2021/01/29/custom-integration-changes#versions for more details

On Wed, Dec 27, 2023 at 7:25 PM jjlawren @.***> wrote:

Good catch, updated the custom component repo with a version.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/89128#issuecomment-1870734235, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZBTI7DONS7Y2I3CCZNETDLYLTC7PAVCNFSM6AAAAAAVPEMJLGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNZQG4ZTIMRTGU . You are receiving this because you commented.Message ID: @.***>

@chellweg it looks like you checked out the custom component before I added the version key to the manifest. It was not loaded on startup. Go into the custom_components/sonos directory, run a git pull, and restart HA.

Weird. I just did the pull this morning but re=pulling fixed it and I can confirm that my scripts now work without error.

On Thu, Dec 28, 2023 at 10:21 AM jjlawren @.***> wrote:

@chellweg https://github.com/chellweg it looks like you checked out the custom component before I added the version key to the manifest. It was not loaded on startup. Go into the custom_components/sonos directory, run a git pull, and restart HA.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/89128#issuecomment-1871316953, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZBTI7BEYMNEN2V673BC25DYLWMCBAVCNFSM6AAAAAAVPEMJLGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNZRGMYTMOJVGM . You are receiving this because you were mentioned.Message ID: @.***>

Alright, I've been using for a few days now. It's a bit hard to totally confirm this is 'fixed' since I didn't have a concrete way to make it happen and usually just noticed it when things like controlling sonos from home assistant or automations didn't work, but I will say that I've experienced 0 issues over the past 3-4 days since installing the custom integration. So I would be pretty confident in saying things haven't gotten Worse, at the very least.

I downloaded the standard home assistant core logs and checked for errors as well as sonos integration diagnostics and didn't see any red flags, but I didn't have debug logging on for sonos. Is there anything I could do or check for to help better confirm if things are truly fixed or at least not causing other issues? I'm not sure what standard procedure is here, but so far anecdotal evidence over the past 3-4 days is very positive.

Is there anything I could do or check for to help better confirm if things are truly fixed or at least not causing other issues?

It's great to hear things seem to be working well so far. As for potential problems I don't expect any, but my concerns would be around edge cases where subscriptions fail or are unstable and it uses cached data when it shouldn't. It wouldn't be an obvious error, but perhaps the speaker groups or other data could become outdated.

I've done some testing and monitored debug logs against actual behavior while intentionally causing issues. Everything worked as I would expect. However there seem to be some highly unstable setups out there that are hard to replicate.

I agree that with 24 devices since installing custom I have had zero issues. Prior to this change the integration had become unusable for me as it would error with every script call. Only thing I could use before were the dashboard audio controls and that sometimes resulted in an error as well. All that’s gone now.

On Mon, Jan 1, 2024 at 1:39 PM jjlawren @.***> wrote:

Is there anything I could do or check for to help better confirm if things are truly fixed or at least not causing other issues?

It's great to hear things seem to be working well so far. As for potential problems I don't expect any, but my concerns would be around edge cases where subscriptions fail or are unstable and it uses cached data when it shouldn't. It wouldn't be an obvious error, but perhaps the speaker groups or other data could become outdated.

I've done some testing and monitored debug logs against actual behavior while intentionally causing issues. Everything worked as I would expect. However there seem to be some highly unstable setups out there that are hard to replicate.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/89128#issuecomment-1873453069, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZBTI7E43Z6F2AMRYFCZLKTYMMGIVAVCNFSM6AAAAAAVPEMJLGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNZTGQ2TGMBWHE . You are receiving this because you were mentioned.Message ID: @.***>

when do you expect this in an official release.

I am also running the custom component with 28 speakers, no issues so far

The change has been accepted into the underlying library and I expect it to be available in HA 2024.2.0.

For anyone using the custom component, please remember to remove it when upgrading once the fix is released.

A reminder that this is now released in 2024.2.0. Please confirm if this improves behavior with your large Sonos system.

Also, remember to remove any custom sonos component if you were testing!

home-assistant / core

'GetZoneGroupState()' call fails on large Sonos systems #89128

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

Example configuration.yaml entry with manually specified Sonos IP addresses