Unable to play 'Song' access denied

[davidakerr]

I have Navidrome installed and working in the web UI, bonob is installed and i have it linked to my sonos application. I can browse all my music but when I select one I get an error "Unable to play 'song' access denied" in the Sonos app. Any ideas where I'm going wrong ?

version: "3"
services:
  navidrome:
    image: deluan/navidrome:latest
    container_name: navidrome
    user: 1040:100
    ports:
      - "4533:4533"
    restart: unless-stopped
    environment:
      ND_LOGLEVEL: info  
    volumes:
      - /volume1/music:/music:ro
      - /volume1/docker/navidrome:/data
  bonob:
    image: simojenki/bonob:latest
    container_name: bonob
    user: 1040:100
    ports:
      - "4534:4534"
    restart: unless-stopped
    environment:
      BNB_PORT: 4534
      BNB_URL: http:/192.168.0.100:4534  
      BNB_SECRET: psswrd-is-lik2e-this-aye
      BNB_SONOS_AUTO_REGISTER: "true"
      BNB_SONOS_DEVICE_DISCOVERY: "true"
      BNB_SONOS_SERVICE_ID: 246
      BNB_SONOS_SEED_HOST: 192.168.0.18
      BNB_SUBSONIC_URL: http://192.168.0.100:4533
      TZ: Europe/London

[simojenki]

Is there any log from bonob/navidrome when this occurs?

[davidakerr]

Nothing that seems to allude to an error in either. Navidrome works outside the context of the Sonos integration. It's logs all seem related to scanning and finishing scanning my music directory. Thanks for looking into this with me.

{
    "message": {
        "level": "debug",
        "data": "<?xml version=\"1.0\" encoding=\"utf-8\"?><soap:Envelope xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\"  xmlns:tns=\"http://www.sonos.com/Services/1.1\"><soap:Body><getExtendedMetadataResponse xmlns=\"http://www.sonos.com/Services/1.1\"><getExtendedMetadataResult><mediaMetadata><itemType>track</itemType><id>track:f890af842bc1938804a73a4f6f615f99</id><mimeType>audio/mpeg</mimeType><title>Little Bit Of Inner Air</title><trackMetadata><album>Made In England</album><albumId>album:344ca27c20dc286135ff77fbb0494c72</albumId><albumArtist>Atomic Rooster</albumArtist><albumArtistId>artist:4cd6c3da277df8ea18b236624ec642aa</albumArtistId><albumArtURI>http://192.168.0.100:4534/art/bnb%3As%3Aart%3Af890af842bc1938804a73a4f6f615f99/size/180?bat=32b269e9c1af02e1bcee39d43eefdd85be332b0505186a9249a4d20b8e5547aa</albumArtURI><artist>Atomic Rooster</artist><artistId>artist:4cd6c3da277df8ea18b236624ec642aa</artistId><duration>159</duration><genre>Unknown</genre><genreId>VW5rbm93bg==</genreId><trackNumber>3</trackNumber></trackMetadata><dynamic><property><name>rating</name><value>100</value></property></dynamic></mediaMetadata></getExtendedMetadataResult></getExtendedMetadataResponse></soap:Body></soap:Envelope>"
    },
    "level": "debug",
    "service": "bonob",
    "timestamp": "2022-03-25 10:26:42"
}

[simojenki]

Playing a track on a Sonos device results in many requests between Sonos and bonob.

When Sonos tries to stream a track it will hit a /stream end point in bonob. Are there any logs related to that?

[davidakerr]

Yes there are many logs related to streams. Is there any sensitive information in here I should obfuscate before I post it ?

[simojenki]

I don't think so, however better to be safe than sorry. Email it to; simojenki at gmail

[peterbuga]

@simojenki thanks for this project! any words on this specific problem? I have the same combo navidrome + bonob everything hosted externally with reverse proxy via cloudflare, everything works just fine except the requests to /stream/track/d418ad5ae77cdec697828984d26e60ed endpoint as example that return a 401 in nginx logs from bonob

all the other endpoints like /art/bnb%3As%3Aart%3A5aa52ebee25bc0a4c3f45bb8f286579b/size/600?bat=00de344f89ae1735535209042a7023c1c9fbf967ba49dd8d0588aeb1e5e2bd28 seem to work just fine directly from browser without any kind of auth

I have some fairly good knowledge on docker & networking if you'd like to give have an extra hand in debugging 👋

[simojenki]

At this point I don't know if this is an issue with bonob or not. Auth for streams works using 2 request headers: bnbt & bnbk. Both of those are passed from the sonos device to bonob as headers.
Does your setup with the various reverse proxies (nginx & cloudflare) propagate all the request headers? Do you see either of these messages in the bonob log? "Missing bnbt header" or "Missing bnbk header"

[peterbuga]

thanks for reply @simojenki

the bnbt and bnbk headers seem to be present (they are marked as ***** in the logs) but i haven't got all the way through to enable deeper log on nginx's side and actually see their values.

i'll debug further by replicating the setup locally on internal network and then move forward to external hosting and see what goes wrong on this side and let you know. 🙂

[simojenki]

Unfortunately as the code is currently written the presence of the log line with the **** doesn't necessarily mean that the header is present. here

However if you are not seeing the error Missing bnbt header then it would appear that the headers are being propagated correctly.

Does it always fail, or does it sometimes work?
If you restart bonob what happens?
What about if you re-authorise your account between sonos/bonob/navidrome?

[peterbuga]

something odd happen: now it's working 😶

basically, after multiple reauthorizations/container recreations/reverse proxy checks and whatnots I simply gave up and left it as it was then after the weekend I gave it another "play" in iOS app and just worked. to answer your questions:

Does it always fail, or does it sometimes work?

always

If you restart bonob what happens?

no change in behavior

What about if you re-authorise your account between sonos/bonob/navidrome?

did it multiple times, with no immediate positive results

now I feel kinda down, I was hoping to find a real debugging solution to post it here for further help. the only thing that crosses my mind is that somehow sonos was not properly reaching the newly created subdomain and/or being an external source sonos somehow must validate it on their side 1st 🤷‍♂️

I still have some of the error logs from that time both from nginx reverse proxy and bonob's but I don't think it'll shed much more light now that's it's working as expected. I could give more in-depth details on my setup but basically navidrome + bonob reside on same internal docker network with bonob being externally accessible via a cloudflare http[with S] -> reverse proxy nginx http[no S]

update: I forgot to mention that over this period I checked and no automated updates were done to either navidrome/bonob/nginx/docker, the only unknown dependency in this case would be CloudFlare itself but I kinda doubt it might be the culprit

[simojenki]

Strange that it just starting working, though better than staying broken!

AFAIK there is no validation required on the sonos end, as we are pushing the source directly into the device.

[sumnerboy12]

Hi - I have just installed bonob in a Docker Swarm environment, using Traefik for reverse proxying. I am running Navidrome and Bonob in separate stacks, where each is available internally on my LAN at <app>.domain.tld. I have setup bonob with the following env vars;

BNB_PORT=4534
BNB_SECRET=secret

BNB_URL=https://bonob.domain.tld
BNB_SUBSONIC_URL=https://navidrome.domain.tld

BNB_SONOS_SERVICE_ID=246
BNB_SONOS_SERVICE_NAME=Navidrome
BNB_SONOS_AUTO_REGISTER=true
BNB_SONOS_DEVICE_DISCOVERY=true
BNB_SONOS_SEED_HOST=<sonos_device_ip>

Everything is working fine, up until the point of actually playing a track. Then I get the access denied message in the Sonos app. I don't see any Missing bnbt header messages in the bonob logs and there is nothing in the Navidrome logs at all.

I see the following in my bonob logs;

bonob_app.1.9cpogeuysdcy@nuc03    | ::ffff:172.16.200.95 - - [11/May/2022:02:34:11 +0000] "GET /stream/track/a567aed1942f6edf671caf8fbb83bf7c HTTP/1.1" 401 - "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.54 Safari/537.36"

If I try accessing that URL in my browser I see the same 401 message.

Any ideas?

I presume Traefik is messing with the headers but I am not sure how to determine that for certain, or how to fix it...

[sumnerboy12]

Here is the info logging in bonob just prior to the 401, showing the request headers etc;

{
  "message": "3a21ed0b-e199-4717-89cd-aa12ff2580d0 bnb<- GET /stream/track/6bf5204f236b91fa8953e7c38a4b6303?{}, headers={\"host\":\"bonob.domain.tld\",\"user-agent\":\"Linux UPnP/1.0 Sonos/68.2-28040 (ZPS13)\",\"accept\":\"*/*\",\"bnbk\":\"*****\",\"bnbt\":\"*****\",\"x-forwarded-for\":\"192.168.10.1\",\"x-forwarded-host\":\"bonob.domain.tld\",\"x-forwarded-port\":\"443\",\"x-forwarded-proto\":\"https\",\"x-forwarded-server\":\"74b90835b9cc\",\"x-real-ip\":\"192.168.10.1\",\"x-sonos-firmware\":\"68.2-28040\",\"x-sonos-id-hash\":\"Uq6lYZFW0oVvwiPnC3Le1MpN3+q4EA+ZFTj9sqfp10k=\",\"x-sonos-muse-api\":\"1.28.0\",\"x-sonos-swgen\":\"2\",\"accept-encoding\":\"gzip\"}",
  "level": "info",
  "service": "bonob",
  "timestamp": "2022-05-11 14:36:30"
}

[simojenki]

Perhaps the ND auth token has expired, so is failing to work.

What happens if you reduce the bonob auth timeout by setting BNB_AUTH_TIMEOUT to say 1m?

This should cause bonob to refresh the auth token every 1m, you will probably see auth token refresh messages in the logs.

[sumnerboy12]

Thanks for the suggestion - I just tried it but no luck.

Is there something different about the /stream endpoint in terms of authentication? Because it seems the Sonos app/client has no trouble access /art for example.

[simojenki]

Yes, stream uses headers for the auth tokens, art uses query string Params.

Where possible I've tried to use headers as they are less likely to appear in access logs.

I'll try and improve the logging and see if we can find a root cause

[sumnerboy12]

Sounds good - more than happy to help test!

[peterbuga]

@sumnerboy12 if you read above I have a sort of similar setup like yours except my services are exposed to internet vs internal lan like yours.

@simojenki this might sound odd but I managed to re-trigger the 401 response on /stream/ endpoint by switching the connection from bonob <=> navidrome back to internal docker network, the weirdest thing is that it didn't fail right away but more like after the auth token had expired and could be properly refreshed again (although I had not seen any logs related to this yet) to give a bit more context: bonob instance (the way sonos is accessing it via internet) is located at https://bonob.somedomain.com both bonob and navidrome are located in same docker instance/network on bonob config I have - BNB_SUBSONIC_URL=https://navidrome.somedomain.com - working - BNB_SUBSONIC_URL=http://navidrome:4533 - (internal docker network) not working

could this be from the fact that once sonos accesses bonob via https all the upstream traffic must be continued via https too? odd question but I'm asking it anyway 😅 I'm not always near my sonos setup to test it but I'll drop more info if I discover something new

[simojenki]

That is interesting;

If you re-start bonob and navidrome does everything work for a while with each of those configurations? ie. does it work and then fail after a while, as this might indicate and issue with the token expiring.

I don't think that whether the traffic between bonob -> navidrome being http or https should matter to the sonos devices, as all requests to navidrome are proxied through bonob, so the sonos device doesn't really know about navidrome. That much said I only use my setup locally so I do not use https.

Does it work ever work when you use the internal docker network? ie. does it work when things first start up and then start failing?

BNB_SUBSONIC_URL=http://navidrome:4533

I'm in the middle of a re-factor of the navidrome integration, I'll try and get that merged in ASAP with some more detailed logging, perhaps that will help identify the root cause.

[sumnerboy12]

Any progress on that re-factor with detailed logging?

[simojenki]

Sorry, a bit slammed at the moment with work & life, unfortunately open source isn't getting any love

[sumnerboy12]

No worries at all, I know the feeling!

[peterbuga]

Hi, I've come across again this problem after I migrated the reverse proxies setup to end-to-end ssl support with traefik + cloudflare, and I want to post my findings maybe it'll help someone else too. My setup consists on everything being hosted on a vps, both navidrom and bonob, with reverse proxy to both of them and sonos devices connect directly to bonob via internet (I've "blocked" bonob endpoint with various authelia rules).

The problem I've noticed is that on a setup like Sonos request -> Cloudflare SSL [ssl setting on either Flexible/Full/Full (strict)] -> Traefik SSL (via Let's Encrypt) -> Bonob will fail to authenticate properly the /stream/track endpoint because the bnbt jwt header provided/requested by sonos devices gets truncated for whatever reason and the token cannot be parsed properly (but weirdly, a curl request passes the entire bnbt header value just fine only the sonos devices tend to break it, so I'm at lost here). I've tried all the combinations I could think of in order to keep Cloudflare ssl proxying my endpoint with no avail. and the only solution I've found for now was to disable proxy on bonob.example.com endpoint and leave it DNS Only option. This unfortunately exposes the real IP but at least the ssl part is handled by traefik + let's encrypt. PS: using the latest 0.6.5 release that has more options for debug logging

Hope this helps someone else and thank you for such a nice pice of software!

[simojenki]

Given that your setup seems to work with curl, perhaps there is some limitation in the sonos device itself? I'm not sure how we would confirm that.

[mycanaletto]

I have the same problem when trying to use a cloudflared tune.

I run two Bonob, one locally for my Sonos and another exposed via Cloudflared for friends.

services:
  navidrome:
    container_name: c-navidrome
    image: deluan/navidrome:latest
    # user: 1000:1000 # should be owner of volumes
    ports:
      - "4533:4533"
    restart: unless-stopped
    environment:
      # Optional: put your config options customization here. Examples:
      ND_SCANSCHEDULE: 1h
      ND_LOGLEVEL: info  
      ND_SESSIONTIMEOUT: 24h
      ND_BASEURL: ""
      ND_SPOTIFY_ID: "c9d4fgsfgsdfgdfsg264c1d1"
      ND_SPOTIFY_SECRET: "61131sfgdsfgsdfgfds75f"
      ND_DEFAULTLANGUAGE: "fr"
    volumes:
      - "/data/navidrome:/data"
      - "/nas/music:/music:ro"
  bonob:
    container_name: c-bonob
    image: simojenki/bonob:latest
    user: 1000:1000 # should be owner of volumes
    ports:
      - "4534:4534"
    restart: unless-stopped
    environment:
      BNB_PORT: 4534
      # ip address of your machine running bonob
      BNB_URL: http://192.168.10.33:4534  
      BNB_SECRET: wrtl
      BNB_SONOS_AUTO_REGISTER: "true"
      BNB_SONOS_DEVICE_DISCOVERY: "true"
      BNB_SONOS_SERVICE_ID: 246
      BNB_SONOS_SERVICE_NAME: "Canaletto Music"
      # ip address of one of your sonos devices
      BNB_SONOS_SEED_HOST: 192.168.10.115
      BNB_SUBSONIC_URL: http://192.168.10.33:4533
      BNB_ICON_FOREGROUND_COLOR: "#1db954"
      BNB_ICON_BACKGROUND_COLOR: "#121212"      
      TZ: "Europe/Paris"

  bonob-external:
    container_name: c-bonob-ext
    image: simojenki/bonob:latest
    user: 1000:1000 # should be owner of volumes
    ports:
      - "4535:4535"
    restart: unless-stopped
    environment:
      BNB_PORT: 4535
      BNB_URL: https://bonob.domain.tld
      BNB_SECRET: wrtl
      BNB_SONOS_AUTO_REGISTER: "false"
      BNB_SONOS_DEVICE_DISCOVERY: "false"
      BNB_SONOS_SERVICE_ID: 246
      BNB_SONOS_SERVICE_NAME: "Online Music"
    #   BNB_SUBSONIC_URL: http://172.20.0.2:4533 # OR
      BNB_SUBSONIC_URL: https://music.domain.tld
      BNB_ICON_FOREGROUND_COLOR: "#1db954"
      BNB_ICON_BACKGROUND_COLOR: "#121212"
      TZ: "Europe/Paris"

  tunnel:
    container_name: c-cloudflared
    image: cloudflare/cloudflared
    restart: unless-stopped
    command: tunnel run
    environment:
      - TUNNEL_TOKEN=eyJhIjoiMGJjNjEyZjdkNjI1IiwicyI6Ik5XTm1aakUwWkdRdE1USXpaUzAwTkdVd0xUa3lOR1l0TWpNNU5EQTVNREpoTkRJNCJ9

On Cloudflared Access I've tried to change some settings but I'm still denied access (next post)

If I go through pfsense+Ha proxy everything works fine, but I prefer to avoid it.

[mycanaletto]

[peterbuga]

@mycanaletto i would strongly suggest to redact/remove the spotify and cloudflare tokens from post above

[mycanaletto]

i would strongly suggest to redact/remove the spotify and cloudflare tokens from post above

It is not my reeal tokens ;-)

[wez]

FWIW, I'm also experience this problem when I run bonob behind a traefik proxy to enable SSL. Curiously, the problem only manifests for certain tracks within an album. It is consistently the same tracks, but there is no obvious pattern as to which tracks will be affected.

Changing the BNB_URL back to the non-TLS http host and port resolves it, but is undesirable because, presumably, the service registration authentication credentials are then being passed in clear text.

[peterbuga]

Curiously, the problem only manifests for certain tracks within an album. It is consistently the same tracks, but there is no obvious pattern as to which tracks will be affected.

@wez I tried multiple times to enable true end-to-end ssl and all the time something temporarily breaks and even if I revert everything to a previous working state it just doesn't work anymore, no matter how many restarts/rebuilds I do. then, if I leave it overnight as is, it'll start working again 🤷‍♂️

[simojenki]

Are the tracks transcoded on the fly? Or played as is?

I'm wondering if the socket timeout is different for TLS in the Sonos devices and some takes hit the timeout, others don't

[wez]

I haven't explicitly enabled transcoding in bonob or navidrome, and I've seen this affect some tracks in the same album as others that were unaffected; all tracks in that album are encoded (presumably!) the same way with the same format and bit rate from a recent bandcamp purchase. How do I check to see if transcoding is happening?

[simojenki]

If transcoding is not enabled in ND for the bonob player then there should be no transcoding happening.

[peterbuga]

@simojenki

Are the tracks transcoded on the fly? Or played as is?

I'm wondering if the socket timeout is different for TLS in the Sonos devices and some takes hit the timeout, others don't

never considered this as a possible setback, next time I'll try to disable any kind of transcoding and use only mp3 files