Error altering crossfade after alexa has been used to trigger playing music

[johnnyfleet]

Hi there - I'm cross-posting this issue here which originally was raised in node-sonos-nfc, but may be more appropriate here as I've managed to recreate now on a separate instance of node-sonos-http-api. I've noticed a specific scenario which seems to be generating an error when trying to play something through node-sonos-nfc using the NFC tag reader.

The issues invovles when music is already playing that was triggered by a request via Alexa and then attempts made to play via nfc tag reader.

Steps to recreate in node-sonos-nfc

1. Reset sonos and raspberry pi.
2. Play something through the nfc tag - all works fine (see logs below)
3. Ask alexa to play something e.g. 'Alexa, play Kings of leon'. Music switches and plays new request.
4. Remove the nfc tag and replace it. Errors with a comment about setting crossfade.
5. nfc approach will continue to fail, even when the music stopped, until I use the sonos app to choose something manually from spotify/mylibrary.
6. After manually setting, add the nfc tag, works all fine.

Steps to trigger issue in node-sonos-http-api

To drill down on the issue for this program:

• It seems that when I request a playlist or album is played via Alexa then the crossfade fails.
• If I try via the webui (http://<machinename>:5005/crossfade/off) and turn off crossfade I get the following error:
  {
  "status": "error",
  "error": "Got status 500 when invoking /MediaRenderer/AVTransport/Control",
  "stack": "Error: Got status 500 when invoking /MediaRenderer/AVTransport/Control\n at Object.invoke (/home/pi/node-sonos-nfc/node_modules/sonos-discovery/lib/helpers/soap.js:99:10)\n at /home/pi/node-sonos-nfc/node_modules/sonos-discovery/lib/models/Player.js:682:19"
  }
  Same with http://<machinename>:5005/crossfade/on

Logs from node-sonos-nfc showing similar issue. Can ignore if want to remove layers of the problem. Above shows how I can recreate problem.

From pm2 log

1. Add an nfc tag after resetting sonos and raspberry pi

0|npm  | [0] ACS ACR122U 00 00 detected TAG_ISO_14443_3 with UID 041ea9b2ed6c81
0|npm  | [0] 
0|npm  | Read from NFC tag with message:  spotify:user:spotify:playlist:37i9dQZF1DWVFJtzvDHN4L
0|npm  | [0] Detected 'spotify' service request
0|npm  | [0] Resetting repeat
0|npm  | [0] Resetting shuffle
0|npm  | [0] 
0|npm  | Resetting crossfade
0|npm  | [0] Clearing Sonos queue
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/spotify/now/spotify:user:spotify:playlist:37i9dQZF1DWVFJtzvDHN4L
0|npm  | [0] 
0|npm  | Sonos API reports:  { status: 'success' }
0|npm  | [0] 
0|npm  | Read from NFC tag with message:  command:shuffle/on
0|npm  | [0] Detected 'command' service request
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/shuffle/on
0|npm  | [0] Sonos API reports:  { status: 'success' }
0|npm  | [0] 
0|npm  | Read from NFC tag with message:  command:next
0|npm  | [0] Detected 'command' service request
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/next
0|npm  | [0] 
0|npm  | Sonos API reports:  { status: 'success' }

2. Logs after playing something via alexa and then re-tagging the nfc tag

0|npm  | [0] 
0|npm  | ACS ACR122U 00 00: TAG_ISO_14443_3 with UID 041ea9b2ed6c81 removed
0|npm  | [0] 
0|npm  | ACS ACR122U 00 00 detected TAG_ISO_14443_3 with UID 041ea9b2ed6c81
0|npm  | [0] 
0|npm  | Read from NFC tag with message:  spotify:user:spotify:playlist:37i9dQZF1DWVFJtzvDHN4L
0|npm  | [0] Detected 'spotify' service request
0|npm  | [0] Resetting repeat
0|npm  | [0] 
0|npm  | Resetting shuffle
0|npm  | [0] 
0|npm  | Resetting crossfade
0|npm  | [1] 
0|npm  | 2022-08-25T22:11:52.981Z ERROR 
0|npm  | [1]   Error: Got status 500 when invoking /MediaRenderer/AVTransport/Control
0|npm  | [1]     at Object.invoke (/home/pi/node-sonos-nfc/node_modules/sonos-discovery/lib/helpers/soap.js:99:10)
0|npm  | [1]     at /home/pi/node-sonos-nfc/node_modules/sonos-discovery/lib/models/Player.js:682:19
0|npm  | [0] Error: Unexpected response while turning crossfade off: 500

3. Logs after changing song in the sonos app, then re-tagging the nfc tag

0|npm  | [0] ACS ACR122U 00 00: TAG_ISO_14443_3 with UID 041ea9b2ed6c81 removed
0|npm  | [0] 
0|npm  | ACS ACR122U 00 00 detected TAG_ISO_14443_3 with UID 041ea9b2ed6c81
0|npm  | [0] Read from NFC tag with message:  spotify:user:spotify:playlist:37i9dQZF1DWVFJtzvDHN4L
0|npm  | [0] Detected 'spotify' service request
0|npm  | [0] Resetting repeat
0|npm  | [0] 
0|npm  | Resetting shuffle
0|npm  | [0] 
0|npm  | Resetting crossfade
0|npm  | [0] 
0|npm  | Clearing Sonos queue
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/spotify/now/spotify:user:spotify:playlist:37i9dQZF1DWVFJtzvDHN4L
0|npm  | [0] 
0|npm  | Sonos API reports:  { status: 'success' }
0|npm  | [0] 
0|npm  | Read from NFC tag with message:  command:shuffle/on
0|npm  | [0] Detected 'command' service request
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/shuffle/on
0|npm  | [0] 
0|npm  | Sonos API reports:  { status: 'success' }
0|npm  | [0] Read from NFC tag with message:  command:next
0|npm  | [0] Detected 'command' service request
0|npm  | [0] Fetching URL via HTTP api: http://localhost:5005/Sun Room/next
0|npm  | [0] 
0|npm  | Sonos API reports:  { status: 'success' }

Notes on hardware set up

Just in case it helps to narrow down, this is my set up:

• Sonos Play:1 (older model with no voice assistant)
• Amazon echo dot 1st generation - paired with the Sonos as the primary speaker.
• Raspberry Pi 3 Model B Rev 1.2