svrooij / sonos2mqtt

:speaker: Sonos mqtt controller. Control your speakers from your mqtt server. mqtt-smarthome insprired.
https://sonos2mqtt.svrooij.io/
MIT License
76 stars 18 forks source link

Startup error. Sonos error on GetZoneGroupState UPnPError 501 (Action failed) #134

Closed BillSobel closed 1 year ago

BillSobel commented 3 years ago

Can't find any direct hits on this error with this project, but others using SoCo seem to have the 501 issue with GetZoneGroupState potentially on linked devices, but unclear. Have you seen this before, any suggestions for debugging? Big system with about 30 zones.

docker run --env-file sonos2mqtt.env -p 6329:6329 svrooij/sonos2mqtt 2021-01-13T17:37:44.366Z [Information] Starting sonos2mqtt v3.1.1 2021-01-13T17:37:44.381Z [Information] LogLevel changed to information 2021-01-13T17:37:44.408Z [Fatal] Error starting sonos2mqtt SonosError: Sonos error on GetZoneGroupState UPnPError 501 (Action failed) at ZoneGroupTopologyService.handleErrorResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:223:23) at processTicksAndRejections (node:internal/process/task_queues:93:5) at async ZoneGroupTopologyService.handleRequestAndParseResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:196:15) at async ZoneGroupTopologyService.SoapRequest (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:75:16) at async ZoneGroupTopologyService.GetZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:46:40) at async ZoneGroupTopologyService.GetParsedZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:86:36) at async SonosManager.LoadAllGroups (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:63:16) at async SonosManager.Initialize (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:56:24) at async SonosManager.InitializeFromDevice (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:37:16) at async SonosToMqtt.start (/usr/src/app/lib/sonos-to-mqtt.js:20:23) { Action: 'GetZoneGroupState', FaultCode: 's:Client', Fault: 'UPnPError', UpnpErrorCode: 501, UpnpErrorDescription: 'Action failed' }

BillSobel commented 3 years ago

Tested the code on a different network with 13 devices, started fine so certainly has to do with that one homes configuration. Guessing players linked to surrounds based on bugs in other libs.

svrooij commented 3 years ago

I think that is not the case, it says that you’re getting an UPNP error (those are a response from the Sonos speaker)

do you have the following information: Sonos app (S1 or S2): Sonos Software version (diagnostic info in app):

{
Action: 'GetZoneGroupState',
FaultCode: 's:Client',
Fault: 'UPnPError',
UpnpErrorCode: 501,
UpnpErrorDescription: 'Action failed'
}
BillSobel commented 3 years ago

Sonos S1 app Controller version 11.2.3 the devices have 11.2.4 on them. Thanks!

svrooij commented 3 years ago

Can you add environment DEBUG with value sonos:* and restart? That should give you way more logging.

I'm running the same version as you (with 7 speakers) and don't have an issue.

BillSobel commented 3 years ago

I left the house with that config but will be back by weekend, will run and send. Thanks!

BillSobel commented 3 years ago

Exported the DEBUG and get the same immediately at startup:

2021-01-14T18:50:50.660Z [Information] Starting sonos2mqtt v3.1.1 2021-01-14T18:50:50.676Z [Information] LogLevel changed to information 2021-01-14T18:50:50.706Z [Fatal] Error starting sonos2mqtt SonosError: Sonos error on GetZoneGroupState UPnPError 501 (Action failed) at ZoneGroupTopologyService.handleErrorResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:223:23) at processTicksAndRejections (node:internal/process/task_queues:93:5) at async ZoneGroupTopologyService.handleRequestAndParseResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:196:15) at async ZoneGroupTopologyService.SoapRequest (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:75:16) at async ZoneGroupTopologyService.GetZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:46:40) at async ZoneGroupTopologyService.GetParsedZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:86:36) at async SonosManager.LoadAllGroups (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:63:16) at async SonosManager.Initialize (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:56:24) at async SonosManager.InitializeFromDevice (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:37:16) at async SonosToMqtt.start (/usr/src/app/lib/sonos-to-mqtt.js:20:23) { Action: 'GetZoneGroupState', FaultCode: 's:Client', Fault: 'UPnPError', UpnpErrorCode: 501, UpnpErrorDescription: 'Action failed' }

BillSobel commented 3 years ago

Also have rotated through numerous of the units, get the same result no matter what unit I point the system to to boot.

svrooij commented 3 years ago

I don’t think the debug log worked. To set environment in docker you cannot just export it on your local machine.

BillSobel commented 3 years ago

I didn't run this test under docker. Get the exception at every startup. Restarting doesn’t matter

svrooij commented 3 years ago

If you're not using docker, can you start the app with the following added in front: DEBUG=sonos:* so the full command will be DEBUG=sonos:* sonos2mqtt [your options].

At my computer that ourputs something like:

2021-01-15T08:20:23.389Z sonos:sonosmanager InitializeFromDevice 192.168.x.x
2021-01-15T08:20:23.411Z sonos:sonosmanager Initialize()
2021-01-15T08:20:23.413Z sonos:service:zonegrouptopology:192.168.x.x GetZoneGroupState()
2021-01-15T08:20:23.384Z [Information] Starting sonos2mqtt v3.1.1-beta.6
2021-01-15T08:20:23.500Z [Information] LogLevel changed to debug
2021-01-15T08:20:23.598Z sonos:service:zonegrouptopology:192.168.x.x Listener added
2021-01-15T08:20:23.599Z sonos:service:zonegrouptopology:192.168.x.x Subscribing to events
2021-01-15T08:20:23.605Z sonos:eventlistener Listener endpoint: http://192.168.y.y:6329/sonos/{sonos-uuid}/{serviceName}
2021-01-15T08:20:23.605Z sonos:service:zonegrouptopology:192.168.x.x Creating event subscription with callback: http://192.168.y.y:6329/sonos/53590c1d-a770-9591-0f6b-ad3ef2dc8d04/ZoneGroupTopology
2021-01-15T08:20:23.615Z [Information] Found 7 sonos speakers
BillSobel commented 3 years ago

Here we go:

2021-01-16T05:49:14.939Z sonos:sonosmanager InitializeFromDevice 10.1.3.117 2021-01-16T05:49:14.941Z sonos:sonosmanager Initialize() 2021-01-16T05:49:14.942Z sonos:service:zonegrouptopology:10.1.3.117 GetZoneGroupState() 2021-01-16T05:49:14.938Z [Information] Starting sonos2mqtt v3.1.1 2021-01-16T05:49:14.955Z [Information] LogLevel changed to information 2021-01-16T05:49:14.985Z sonos:service:zonegrouptopology:10.1.3.117 Sonos error on GetZoneGroupState { faultcode: 's:Client', faultstring: 'UPnPError', detail: { UPnPError: { errorCode: 501 } } } 2021-01-16T05:49:14.985Z [Fatal] Error starting sonos2mqtt SonosError: Sonos error on GetZoneGroupState UPnPError 501 (Action failed) at ZoneGroupTopologyService.handleErrorResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:223:23) at processTicksAndRejections (node:internal/process/task_queues:93:5) at async ZoneGroupTopologyService.handleRequestAndParseResponse (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:196:15) at async ZoneGroupTopologyService.SoapRequest (/usr/src/app/node_modules/@svrooij/sonos/lib/services/base-service.js:75:16) at async ZoneGroupTopologyService.GetZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:46:40) at async ZoneGroupTopologyService.GetParsedZoneGroupState (/usr/src/app/node_modules/@svrooij/sonos/lib/services/zone-group-topology.service.js:86:36) at async SonosManager.LoadAllGroups (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:63:16) at async SonosManager.Initialize (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:56:24) at async SonosManager.InitializeFromDevice (/usr/src/app/node_modules/@svrooij/sonos/lib/sonos-manager.js:37:16) at async SonosToMqtt.start (/usr/src/app/lib/sonos-to-mqtt.js:20:23) { Action: 'GetZoneGroupState', FaultCode: 's:Client', Fault: 'UPnPError', UpnpErrorCode: 501, UpnpErrorDescription: 'Action failed' }

This thread seems to cover the issue, suggesting the API is actually broken on large installs. https://github.com/SoCo/SoCo/issues/518 And that manual discovery is the fallback. (Heck if needed, I can pass a list of alley player IPs)

svrooij commented 3 years ago

So actually the “give me all the speakers” fails on the Sonos side. The issue with soco mentions that if you have more then 20 (or 22) speakers you have to group them before you can ask an of the speakers to show all players.

This is something that cannot be fixed easily. Because this app is focused on the groups it doesn’t work if it cannot ask the speakers to what speakers are available.

makuser commented 2 years ago

So actually the “give me all the speakers” fails on the Sonos side. The issue with soco mentions that if you have more then 20 (or 22) speakers you have to group them before you can ask an of the speakers to show all players.

What exactly does this mean? What shall I do if I have more than 20 players?

svrooij commented 2 years ago

This means that if you have more then 20 players, you should group them using the official app. My guess (not tested) in the S2 system this might be more stable, since S2 compatible speakers have more memory and are a little bit more powerful.

you could also split your system, but that would require 2 different networks, router changes and more stuff like that.

maybe you can split your speakers in half, and the run both a S1 and a S2 system.

svrooij commented 2 years ago

@makuser technical explanation, this call fails on big systems (20+). And this software depends on it to load info all available players/groups

makuser commented 2 years ago

This means that if you have more then 20 players, you should group them using the official app. My guess (not tested) in the S2 system this might be more stable, since S2 compatible speakers have more memory and are a little bit more powerful.

you could also split your system, but that would require 2 different networks, router changes and more stuff like that.

maybe you can split your speakers in half, and the run both a S1 and a S2 system.

Thank you so much for this fast information. I'm running 14.2 with currently 33 groups, but a part of them is offline currently, and the speakers that are online are way below that limit. So that's why I'm wondering what I could do.

We'll try to get them all back online, group them, and then then power them off again, in hopes that this would solve the issue.

svrooij commented 2 years ago

I think you can also remove the offline players from the system with the app.

Or maybe try to start this app with the IP of one of the newer players in your system

makuser commented 2 years ago

I think you can also remove the offline players from the system with the app.

Or maybe try to start this app with the IP of one of the newer players in your system

No offline players are shown in the sonos app, so no way to remove them.

I will have to bring them online to group them, I see no other way. I tried sending the SOAP myself via curl and that yields a 501 on every single online player in the network, so they must have cached it or so... It's incredibly stupid from sonos to have the system designed that way and apparently not fix it for at least half a decade already (I found bugreports dating back to 2017).

curl -X POST http://${IP}:1400/ZoneGroupTopology/Control -H 'Content-Type: text/xml' -H 'SOAPAction: urn:schemas-upnp-org:service:ZoneGroupTopology:1#GetZoneGroupState' -d '<?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetZoneGroupAttributes xmlns:u="urn:schemas-upnp-org:service:ZoneGroupTopology:1"></u:GetZoneGroupAttributes></s:Body></s:Envelope>'
<?xml version="1.0" encoding="UTF-8"?>
<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>

The same call on a smaller sonos network properly shows the group information, as requested.

Thank you very much @svrooij for your quick response. I guess it's now at the devs over at SoCo to circumvent this bug, by not using that SOAP call, just like the official app doesn't use that call. This however (https://github.com/SoCo/SoCo/issues/518#issuecomment-569836877) hasn't gotten any updates since late 2019 though, so it really does not seem to be up that high on the priority list. So thank you again :)

svrooij commented 2 years ago

@makuser I'm curious what you're trying to accomplish? This library is built around the idea of all the groups. The library underneath (for controlling and listening for events) is speaker based.

So depending on what you want to do with the system, it might also be possible to send the events for single speakers to mqtt and control those speakers through mqtt. But off-course the group part will never work and this will take some refactoring.

Than you would have to start it with all the IP addresses of the speakers you want to monitor/control.

github-actions[bot] commented 1 year ago

:tada: This issue has been resolved in version 3.2.0-beta.14 :tada:

The release is available on:

Your semantic-release bot :package::rocket: