[ISSUE] Skill can connect to Ask Navidrome but requests don't process (HTTP Error 403)

[TemporalUncertainty]

Describe the issue Asknavidrome recieves but is unable to process requests from the alexa skill. When using the "OPEN InvocationName" command the developer console or device responds with ready but the log shows this error: 2023-06-03 23:25:29,994 - asknavidrome.subsonic_api - ERROR - Failed to connect to Navidrome When using the "ASK InvocationName to DoAnything" command the console/device can't proceed and the log has this error: 2023-06-03 23:26:47,948 - root - ERROR - General Exception: HTTP Error 403: Forbidden

Operating System Docker Compose (under Portainer on Ubuntu).

To Reproduce Ask the device or dev console to "OPEN InvocationName" Then ask the device or dev console to "ASK InvocationName to play music by ArtistName" or "ASK InvocationName to play music"

Logs 2023-06-03 23:25:28,807 - werkzeug - INFO - 172.31.0.1 - - [03/Jun/2023 23:25:28] "POST / HTTP/1.1" 200 - 2023-06-03 23:25:29,994 - asknavidrome.subsonic_api - ERROR - Failed to connect to Navidrome 2023-06-03 23:25:30,029 - werkzeug - INFO - 172.31.0.1 - - [03/Jun/2023 23:25:30] "POST / HTTP/1.1" 200 - 2023-06-03 23:26:14,473 - root - ERROR - General Exception: HTTP Error 403: Forbidden 2023-06-03 23:26:14,473 - root - ERROR - Request Type Was: IntentRequest 2023-06-03 23:26:14,473 - root - ERROR - Intent Name Was: NaviSonicPlayMusicByGenre 2023-06-03 23:26:14,475 - werkzeug - INFO - 172.31.0.1 - - [03/Jun/2023 23:26:14] "POST / HTTP/1.1" 200 - 2023-06-03 23:26:47,948 - root - ERROR - General Exception: HTTP Error 403: Forbidden 2023-06-03 23:26:47,948 - root - ERROR - Request Type Was: IntentRequest 2023-06-03 23:26:47,948 - root - ERROR - Intent Name Was: NaviSonicPlaySongByArtist 2023-06-03 23:26:47,951 - werkzeug - INFO - 172.31.0.1 - - [03/Jun/2023 23:26:47] "POST / HTTP/1.1" 200 -

Comments Navidrome instance is externally accessible by android apps and web browsers using the same credentials in the docker compose file) Asknavidrome service is externally accessible (although shows a 405 method not allowed page when viewed by a browser) I use cloudflare tunnels to access the containers.

[rosskouk]

Hi,

The 405 when accessing the skill is normal if a none complete request is sent so that should be nothing to worry about.

The issue looks to be an internal one in that the skill container cannot connect to your navidrome instance.

To troubleshoot further I would open a shell in the skill container and use curl / to try and get to your navidrome instance to see what is happening. The external side looks good from your logs, the intent requested gets to the skill container fine.

[TemporalUncertainty]

Thank you for the suggestion. From inside the asknavidrome container I can curl the navidrome instance - the returned results include a message about needing to enable javascript but I expect that doesn't mean anything given curl probably can't process JS. I can also access a bunch of URLS (google, bing etc). Looks to me like the container can reach both the internet and the navidrome instance.

EDIT - I set the debug level to 3 and this is what's in the logs when I test through the developer console:

for ECHO OPEN 'skillname'

2023-10-01 08:17:37,662 - root - DEBUG - Request received: {'error': None, 'locale': 'en-AU', 'object_type': 'SessionEndedRequest', 'reason': 'USER_INITIATED', 'request_id': 'REDACTED', 'timestamp': datetime.datetime(2023, 10, 1, 8, 17, 35, tzinfo=tzlocal())} 2023-10-01 08:17:37,662 - root - DEBUG - In SkillEventHandler 2023-10-01 08:17:37,663 - root - DEBUG - Response sent: {'api_response': None, 'can_fulfill_intent': None, 'card': None, 'directives': None, 'experimentation': None, 'output_speech': None, 'reprompt': None, 'should_end_session': None} 2023-10-01 08:17:37,663 - werkzeug - INFO - 172.31.0.1 - - [01/Oct/2023 08:17:37] "POST / HTTP/1.1" 200 - 2023-10-01 08:17:38,751 - root - DEBUG - Request received: {'locale': 'en-AU', 'object_type': 'LaunchRequest', 'request_id': 'REDACTED', 'task': None, 'timestamp': datetime.datetime(2023, 10, 1, 8, 17, 35, tzinfo=tzlocal())} 2023-10-01 08:17:38,751 - root - DEBUG - In LaunchRequestHandler 2023-10-01 08:17:38,751 - asknavidrome.subsonic_api - DEBUG - In function ping() 2023-10-01 08:17:38,834 - asknavidrome.subsonic_api - ERROR - Failed to connect to Navidrome 2023-10-01 08:17:38,901 - root - DEBUG - Response sent: {'api_response': None, 'can_fulfill_intent': None, 'card': None, 'directives': None, 'experimentation': None, 'output_speech': {'object_type': 'SSML', 'play_behavior': None, 'ssml': '<speak>Ready!</speak>'}, 'reprompt': {'directives': None, 'output_speech': {'object_type': 'SSML', 'play_behavior': None, 'ssml': '<speak>Ready!</speak>'}}, 'should_end_session': False} 2023-10-01 08:17:38,902 - werkzeug - INFO - 192.168.1.250 - - [01/Oct/2023 08:17:38] "POST / HTTP/1.1" 200 -

and for PLAY MUSIC BY 'artist name'

2023-10-01 08:18:06,903 - root - DEBUG - Request received: {'dialog_state': None, 'intent': {'confirmation_status': 'NONE', 'name': 'NaviSonicPlayMusicByArtist', 'slots': {'artist': {'confirmation_status': 'NONE', 'name': 'artist', 'resolutions': None, 'slot_value': {'object_type': 'Simple', 'resolutions': None, 'value': 'tycho'}, 'value': 'tycho'}}}, 'locale': 'en-AU', 'object_type': 'IntentRequest', 'request_id': 'REDACTED', 'timestamp': datetime.datetime(2023, 10, 1, 8, 18, 6, tzinfo=tzlocal())} 2023-10-01 08:18:06,903 - root - DEBUG - In NaviSonicPlayMusicByArtist 2023-10-01 08:18:06,903 - asknavidrome.subsonic_api - DEBUG - In function search_artist() 2023-10-01 08:18:06,983 - root - DEBUG - In GeneralExceptionHandler 2023-10-01 08:18:06,983 - root - ERROR - General Exception: HTTP Error 403: Forbidden 2023-10-01 08:18:06,983 - root - ERROR - Request Type Was: IntentRequest 2023-10-01 08:18:06,984 - root - ERROR - Intent Name Was: NaviSonicPlayMusicByArtist 2023-10-01 08:18:06,987 - werkzeug - INFO - 172.31.0.1 - - [01/Oct/2023 08:18:06] "POST / HTTP/1.1" 200 -

I'm guessing by the 2 totally different IP addresses that it's some kind of Docker networking issue that I have no clue how to resolve :(

[rosskouk]

It does look like something like that, can you post your skill config file, redacting the passwords and IDs please? When in the skill container and attempting to CURL the Navidrome instance there should be no mention of JavaScript, it looks like the request is going somewhere else. Here is an example of what I get (replace NAVIDROME-URL with your URL (the contents of the NAVI_URL environment variable):

/opt/asknavidrome # curl https://NAVIDROME-URL/rest/ping

<subsonic-response xmlns="http://subsonic.org/restapi" status="failed" version="1.16.1" type="navidrome" serverVersion="0.47.5 (86fe1e3b)"><error code="10" message="Missing required parameter &#34;u&#34;"></error></subsonic-response>

We can ignore the error, that's expected as we haven't authenticated, you should be getting something starting with "subsonic-response" though. If you're not getting that I suspect the path the skill has to the Navidrome REST API is incorrect.

[TemporalUncertainty]

When I curl with my URL from inside the container I get pretty much the exact same result you posted (although I seem have a more recent version of navidrome... and an extra openSubsonic value?).

<subsonic-response xmlns="http://subsonic.org/restapi" status="failed" version="1.16.1" type="navidrome" serverVersion="0.49.3-SNAPSHOT (a984bbbc)" openSubsonic="true"><error code="10" message="Missing required parameter &#34;u&#34;"></error></subsonic-response>

I'm using compose so all my config is in the file..

navisonic:
  image: 'ghcr.io/rosskouk/asknavidrome:latest'
  container_name: REDACTED
    environment:
      - 'NAVI_SKILL_ID=REDACTED'
      - 'NAVI_URL=https://REDACTED'
      - 'NAVI_USER=guest'
      - 'NAVI_PASS=REDACTED'
      - 'NAVI_SONG_COUNT=50'
      - 'NAVI_PORT=443'
      - 'NAVI_API_PATH=/rest'
      - 'NAVI_API_VER=1.16.1'
      - 'NAVI_DEBUG=3'              
    ports:
      - '5000:5000'
    logging:
      driver: "json-file"
      options:
        max-size: "10m"
        max-file: "1"
    deploy:
      restart_policy:
        condition: on-failure
        delay: 5s
        max_attempts: 3
        window: 120s

[rosskouk]

Hi,

This seems strange. I'll try updating my Navidrome instance as soon as I can to see if I can recreate the issue. The problem looks like it is just the skill not being able to connect to your Navidrome instance and once that's resolved it should just work

[Ahimgit]

Hi,

I was getting similar issue trying to hit my public navidrome url sitting behind cloudflare, I dumped auth tokens and replicated exact requests libsonic is doing down to diff in User-Agent. And it looks like cf is very aggressive about pythons3 urllib's 'User-Agent': 'Python-urllib/*. Give it it a try if you are using that:

# works (curl user agent)
curl -v https://<you url>/app
# 403 
curl -v https://<you url>/app -H 'User-Agent: Python-urllib/22.1'

Here is waf rule config in cloudflare to disable it

@TemporalUncertainty