ARC (surround group) 'Pause' not working after turning off TV

[niels-vd]

I got an ARC with sub and 2 one's as a surround set connected to my TV. When I turn off the TV, the ARC set ('woonkamer') is still 'on' in the home app(s). At that point I'm unable to turn it off/pause. If I toggle the 'tv' or 'sonos' accessoiry it just toggles back on again. After viewing another issue I added an automation that changes the input from 'tv' to a radio station, when the 'tv characteristic' changes to 'off'. The radio station than starts playing (after about 15s), but I'm still unable to turn if off using home app(s) (still toggling back to on/playing). The native Sonos app shows the correct status at all times. After a homebridge restart the status is set correctly in home. It also seems that the status in the home app changes to the right state after about 15-20 minutes. I attached the debug log of the following scenario:

• TV turns on
• TV turns off
• automation changes input to 'NPO 3FM'
• Music is paused using the Sonos app.
  homebridge-ZP.log

[ebaauw]

You cannot switch off the Sonos accessory when it's on TV input. The Sonos app disables the play/pause button when "playing" the TV input, but I cannot do that in HomeKit.

After switching to another input, the play/pause button is re-enabled, and you should be able to pause the zone player from HomeKit. From your log, I see the input switching to a radio station after the TV no longer sends any signal, I assume this is a HomeKit automation? However, at the same time you Roam comes online, causing all sorts of interfering traffic. I can see you try and switch the Arc off from HomeKit at 8:16:07, but Homebridge ZP doesn't send any command to the Arc. I suspect this is because Homebridge ZP didn't receive the current transport actions, and thinks it's still not possible to issue a Pause or Stop command. Could you try and set Log Level for the Arc to 3 and re-capture the log file? That should log the changes to the current transport actions.

After switching the Arc off using the Sonos app (at 8:16:14), you should be able to control it again from HomeKit, as switching it off should re-send the current transport actions.

[niels-vd]

@ebaauw The switch to a radio station is a homekit automation indeed (created in Eve). I added that to force the input change, hoping it would enable play/pause control again. I added the level 3 debug log. I replayed the same scenario, including the automated switch to radio station.

homebridge-3.log

[ebaauw]

Switching the Arc to TV works as expected:

[5/17/2021, 9:48:36 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: event: NOTIFY MediaRenderer/AVTransport/Event
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set On from false to true
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer TV: set Active from 0 to 1
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: On changed from true to true
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set Track from "NPO 3FM" to "TV"
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set TV from false to true
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set currentTransportActions from ["Set","Stop","Play"] to ["Set","Play"]
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set currentValidPlayModes from [""] to [""]
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set uri from "x-sonosapi-stream:s6707?sid=254&flags=8224&sn=0" to "x-sonos-htastream:RINCON_48A6B8B1EC5101400:spdif"
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer TV: set Active Identifier from 6 to 4
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer Sonos: set Active Identifier from 6 to 4
[5/17/2021, 9:48:36 AM] [Sonos] Speaker Woonkamer TV: set Active Identifier to "TV"

The current transport actions are set to "Play" and "Set" (no "Stop" nor "Pause").

However, they're not reset when switching to the radio station:

[5/17/2021, 9:49:06 AM] [Sonos] Speaker Woonkamer TV: set Active Identifier to "NPO 3FM"
[5/17/2021, 9:49:06 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: request 22: POST /MediaRenderer/AVTransport/Control SetAVTransportURI
[5/17/2021, 9:49:06 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: request 22: status 200 OK
[5/17/2021, 9:49:06 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: request 23: POST /MediaRenderer/AVTransport/Control Play
[5/17/2021, 9:49:06 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: event: NOTIFY MediaRenderer/AVTransport/Event
[5/17/2021, 9:49:06 AM] [Sonos] Speaker Woonkamer Sonos: ignore AVTransPortEvent after SetAVTransportURI
[5/17/2021, 9:49:08 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: request 23: status 200 OK
[5/17/2021, 9:49:10 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: event: NOTIFY MediaRenderer/AVTransport/Event
[5/17/2021, 9:49:10 AM] [Sonos] Speaker Woonkamer Sonos: set uri from "x-sonos-htastream:RINCON_48A6B8B1EC5101400:spdif" to "x-sonosapi-stream:s6707?sid=254&flags=8224&sn=0"
[5/17/2021, 9:49:11 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: event: NOTIFY MediaRenderer/AVTransport/Event
[5/17/2021, 9:49:11 AM] [Sonos] Speaker Woonkamer Sonos: set Track from "TV" to "DANNY VERA - ROLLER COASTER"
[5/17/2021, 9:49:15 AM] [Sonos] RINCON_48A6B8B1EC5101400 [Speaker Woonkamer]: event: NOTIFY MediaRenderer/AVTransport/Event
[5/17/2021, 9:49:20 AM] [Sonos] Speaker Woonkamer TV: Active changed from 1 to 0
[5/17/2021, 9:49:20 AM] [Sonos] Speaker Woonkamer Sonos: On changed from true to false
[5/17/2021, 9:49:20 AM] [Sonos] Speaker Woonkamer Sonos: set On from false to true
[5/17/2021, 9:49:20 AM] [Sonos] Speaker Woonkamer TV: set Active from 0 to 1

I think the current transport actions are in the ignored AVTransPort event, and not repeated in the following events. I need to check if I can reproduce this in my setup; otherwise I'm gonna have to ask you to collect a ridiculous amount of debug info.

[niels-vd]

@ebaauw

I think the current transport actions are in the ignored AVTransPort event, and not repeated in the following events. I need to check if I can reproduce this in my setup; otherwise I'm gonna have to ask you to collect a ridiculous amount of debug info.

Thanks for the efforts! Always happy to help out of course, it's my problem after all ...

[ebaauw]

I finally managed to reproduce the issue in my setup. Beta v1.4.0-1 no longer ignores the AVTransport event and seems to work OK. It will show the Sonos service as off while switching inputs, but it switches back to on, once the zone player has connected to the new input stream. I think I ignored the event solely to prevent it from flipping between on, off, and back on.

[niels-vd]

Good to hear! Thanks for all the efforts, I'll definitely try the fix asap!

[ebaauw]

In v1.4.0.

[niels-vd]

Thanks for all the work! I was just able to try the beta before the weekend and all seems to work as expected now!