May 28 22:00:07 volumio volumio[937]: verbose: New Socket.io Connection to 192.168.1.17 from 192.168.1.10 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/538.18 (KHTML, like Gecko) Chrome/140.0.0.0 Mobile Safari/538.18 Engine version: 3 Transport: polling Total Clients: 8 May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::volumioGetVisibleSources May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::volumioGetState May 28 22:00:07 volumio volumio[937]: info: CorePlayQueue::getTrack 5 May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 28 22:00:07 volumio volumio[937]: info: Received Get System Info May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 22:00:07 volumio volumio[937]: info: Discovery: Getting this device information May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::volumioGetState May 28 22:00:07 volumio volumio[937]: info: CorePlayQueue::getTrack 5 May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::volumioGetState May 28 22:00:07 volumio volumio[937]: info: CorePlayQueue::getTrack 5 May 28 22:00:07 volumio volumio[937]: info: Listing playlists May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::volumioGetQueue May 28 22:00:07 volumio volumio[937]: info: CoreStateMachine::getQueue May 28 22:00:07 volumio volumio[937]: info: CorePlayQueue::getQueue May 28 22:00:07 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 28 22:00:17 volumio volumio[937]: info: CoreCommandRouter::volumioPlay May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::play index 1 May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::stop May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::play index undefined May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 22:00:17 volumio volumio[937]: info: CorePlayQueue::getTrack 1 May 28 22:00:17 volumio volumio[937]: info: CoreStateMachine::startPlaybackTimer May 28 22:00:17 volumio volumio[937]: info: CorePlayQueue::getTrack 1 May 28 22:00:17 volumio volumio[937]: info: [1779973217592] ControllerSpotify::clearAddPlayTrack May 28 22:00:17 volumio volumio[937]: info: Sending Spotify command with payload to local API: /player/play May 28 22:00:17 volumio go-librespot[1698]: time="2026-05-28T22:00:17+09:00" level=error msg="failed handling request play" error="failed resolving context: invalid status code from context resolve: 503" May 28 22:00:17 volumio volumio[937]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error May 28 22:00:20 volumio volumio[937]: info: CoreCommandRouter::volumioPlay May 28 22:00:20 volumio volumio[937]: info: CoreStateMachine::play index undefined May 28 22:00:20 volumio volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 22:00:20 volumio volumio[937]: info: CorePlayQueue::getTrack 1 May 28 22:00:20 volumio volumio[937]: info: CoreStateMachine::startPlaybackTimer May 28 22:00:20 volumio volumio[937]: info: CorePlayQueue::getTrack 1 May 28 22:00:20 volumio volumio[937]: info: [1779973220866] ControllerSpotify::clearAddPlayTrack May 28 22:00:20 volumio volumio[937]: info: Sending Spotify command with payload to local API: /player/play May 28 22:00:20 volumio go-librespot[1698]: time="2026-05-28T22:00:20+09:00" level=error msg="failed handling request play" error="failed resolving context: invalid status code from context resolve: 503" May 28 22:00:20 volumio volumio[937]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error May 28 22:00:22 volumio go-librespot[1698]: time="2026-05-28T22:00:22+09:00" level=trace msg="sent dealer ping" May 28 22:00:22 volumio go-librespot[1698]: time="2026-05-28T22:00:22+09:00" level=trace msg="received dealer pong" May 28 22:00:26 volumio volumio[937]: info: CoreCommandRouter::volumioClearQueue May 28 22:00:26 volumio volumio[937]: info: CoreStateMachine::ClearQueue May 28 22:00:26 volumio volumio[937]: info: CoreStateMachine::stop May 28 22:00:26 volumio volumio[937]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 22:00:26 volumio volumio[937]: info: CorePlayQueue::clearPlayQueue May 28 22:00:26 volumio volumio[937]: info: CorePlayQueue::saveQueue May 28 22:00:26 volumio volumio[937]: info: CoreCommandRouter::volumioPushState May 28 22:00:26 volumio volumio[937]: info: CoreCommandRouter::volumioPushQueue May 28 22:00:31 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 28 22:00:31 volumio volumio[937]: info: In handleBrowseUri, curUri=spotify May 28 22:00:31 volumio volumio[937]: info: Preload queue cleared May 28 22:00:31 volumio volumio[937]: info: Preload queue cleared May 28 22:00:31 volumio volumio[937]: info: Preload queue cleared May 28 22:00:31 volumio volumio[937]: info: Preload queue cleared May 28 22:00:35 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 28 22:00:35 volumio volumio[937]: info: In handleBrowseUri, curUri=spotify/myalbums May 28 22:00:41 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 28 22:00:41 volumio volumio[937]: info: In handleBrowseUri, curUri=spotify/myartists May 28 22:00:43 volumio volumio[937]: info: Preload queue cleared May 28 22:00:45 volumio volumio[937]: error: An error occurred while listing Spotify my albums WebapiError: [object Object] May 28 22:00:45 volumio volumio[937]: error: Failed to execute browseSource: May 28 22:00:51 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 28 22:00:51 volumio volumio[937]: info: In handleBrowseUri, curUri=spotify/myartists May 28 22:00:51 volumio go-librespot[1698]: time="2026-05-28T22:00:51+09:00" level=trace msg="received accesspoint ping" May 28 22:00:52 volumio go-librespot[1698]: time="2026-05-28T22:00:52+09:00" level=trace msg="received accesspoint pong ack" May 28 22:00:52 volumio go-librespot[1698]: time="2026-05-28T22:00:52+09:00" level=trace msg="sent dealer ping" May 28 22:00:52 volumio go-librespot[1698]: time="2026-05-28T22:00:52+09:00" level=trace msg="received dealer pong" May 28 22:00:54 volumio volumio[937]: info: Preload queue cleared May 28 22:01:01 volumio ntpd[1176]: PROTO: 129.250.35.250 unlink local addr 192.168.1.17 -> May 28 22:01:13 volumio ntpd[1176]: PROTO: 117.102.178.88 unlink local addr 192.168.1.17 -> May 28 22:01:22 volumio go-librespot[1698]: time="2026-05-28T22:01:22+09:00" level=trace msg="sent dealer ping" May 28 22:01:22 volumio go-librespot[1698]: time="2026-05-28T22:01:22+09:00" level=trace msg="received dealer pong" May 28 22:01:23 volumio volumio[937]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 28 22:01:23 volumio volumio[937]: info: In handleBrowseUri, curUri=spotify:artist:3JByu9VCNA1Rs6puGfRupj May 28 22:01:27 volumio volumio[937]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 22:01:27 volumio volumio[937]: WebapiError: [object Object] May 28 22:01:27 volumio volumio[937]: at _toError (/data/plugins/music_service/spop/node_modules/spotify-web-api-node/src/http-manager.js:47:10) May 28 22:01:27 volumio volumio[937]: at /data/plugins/music_service/spop/node_modules/spotify-web-api-node/src/http-manager.js:71:25 May 28 22:01:27 volumio volumio[937]: at Request.callback (/data/plugins/music_service/spop/node_modules/spotify-web-api-node/node_modules/superagent/lib/node/index.js:905:3) May 28 22:01:27 volumio volumio[937]: at IncomingMessage. (/data/plugins/music_service/spop/node_modules/spotify-web-api-node/node_modules/superagent/lib/node/index.js:1127:20) May 28 22:01:27 volumio volumio[937]: at IncomingMessage.emit (node:events:526:35) May 28 22:01:27 volumio volumio[937]: at endReadableNT (node:internal/streams/readable:1376:12) May 28 22:01:27 volumio volumio[937]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { May 28 22:01:27 volumio volumio[937]: body: {}, May 28 22:01:27 volumio volumio[937]: headers: { May 28 22:01:27 volumio volumio[937]: 'content-length': '91', May 28 22:01:27 volumio volumio[937]: 'content-type': 'text/plain', May 28 22:01:27 volumio volumio[937]: via: '1.1 google', May 28 22:01:27 volumio volumio[937]: date: 'Thu, 28 May 2026 13:01:27 GMT', May 28 22:01:27 volumio volumio[937]: 'alt-svc': 'h3=":443"; ma=2592000,h3-29=":443"; ma=2592000', May 28 22:01:27 volumio volumio[937]: connection: 'close' May 28 22:01:27 volumio volumio[937]: }, May 28 22:01:27 volumio volumio[937]: statusCode: 503 May 28 22:01:27 volumio volumio[937]: } May 28 22:01:27 volumio volumio[937]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 22:01:27 volumio sudo[5662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-28 22:00' May 28 22:01:27 volumio sudo[5662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"