-- Logs begin at Mon 2026-04-13 15:31:00 CEST, end at Mon 2026-04-13 15:33:48 CEST. -- Apr 13 15:32:01 volumioalrum go-librespot[2078]: time="2026-04-13T15:32:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 13 15:32:01 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 15:32:01 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 15:32:01 volumioalrum sudo[2114]: pam_unix(sudo:session): session closed for user root Apr 13 15:32:01 volumioalrum kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 13 15:32:01 volumioalrum kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Apr 13 15:32:01 volumioalrum volumio[1047]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Apr 13 15:32:03 volumioalrum volumio-time-update[774]: volumio-time-update-util: Date not found in response Apr 13 15:32:03 volumioalrum volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 15:32:04 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 15:32:04 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 13 15:32:04 volumioalrum systemd[1]: Stopped go-librespot Daemon. Apr 13 15:32:04 volumioalrum systemd[1]: Started go-librespot Daemon. Apr 13 15:32:04 volumioalrum go-librespot[2177]: go-librespot daemon starting... Apr 13 15:32:04 volumioalrum go-librespot[2177]: time="2026-04-13T15:32:04+02:00" level=info msg="running go-librespot 0.4.0" Apr 13 15:32:04 volumioalrum go-librespot[2177]: time="2026-04-13T15:32:04+02:00" level=debug msg="app state loaded" Apr 13 15:32:04 volumioalrum go-librespot[2177]: time="2026-04-13T15:32:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 15:32:07 volumioalrum volumio[1047]: error: MyVolumio Plugin failed to start in a timely fashion Apr 13 15:32:07 volumioalrum volumio[1047]: [Metrics] CommandRouter: 61s 568.26ms Apr 13 15:32:07 volumioalrum volumio[1047]: info: CoreCommandRouter::volumiosetStartupVolume Apr 13 15:32:07 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 15:32:07 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 15:32:07 volumioalrum volumio[1047]: info: CoreCommandRouter::Close All Modals sent Apr 13 15:32:07 volumioalrum volumio[1047]: info: CoreCommandRouter::Close All Modals sent Apr 13 15:32:07 volumioalrum volumio[1047]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 13 15:32:07 volumioalrum volumio[1047]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 13 15:32:07 volumioalrum volumio[1047]: info: camilladsp stopping service pid 1788... Apr 13 15:32:07 volumioalrum volumio[1047]: info: camilladsp service terminated, instance 1 Apr 13 15:32:07 volumioalrum volumio[1047]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 13 15:32:07 volumioalrum volumio[1047]: info: camilladsp service started and running in background, instance 1 Apr 13 15:32:08 volumioalrum volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Apr 13 15:32:08 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 13 15:32:08 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 15:32:08 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 13 15:32:10 volumioalrum dhcpcd[843]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Apr 13 15:32:11 volumioalrum dhcpcd[1590]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Apr 13 15:32:14 volumioalrum volumio[1047]: info: BOOT COMPLETED Apr 13 15:32:17 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 13 15:32:17 volumioalrum volumio[1047]: info: FusionDsp - {"Reload":{"result":"Ok"}} Apr 13 15:32:17 volumioalrum volumio[1047]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.912&uuid=d1746440935241e3ca8e6b2ea71fa945" http://updates.volumio.org/downloader-v1/track-device Apr 13 15:32:17 volumioalrum volumio[1047]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 13 15:32:17 volumioalrum volumio[1047]: Dload Upload Total Spent Left Speed Apr 13 15:32:17 volumioalrum volumio[1047]: [1.6K blob data] Apr 13 15:32:17 volumioalrum volumio[1047]: retrying in 5 seconds, trial 1 Apr 13 15:32:17 volumioalrum volumio[1047]: info: Volumio Calling Home Apr 13 15:32:24 volumioalrum go-librespot[2177]: time="2026-04-13T15:32:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 13 15:32:24 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 15:32:24 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 15:32:27 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 15:32:27 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 13 15:32:27 volumioalrum systemd[1]: Stopped go-librespot Daemon. Apr 13 15:32:27 volumioalrum systemd[1]: Started go-librespot Daemon. Apr 13 15:32:27 volumioalrum go-librespot[2242]: go-librespot daemon starting... Apr 13 15:32:27 volumioalrum go-librespot[2242]: time="2026-04-13T15:32:27+02:00" level=info msg="running go-librespot 0.4.0" Apr 13 15:32:27 volumioalrum go-librespot[2242]: time="2026-04-13T15:32:27+02:00" level=debug msg="app state loaded" Apr 13 15:32:27 volumioalrum go-librespot[2242]: time="2026-04-13T15:32:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 15:32:28 volumioalrum volumio-time-update[774]: volumio-time-update-util: Date not found in response Apr 13 15:32:28 volumioalrum volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 15:32:31 volumioalrum ntpd[1008]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 13 15:32:33 volumioalrum volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Apr 13 15:32:37 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 15:32:37 volumioalrum go-librespot[2242]: time="2026-04-13T15:32:37+02:00" level=debug msg="new websocket client" Apr 13 15:32:37 volumioalrum volumio[1047]: info: Connection to go-librespot Websocket established Apr 13 15:32:41 volumioalrum volumio[1047]: info: Getting Spotify volume Apr 13 15:32:47 volumioalrum go-librespot[2242]: time="2026-04-13T15:32:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 13 15:32:47 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 15:32:47 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 15:32:47 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 13 15:32:47 volumioalrum volumio[1047]: at connResetException (internal/errors.js:639:14) Apr 13 15:32:47 volumioalrum volumio[1047]: at Socket.socketOnEnd (_http_client.js:499:23) Apr 13 15:32:47 volumioalrum volumio[1047]: at Socket.emit (events.js:412:35) Apr 13 15:32:47 volumioalrum volumio[1047]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 13 15:32:47 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 13 15:32:47 volumioalrum volumio[1047]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 13 15:32:47 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Apr 13 15:32:47 volumioalrum volumio[1047]: (node:1047) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Apr 13 15:32:47 volumioalrum volumio[1047]: info: Connection to go-librespot Websocket closed Apr 13 15:32:48 volumioalrum volumio[1047]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.912&uuid=d1746440935241e3ca8e6b2ea71fa945" http://updates.volumio.org/downloader-v1/track-device Apr 13 15:32:48 volumioalrum volumio[1047]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 13 15:32:48 volumioalrum volumio[1047]: Dload Upload Total Spent Left Speed Apr 13 15:32:48 volumioalrum volumio[1047]: [1.6K blob data] Apr 13 15:32:48 volumioalrum volumio[1047]: retrying in 5 seconds, trial 2 Apr 13 15:32:48 volumioalrum volumio[1047]: info: Volumio Calling Home Apr 13 15:32:50 volumioalrum volumio[1047]: info: Initializing connection to go-librespot Websocket Apr 13 15:32:51 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 15:32:51 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 13 15:32:51 volumioalrum systemd[1]: Stopped go-librespot Daemon. Apr 13 15:32:51 volumioalrum systemd[1]: Started go-librespot Daemon. Apr 13 15:32:51 volumioalrum go-librespot[2302]: go-librespot daemon starting... Apr 13 15:32:51 volumioalrum go-librespot[2302]: time="2026-04-13T15:32:51+02:00" level=info msg="running go-librespot 0.4.0" Apr 13 15:32:51 volumioalrum go-librespot[2302]: time="2026-04-13T15:32:51+02:00" level=debug msg="app state loaded" Apr 13 15:32:51 volumioalrum go-librespot[2302]: time="2026-04-13T15:32:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 15:32:51 volumioalrum ntpd[1008]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 13 15:32:53 volumioalrum volumio-time-update[774]: volumio-time-update-util: Date not found in response Apr 13 15:32:53 volumioalrum volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 15:32:57 volumioalrum volumio[1047]: info: Discovery: adding d016a4a5-e68e-44ec-998d-33514b24f501 Apr 13 15:32:57 volumioalrum volumio[1047]: info: Discovery: Found device VolumioAlrum Apr 13 15:32:57 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioGetState Apr 13 15:32:57 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:32:57 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 15:32:58 volumioalrum volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Apr 13 15:33:03 volumioalrum dhcpcd[843]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Apr 13 15:33:04 volumioalrum dhcpcd[1590]: eth0: ignoring offer of 192.168.1.101 from 192.168.1.1 Apr 13 15:33:11 volumioalrum go-librespot[2302]: time="2026-04-13T15:33:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 13 15:33:11 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 15:33:11 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 15:33:11 volumioalrum ntpd[1008]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 13 15:33:14 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 15:33:14 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 13 15:33:14 volumioalrum systemd[1]: Stopped go-librespot Daemon. Apr 13 15:33:14 volumioalrum systemd[1]: Started go-librespot Daemon. Apr 13 15:33:14 volumioalrum go-librespot[2386]: go-librespot daemon starting... Apr 13 15:33:14 volumioalrum go-librespot[2386]: time="2026-04-13T15:33:14+02:00" level=info msg="running go-librespot 0.4.0" Apr 13 15:33:14 volumioalrum go-librespot[2386]: time="2026-04-13T15:33:14+02:00" level=debug msg="app state loaded" Apr 13 15:33:14 volumioalrum go-librespot[2386]: time="2026-04-13T15:33:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 15:33:18 volumioalrum volumio[1047]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: Apr 13 15:33:18 volumioalrum volumio[1047]: LoungeScreenDisconnected { Apr 13 15:33:18 volumioalrum volumio[1047]: AID: null, Apr 13 15:33:18 volumioalrum volumio[1047]: name: 'loungeScreenDisconnected', Apr 13 15:33:18 volumioalrum volumio[1047]: payload: {} Apr 13 15:33:18 volumioalrum volumio[1047]: } Apr 13 15:33:18 volumioalrum volumio[1047]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Apr 13 15:33:18 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:18 volumioalrum volumio[1047]: IncompleteAPIDataError: Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Apr 13 15:33:18 volumioalrum volumio[1047]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Apr 13 15:33:18 volumioalrum volumio[1047]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Apr 13 15:33:18 volumioalrum volumio[1047]: at AsyncTaskQueue.push (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:39:18) Apr 13 15:33:18 volumioalrum volumio[1047]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:339:67 Apr 13 15:33:18 volumioalrum volumio[1047]: at new Promise () Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.sendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:338:16) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:236:28) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:207:26) Apr 13 15:33:18 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:18 volumioalrum volumio[1047]: at async Promise.all (index 0) Apr 13 15:33:18 volumioalrum volumio[1047]: at async YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:110:13) Apr 13 15:33:18 volumioalrum volumio[1047]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Apr 13 15:33:18 volumioalrum volumio[1047]: error: [yt-cast-receiver] Failed to start receiver: Apr 13 15:33:18 volumioalrum volumio[1047]: (AppError) Failed to start YouTubeApp Apr 13 15:33:18 volumioalrum volumio[1047]: --->(SessionError) (YouTube) Failed to establish session Apr 13 15:33:18 volumioalrum volumio[1047]: ------>(ConnectionError) (YouTube) Connection error in generating screen Id Apr 13 15:33:18 volumioalrum volumio[1047]: Error info: { Apr 13 15:33:18 volumioalrum volumio[1047]: url: 'https://www.youtube.com/api/lounge/pairing/generate_screen_id' Apr 13 15:33:18 volumioalrum volumio[1047]: } Apr 13 15:33:18 volumioalrum volumio[1047]: --------->(FetchError) request to https://www.youtube.com/api/lounge/pairing/generate_screen_id failed, reason: getaddrinfo ENOTFOUND www.youtube.com Apr 13 15:33:18 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:18 volumioalrum volumio[1047]: AppError: Failed to start YouTubeApp Apr 13 15:33:18 volumioalrum volumio[1047]: at YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:125:19) Apr 13 15:33:18 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:18 volumioalrum volumio[1047]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Apr 13 15:33:18 volumioalrum volumio[1047]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: Apr 13 15:33:18 volumioalrum volumio[1047]: LoungeScreenDisconnected { Apr 13 15:33:18 volumioalrum volumio[1047]: AID: null, Apr 13 15:33:18 volumioalrum volumio[1047]: name: 'loungeScreenDisconnected', Apr 13 15:33:18 volumioalrum volumio[1047]: payload: {} Apr 13 15:33:18 volumioalrum volumio[1047]: } Apr 13 15:33:18 volumioalrum volumio[1047]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Apr 13 15:33:18 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:18 volumioalrum volumio[1047]: IncompleteAPIDataError: Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Apr 13 15:33:18 volumioalrum volumio[1047]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Apr 13 15:33:18 volumioalrum volumio[1047]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Apr 13 15:33:18 volumioalrum volumio[1047]: at AsyncTaskQueue.push (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:39:18) Apr 13 15:33:18 volumioalrum volumio[1047]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:339:67 Apr 13 15:33:18 volumioalrum volumio[1047]: at new Promise () Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.sendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:338:16) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:236:28) Apr 13 15:33:18 volumioalrum volumio[1047]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:118:35 Apr 13 15:33:18 volumioalrum volumio[1047]: at Array.forEach () Apr 13 15:33:18 volumioalrum volumio[1047]: at YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:114:24) Apr 13 15:33:18 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:18 volumioalrum volumio[1047]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Apr 13 15:33:18 volumioalrum volumio[1047]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: Apr 13 15:33:18 volumioalrum volumio[1047]: LoungeScreenDisconnected { Apr 13 15:33:18 volumioalrum volumio[1047]: AID: null, Apr 13 15:33:18 volumioalrum volumio[1047]: name: 'loungeScreenDisconnected', Apr 13 15:33:18 volumioalrum volumio[1047]: payload: {} Apr 13 15:33:18 volumioalrum volumio[1047]: } Apr 13 15:33:18 volumioalrum volumio[1047]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Apr 13 15:33:18 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:18 volumioalrum volumio[1047]: IncompleteAPIDataError: Missing data required to construct query string from bind params Apr 13 15:33:18 volumioalrum volumio[1047]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Apr 13 15:33:18 volumioalrum volumio[1047]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Apr 13 15:33:18 volumioalrum volumio[1047]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Apr 13 15:33:18 volumioalrum volumio[1047]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Apr 13 15:33:18 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:18 volumioalrum volumio[1047]: error: [ytcr] Failed to start plugin: Apr 13 15:33:18 volumioalrum volumio[1047]: (AppError) Failed to start YouTubeApp Apr 13 15:33:18 volumioalrum volumio[1047]: --->(SessionError) (YouTube) Failed to establish session Apr 13 15:33:18 volumioalrum volumio[1047]: ------>(ConnectionError) (YouTube) Connection error in generating screen Id Apr 13 15:33:18 volumioalrum volumio[1047]: Error info: { Apr 13 15:33:18 volumioalrum volumio[1047]: url: 'https://www.youtube.com/api/lounge/pairing/generate_screen_id' Apr 13 15:33:18 volumioalrum volumio[1047]: } Apr 13 15:33:18 volumioalrum volumio[1047]: --------->(FetchError) request to https://www.youtube.com/api/lounge/pairing/generate_screen_id failed, reason: getaddrinfo ENOTFOUND www.youtube.com Apr 13 15:33:18 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:18 volumioalrum volumio[1047]: AppError: Failed to start YouTubeApp Apr 13 15:33:18 volumioalrum volumio[1047]: at YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:125:19) Apr 13 15:33:18 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:18 volumioalrum volumio[1047]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/YouTubeCastReceiver.js:91:13) Apr 13 15:33:18 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 15:33:18 volumioalrum volumio-time-update[774]: volumio-time-update-util: Date not found in response Apr 13 15:33:18 volumioalrum volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 15:33:23 volumioalrum volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Apr 13 15:33:31 volumioalrum ntpd[1008]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 13 15:33:34 volumioalrum go-librespot[2386]: time="2026-04-13T15:33:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Apr 13 15:33:34 volumioalrum systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 13 15:33:34 volumioalrum systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 15:33:35 volumioalrum dhcpcd[843]: eth0: probing address 192.168.1.101/24 Apr 13 15:33:36 volumioalrum dhcpcd[1590]: eth0: probing address 192.168.1.101/24 Apr 13 15:33:37 volumioalrum systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 13 15:33:37 volumioalrum systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 13 15:33:37 volumioalrum systemd[1]: Stopped go-librespot Daemon. Apr 13 15:33:37 volumioalrum systemd[1]: Started go-librespot Daemon. Apr 13 15:33:37 volumioalrum go-librespot[2427]: go-librespot daemon starting... Apr 13 15:33:37 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:37+02:00" level=info msg="running go-librespot 0.4.0" Apr 13 15:33:37 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:37+02:00" level=debug msg="app state loaded" Apr 13 15:33:37 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 15:33:37 volumioalrum volumio[1047]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: Apr 13 15:33:37 volumioalrum volumio[1047]: LoungeScreenDisconnected { Apr 13 15:33:37 volumioalrum volumio[1047]: AID: null, Apr 13 15:33:37 volumioalrum volumio[1047]: name: 'loungeScreenDisconnected', Apr 13 15:33:37 volumioalrum volumio[1047]: payload: {} Apr 13 15:33:37 volumioalrum volumio[1047]: } Apr 13 15:33:37 volumioalrum volumio[1047]: (IncompleteAPIDataError) Missing data required to construct query string from bind params Apr 13 15:33:37 volumioalrum volumio[1047]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } Apr 13 15:33:37 volumioalrum volumio[1047]: Stack trace: Apr 13 15:33:37 volumioalrum volumio[1047]: IncompleteAPIDataError: Missing data required to construct query string from bind params Apr 13 15:33:37 volumioalrum volumio[1047]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) Apr 13 15:33:37 volumioalrum volumio[1047]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) Apr 13 15:33:37 volumioalrum volumio[1047]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) Apr 13 15:33:37 volumioalrum volumio[1047]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) Apr 13 15:33:37 volumioalrum volumio[1047]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) Apr 13 15:33:37 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:37 volumioalrum volumio[1047]: at async /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/YouTubeApp.js:118:21 Apr 13 15:33:38 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 15:33:40 volumioalrum dhcpcd[843]: eth0: leased 192.168.1.101 for 86400 seconds Apr 13 15:33:40 volumioalrum dhcpcd[843]: eth0: adding route to 192.168.1.0/24 Apr 13 15:33:40 volumioalrum dhcpcd[843]: eth0: changing default route via 192.168.1.1 Apr 13 15:33:40 volumioalrum dhcpcd[1590]: eth0: deleted default route Apr 13 15:33:40 volumioalrum avahi-daemon[765]: Registering new address record for 192.168.1.101 on eth0.IPv4. Apr 13 15:33:40 volumioalrum ntpd[1008]: ntpd exiting on signal 15 (Terminated) Apr 13 15:33:40 volumioalrum systemd[1]: Stopping Network Time Service... Apr 13 15:33:40 volumioalrum systemd[1]: ntp.service: Succeeded. Apr 13 15:33:40 volumioalrum systemd[1]: Stopped Network Time Service. Apr 13 15:33:40 volumioalrum systemd[1]: Starting Network Time Service... Apr 13 15:33:40 volumioalrum ntpd[2482]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 13 15:33:40 volumioalrum ntpd[2482]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 13 15:33:40 volumioalrum systemd[1]: Started Network Time Service. Apr 13 15:33:40 volumioalrum ntpd[2488]: proto: precision = 0.187 usec (-22) Apr 13 15:33:40 volumioalrum ntpd[2488]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 13 15:33:40 volumioalrum ntpd[2488]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 13 15:33:40 volumioalrum ntpd[2488]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1203 days ago Apr 13 15:33:40 volumioalrum ntpd[2488]: Listen and drop on 0 v6wildcard [::]:123 Apr 13 15:33:40 volumioalrum ntpd[2488]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 13 15:33:40 volumioalrum ntpd[2488]: Listen normally on 2 lo 127.0.0.1:123 Apr 13 15:33:40 volumioalrum ntpd[2488]: Listen normally on 3 eth0 169.254.251.118:123 Apr 13 15:33:40 volumioalrum ntpd[2488]: Listen normally on 4 eth0 192.168.1.101:123 Apr 13 15:33:40 volumioalrum ntpd[2488]: Listening on routing socket on fd #21 for interface updates Apr 13 15:33:40 volumioalrum ntpd[2488]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 15:33:40 volumioalrum ntpd[2488]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 15:33:40 volumioalrum avahi-daemon[765]: Withdrawing address record for 169.254.251.118 on eth0. Apr 13 15:33:40 volumioalrum avahi-daemon[765]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.251.118. Apr 13 15:33:40 volumioalrum dhcpcd[843]: eth0: deleting route to 169.254.0.0/16 Apr 13 15:33:40 volumioalrum dhcpcd[1590]: eth0: deleted route to 169.254.0.0/16 Apr 13 15:33:40 volumioalrum dhcpcd[1590]: eth0: adding route to 169.254.0.0/16 Apr 13 15:33:40 volumioalrum dhcpcd[1590]: if_route (ADD): Invalid argument Apr 13 15:33:40 volumioalrum dhcpcd[1590]: eth0: adding default route Apr 13 15:33:40 volumioalrum dhcpcd[1590]: if_route (ADD): Invalid argument Apr 13 15:33:40 volumioalrum avahi-daemon[765]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.101. Apr 13 15:33:41 volumioalrum ntpd[2488]: Soliciting pool server 5.186.56.205 Apr 13 15:33:42 volumioalrum dhcpcd[1590]: eth0: leased 192.168.1.101 for 86400 seconds Apr 13 15:33:42 volumioalrum dhcpcd[1590]: eth0: adding route to 192.168.1.0/24 Apr 13 15:33:42 volumioalrum dhcpcd[1590]: eth0: adding default route via 192.168.1.1 Apr 13 15:33:42 volumioalrum dhcpcd[1590]: eth0: adding route to 169.254.0.0/16 Apr 13 15:33:42 volumioalrum dhcpcd[1590]: if_route (ADD): Invalid argument Apr 13 15:33:42 volumioalrum ntpd[2488]: Soliciting pool server 192.36.143.130 Apr 13 15:33:42 volumioalrum ntpd[2488]: Deleting interface #3 eth0, 169.254.251.118#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Apr 13 15:33:42 volumioalrum ntpd[2488]: Soliciting pool server 212.132.97.26 Apr 13 15:33:42 volumioalrum ntpd[2488]: ntpd exiting on signal 15 (Terminated) Apr 13 15:33:42 volumioalrum systemd[1]: Stopping Network Time Service... Apr 13 15:33:42 volumioalrum ntpd[2488]: 5.186.56.205 local addr 192.168.1.101 -> Apr 13 15:33:42 volumioalrum ntpd[2488]: 192.36.143.130 local addr 192.168.1.101 -> Apr 13 15:33:42 volumioalrum ntpd[2488]: 212.132.97.26 local addr 192.168.1.101 -> Apr 13 15:33:42 volumioalrum systemd[1]: ntp.service: Succeeded. Apr 13 15:33:42 volumioalrum systemd[1]: Stopped Network Time Service. Apr 13 15:33:42 volumioalrum systemd[1]: Starting Network Time Service... Apr 13 15:33:42 volumioalrum ntpd[2538]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 13 15:33:42 volumioalrum ntpd[2538]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 13 15:33:42 volumioalrum systemd[1]: Started Network Time Service. Apr 13 15:33:42 volumioalrum ntpd[2544]: proto: precision = 0.187 usec (-22) Apr 13 15:33:42 volumioalrum ntpd[2544]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 13 15:33:42 volumioalrum ntpd[2544]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 13 15:33:42 volumioalrum ntpd[2544]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1203 days ago Apr 13 15:33:42 volumioalrum ntpd[2544]: Listen and drop on 0 v6wildcard [::]:123 Apr 13 15:33:42 volumioalrum ntpd[2544]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 13 15:33:42 volumioalrum ntpd[2544]: Listen normally on 2 lo 127.0.0.1:123 Apr 13 15:33:42 volumioalrum ntpd[2544]: Listen normally on 3 eth0 192.168.1.101:123 Apr 13 15:33:42 volumioalrum ntpd[2544]: Listening on routing socket on fd #20 for interface updates Apr 13 15:33:42 volumioalrum ntpd[2544]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 15:33:42 volumioalrum ntpd[2544]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 15:33:42 volumioalrum kernel: traps: dhcpcd[1590] general protection fault ip:5572abccf075 sp:7fffbb6139d0 error:0 in dhcpcd[5572abcba000+32000] Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="new websocket client" Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=info msg="zeroconf server listening on port 38111" Apr 13 15:33:43 volumioalrum volumio[1047]: info: Connection to go-librespot Websocket established Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Apr 13 15:33:43 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Apr 13 15:33:43 volumioalrum volumio-time-update[774]: volumio-time-update-util: Date not found in response Apr 13 15:33:43 volumioalrum volumio-time-update[774]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 15:33:43 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioGetState Apr 13 15:33:43 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="obtained new client token: AAB+15nbF8PpxXhx/CtmU0BebE5IU/bN23IySPOMdW2uswgTEYEtnwEIiZNDZuGfPDPL5/gMRIo/BLjpiKll9iKtdl8SRRaql6nCTIQoVVRZksNIG8nPTXQGnj3fjnwotP8KaPWjJY23QCmKXXNBihj+jwII5RqoSMvh5SPuBo4UhxrYv7/T3fG+sfYz/S2vVEujk5F4na5H2WTpCnHP76r+8brQzzJNWKYFf8EfXahMwjMqSwtVETQO6A==" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="completed keyexchange" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="completed challenge" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=info msg="authenticated AP" username="th*****99" Apr 13 15:33:43 volumioalrum ntpd[2544]: Soliciting pool server 195.72.61.39 Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=info msg="authenticated Login5" username="th*****99" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="initializing zeroconf session" username="th*****99" Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin bluetooth to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin multiroom to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin metavolumio to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin cd_controller to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 13 15:33:43 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="dealer connection opened" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=trace msg="starting accesspoint recv loop" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=trace msg="starting dealer recv loop" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=trace msg="received accesspoint ping" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="received connection id: ZjY0NmVjNTktMzQx...MTBENTUwN0VGMQ==" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=trace msg="received accesspoint pong ack" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 13 15:33:43 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:43+02:00" level=debug msg="update volume requested to 65535/65535" Apr 13 15:33:44 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:44+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 13 15:33:44 volumioalrum go-librespot[2427]: time="2026-04-13T15:33:44+02:00" level=trace msg="emitting websocket event: volume" Apr 13 15:33:44 volumioalrum ntpd[2544]: Soliciting pool server 193.200.91.90 Apr 13 15:33:44 volumioalrum ntpd[2544]: Soliciting pool server 162.159.200.123 Apr 13 15:33:44 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 13 15:33:44 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 13 15:33:44 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 15:33:44 volumioalrum volumio[1047]: info: Starting MyVolumio Remote Streaming Endpoints Apr 13 15:33:44 volumioalrum volumio[1047]: info: MyVolumio login type: Token Apr 13 15:33:44 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 13 15:33:44 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 13 15:33:45 volumioalrum ntpd[2544]: Soliciting pool server 86.52.51.137 Apr 13 15:33:45 volumioalrum ntpd[2544]: Soliciting pool server 192.36.143.130 Apr 13 15:33:45 volumioalrum ntpd[2544]: Soliciting pool server 87.63.200.138 Apr 13 15:33:45 volumioalrum volumio[1047]: info: Starting Streaming Service Transparent Proxy Apr 13 15:33:45 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 13 15:33:45 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 13 15:33:45 volumioalrum volumio[1047]: info: Streaming services startup Apr 13 15:33:45 volumioalrum volumio[1047]: info: Starting Streaming Daemon Apr 13 15:33:45 volumioalrum sudo[2556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 15:33:45 volumioalrum sudo[2556]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 15:33:45 volumioalrum sudo[2556]: pam_unix(sudo:session): session closed for user root Apr 13 15:33:45 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 13 15:33:45 volumioalrum volumio[1047]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 13 15:33:45 volumioalrum volumio[1047]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 13 15:33:45 volumioalrum volumio[1047]: info: Setting Volumio Volume from Spotify: 100 Apr 13 15:33:45 volumioalrum volumio[1047]: info: VolumeController::SetAlsaVolume100 Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioGetState Apr 13 15:33:45 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreStateMachine::pushState Apr 13 15:33:45 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioPushState Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 15:33:45 volumioalrum volumio[1047]: info: Received Get System Info Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 15:33:45 volumioalrum volumio[1047]: info: Discovery: Getting this device information Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioGetState Apr 13 15:33:45 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:33:45 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 15:33:45 volumioalrum volumio[1047]: error: Cannot start Volumio Streaming Daemon Apr 13 15:33:45 volumioalrum volumio[1047]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 13 15:33:45 volumioalrum volumio[1047]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Apr 13 15:33:46 volumioalrum volumio[1047]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Apr 13 15:33:46 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 7) Apr 13 15:33:46 volumioalrum volumio[1047]: info: Getting Spotify volume Apr 13 15:33:46 volumioalrum volumio[1047]: info: Spotify volume: 100 Apr 13 15:33:46 volumioalrum volumio[1047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Apr 13 15:33:46 volumioalrum volumio[1047]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Apr 13 15:33:46 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 8) Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Apr 13 15:33:46 volumioalrum volumio[1047]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Apr 13 15:33:46 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 9) Apr 13 15:33:46 volumioalrum volumio[1047]: info: CoreCommandRouter::volumioGetState Apr 13 15:33:46 volumioalrum volumio[1047]: info: CorePlayQueue::getTrack 0 Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined Apr 13 15:33:46 volumioalrum volumio[1047]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) Apr 13 15:33:46 volumioalrum volumio[1047]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Apr 13 15:33:46 volumioalrum volumio[1047]: (node:1047) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 10) Apr 13 15:33:46 volumioalrum volumio[1047]: error: MyVolumio Custom Token format not valid, refreshing it Apr 13 15:33:46 volumioalrum volumio[1047]: STREAMING PROXY: Starting server on port 3245 Apr 13 15:33:46 volumioalrum volumio[1047]: Node JS runtime: 14 Apr 13 15:33:46 volumioalrum ntpd[2544]: Soliciting pool server 80.248.138.19 Apr 13 15:33:46 volumioalrum ntpd[2544]: Soliciting pool server 80.209.68.118 Apr 13 15:33:46 volumioalrum ntpd[2544]: Soliciting pool server 5.186.56.205 Apr 13 15:33:46 volumioalrum ntpd[2544]: Soliciting pool server 185.181.223.169 Apr 13 15:33:46 volumioalrum volumio[1047]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 13 15:33:46 volumioalrum volumio[1047]: info: MyVolumio login type: Token Apr 13 15:33:46 volumioalrum volumio[1047]: info: MyVolumio login type: Token Apr 13 15:33:47 volumioalrum volumio[1047]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 13 15:33:47 volumioalrum ntpd[2544]: Soliciting pool server 87.104.58.9 Apr 13 15:33:47 volumioalrum ntpd[2544]: Soliciting pool server 213.5.39.34 Apr 13 15:33:47 volumioalrum ntpd[2544]: Soliciting pool server 212.132.97.26 Apr 13 15:33:48 volumioalrum volumio[1047]: info: MyVolumio token set successfully Apr 13 15:33:48 volumioalrum volumio[1047]: info: MYVOLUMIO: Adding device Apr 13 15:33:48 volumioalrum volumio[1047]: info: MYVOLUMIO: Evaluating Server Apr 13 15:33:48 volumioalrum volumio-time-update[774]: volumio-time-update-util: Fetching time from Volumio... Apr 13 15:33:48 volumioalrum volumio-time-update[774]: volumio-time-update-util: Setting system time to: 2026-04-13 15:33:47 Apr 13 15:33:48 volumioalrum sudo[2573]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-04-13 15:33:47 Apr 13 15:33:48 volumioalrum sudo[2573]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 15:33:48 volumioalrum dbus-daemon[781]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.25' (uid=0 pid=2574 comm="timedatectl set-time 2026-04-13 15:33:47 ") Apr 13 15:33:48 volumioalrum systemd[1]: Starting Time & Date Service... Apr 13 15:33:48 volumioalrum ntpd[2544]: Soliciting pool server 86.52.112.177 Apr 13 15:33:48 volumioalrum ntpd[2544]: Soliciting pool server 162.159.200.1 Apr 13 15:33:48 volumioalrum dbus-daemon[781]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 13 15:33:48 volumioalrum systemd[1]: Started Time & Date Service. Apr 13 15:33:47 volumioalrum systemd-timedated[2578]: Changed local time to Mon Apr 13 15:33:47 2026 Apr 13 15:33:47 volumioalrum sudo[2573]: pam_unix(sudo:session): session closed for user root Apr 13 15:33:47 volumioalrum volumio-time-update[774]: volumio-time-update-util: System time updated successfully. Apr 13 15:33:47 volumioalrum systemd[1]: Started Volumio Time Update Utility. Apr 13 15:33:47 volumioalrum systemd[1]: Reached target Multi-User System. Apr 13 15:33:47 volumioalrum systemd[1]: Reached target Graphical Interface. Apr 13 15:33:47 volumioalrum systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 13 15:33:47 volumioalrum systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 13 15:33:47 volumioalrum systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 13 15:33:47 volumioalrum systemd[1]: Startup finished in 9.167s (firmware) + 2.689s (loader) + 10.084s (kernel) + 2min 49.304s (userspace) = 3min 11.246s. Apr 13 15:33:47 volumioalrum volumio[1047]: info: MyVolumio Plan changed: premium Apr 13 15:33:47 volumioalrum volumio[1047]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 13 15:33:47 volumioalrum volumio[1047]: info: Removing browser output: myVolumio user plan is not superstar Apr 13 15:33:47 volumioalrum volumio[1047]: info: Removing audio output: Apr 13 15:33:47 volumioalrum volumio[1047]: info: MYVOLUMIO: Adding device Apr 13 15:33:47 volumioalrum volumio[1047]: info: MYVOLUMIO: Evaluating Server Apr 13 15:33:47 volumioalrum volumio[1047]: error: Failed to ping endpoint us1.myvolumio.org : unknown error Apr 13 15:33:47 volumioalrum volumio[1047]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 15:33:47 volumioalrum volumio[1047]: Error: Unable to resolve or reject the same promise twice Apr 13 15:33:47 volumioalrum volumio[1047]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 13 15:33:47 volumioalrum volumio[1047]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Apr 13 15:33:47 volumioalrum volumio[1047]: at Socket.emit (events.js:400:28) Apr 13 15:33:47 volumioalrum volumio[1047]: at addChunk (internal/streams/readable.js:293:12) Apr 13 15:33:47 volumioalrum volumio[1047]: at readableAddChunk (internal/streams/readable.js:267:9) Apr 13 15:33:47 volumioalrum volumio[1047]: at Socket.Readable.push (internal/streams/readable.js:206:10) Apr 13 15:33:47 volumioalrum volumio[1047]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Apr 13 15:33:47 volumioalrum volumio[1047]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 15:33:47 volumioalrum sudo[2602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-13 15:32 Apr 13 15:33:47 volumioalrum sudo[2602]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 09:58:18 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="54b3518c7dd8feba4753e0ad124ce801"