-- Logs begin at Sat 2026-02-21 20:16:17 CET, end at Tue 2026-02-24 21:29:56 CET. -- Feb 24 21:28:09 volumio ntpd[873]: Soliciting pool server 162.159.200.123 Feb 24 21:28:14 volumio ntpd[873]: Soliciting pool server 2001:470:1f1c:298::9:123 Feb 24 21:28:16 volumio ntpd[873]: Soliciting pool server 193.104.37.238 Feb 24 21:28:18 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 21:28:18 volumio volumio[805]: info: CURURI: albums:// Feb 24 21:28:18 volumio volumio[805]: info: listAlbums - loading Albums from cache Feb 24 21:28:18 volumio ntpd[873]: Soliciting pool server 185.111.204.220 Feb 24 21:28:18 volumio volumio[805]: info: Preload queue cleared Feb 24 21:28:22 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 21:28:22 volumio volumio[805]: info: CURURI: playlists Feb 24 21:28:22 volumio volumio[805]: info: Listing playlists Feb 24 21:28:22 volumio volumio[805]: info: Preload queue cleared Feb 24 21:28:24 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 21:28:24 volumio volumio[805]: info: CURURI: artists:// Feb 24 21:28:24 volumio volumio[805]: info: Preload queue cleared Feb 24 21:28:25 volumio volumio[805]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:28:25 volumio volumio[805]: TypeError: Cannot read property 'slice' of null Feb 24 21:28:25 volumio volumio[805]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 24 21:28:25 volumio volumio[805]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 24 21:28:25 volumio volumio[805]: at Object.onceWrapper (events.js:422:26) Feb 24 21:28:25 volumio volumio[805]: at ClientRequest.emit (events.js:315:20) Feb 24 21:28:25 volumio volumio[805]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Feb 24 21:28:25 volumio volumio[805]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Feb 24 21:28:25 volumio volumio[805]: at TLSSocket.socketOnData (_http_client.js:509:22) Feb 24 21:28:25 volumio volumio[805]: at TLSSocket.emit (events.js:315:20) Feb 24 21:28:25 volumio volumio[805]: at addChunk (internal/streams/readable.js:309:12) Feb 24 21:28:25 volumio volumio[805]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 24 21:28:25 volumio volumio[805]: at TLSSocket.Readable.push (internal/streams/readable.js:223:10) Feb 24 21:28:25 volumio volumio[805]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Feb 24 21:28:25 volumio volumio[805]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:28:26 volumio sudo[2241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-24 21:27 Feb 24 21:28:26 volumio sudo[2241]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:26 volumio sudo[2241]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:26 volumio volumio-remote-updater[556]: [2026-02-24 21:28:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 24 21:28:26 volumio volumio-remote-updater[556]: [2026-02-24 21:28:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 24 21:28:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 24 21:28:26 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:26.829+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 24 21:28:26 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:26.832+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 24 21:28:26 volumio go-librespot[1106]: time="2026-02-24T21:28:26+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Feb 24 21:28:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 24 21:28:26 volumio systemd[1]: Started dynamicswap service. Feb 24 21:28:26 volumio systemd[1]: dynamicswap.service: Succeeded. Feb 24 21:28:27 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Feb 24 21:28:27 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Feb 24 21:28:27 volumio systemd[1]: Started dynamicswap service. Feb 24 21:28:27 volumio systemd[1]: Stopped Volumio Backend Module. Feb 24 21:28:27 volumio systemd[1]: Started Volumio Backend Module. Feb 24 21:28:27 volumio systemd[1]: dynamicswap.service: Succeeded. Feb 24 21:28:27 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:27.835+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 24 21:28:29 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:28:29 volumio volumio[2255]: info: ----- Volumio3 ---- Feb 24 21:28:29 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:28:29 volumio volumio[2255]: info: ----- System startup ---- Feb 24 21:28:29 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:28:30 volumio volumio[2255]: info: MYVOLUMIO Environment detected Feb 24 21:28:30 volumio volumio[2255]: info: Plugin folders cleanup Feb 24 21:28:30 volumio volumio[2255]: info: Scanning into folder /volumio/app/plugins/ Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category audio_interface Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category miscellanea Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category music_service Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category plugins.json Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category system_controller Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category user_interface Feb 24 21:28:30 volumio volumio[2255]: info: Scanning into folder /data/plugins/ Feb 24 21:28:30 volumio volumio[2255]: info: Scanning category music_service Feb 24 21:28:30 volumio volumio[2255]: info: Plugin folders cleanup completed Feb 24 21:28:30 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:28:30 volumio volumio[2255]: info: ----- Core plugins startup ---- Feb 24 21:28:30 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:28:30 volumio volumio[2255]: info: Loading plugins from folder /volumio/app/plugins/ Feb 24 21:28:30 volumio volumio[2255]: info: Adding plugin upnp to MyMusic Plugins Feb 24 21:28:30 volumio volumio[2255]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 24 21:28:30 volumio volumio[2255]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 24 21:28:30 volumio volumio[2255]: info: Loading plugins from folder /data/plugins/ Feb 24 21:28:30 volumio volumio[2255]: info: Loading plugin "system"... Feb 24 21:28:30 volumio volumio[2255]: info: Loading plugin "appearance"... Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "network"... Feb 24 21:28:31 volumio volumio[2255]: info: Refreshing Cached IP Addresses Feb 24 21:28:31 volumio sudo[2283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 21:28:31 volumio sudo[2283]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:31 volumio sudo[2283]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:31 volumio sudo[2285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 21:28:31 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "services"... Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "volumio5onboarding"... Feb 24 21:28:31 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "alsa_controller"... Feb 24 21:28:31 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "wizard"... Feb 24 21:28:31 volumio volumio-remote-updater[556]: [2026-02-24 21:28:31] [connect] Successful connection Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "networkfs"... Feb 24 21:28:31 volumio volumio[2255]: info: Cannot mount NAS HD_Music at system boot, trial number 1 ,retrying in 5 seconds Feb 24 21:28:31 volumio volumio[2255]: info: Starting Udev Watcher for removable devices Feb 24 21:28:31 volumio volumio[2255]: info: Ignoring mount for partition: boot Feb 24 21:28:31 volumio volumio[2255]: info: Ignoring mount for partition: volumio Feb 24 21:28:31 volumio volumio[2255]: info: Ignoring mount for partition: volumio_data Feb 24 21:28:31 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "volumio_command_line_client"... Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "upnp"... Feb 24 21:28:31 volumio volumio[2255]: info: [1771964911933] Starting Upmpd Daemon Feb 24 21:28:31 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "my_music"... Feb 24 21:28:31 volumio volumio[2255]: info: Loading plugin "mpd"... Feb 24 21:28:32 volumio volumio[2255]: info: Loading plugin "upnp_browser"... Feb 24 21:28:32 volumio volumio[2255]: info: Starting UPNP Browser Feb 24 21:28:32 volumio volumio[2255]: info: Loading plugin "alarm-clock"... Feb 24 21:28:32 volumio volumio[2255]: info: Loading plugin "airplay_emulation"... Feb 24 21:28:32 volumio volumio[2255]: info: Starting Shairport Sync Feb 24 21:28:32 volumio volumio[2255]: info: Loading plugin "last_100"... Feb 24 21:28:32 volumio volumio[2255]: info: Loading plugin "webradio"... Feb 24 21:28:33 volumio volumio[2255]: info: Loading plugin "i2s_dacs"... Feb 24 21:28:33 volumio volumio[2255]: info: Loading plugin "volumiodiscovery"... Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 24 21:28:33 volumio node[2255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 21:28:33 volumio node[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** For more information see Feb 24 21:28:33 volumio node[2255]: *** WARNING *** For more information see Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 24 21:28:33 volumio node[2255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 21:28:33 volumio node[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 21:28:33 volumio volumio[2255]: *** WARNING *** For more information see Feb 24 21:28:33 volumio node[2255]: *** WARNING *** For more information see Feb 24 21:28:33 volumio volumio[2255]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 24 21:28:33 volumio volumio[2255]: info: Discovery: Started advertising with name: Volumio Feb 24 21:28:33 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 21:28:33 volumio volumio[2255]: info: Loading plugin "spop"... Feb 24 21:28:34 volumio volumio[2255]: info: Loading plugin "outputs"... Feb 24 21:28:34 volumio volumio[2255]: info: Loading plugin "albumart"... Feb 24 21:28:34 volumio volumio[2255]: info: Plugin example_plugin is not enabled Feb 24 21:28:34 volumio volumio[2255]: info: Loading plugin "inputs"... Feb 24 21:28:34 volumio volumio[2255]: info: Loading plugin "updater_comm"... Feb 24 21:28:35 volumio volumio[2255]: info: Plugin mpdemulation is not enabled Feb 24 21:28:35 volumio volumio[2255]: info: Loading plugin "rest_api"... Feb 24 21:28:35 volumio volumio[2255]: info: Loading plugin "websocket"... Feb 24 21:28:35 volumio volumio[2255]: info: Starting Socket.io Server version 2.3.0 Feb 24 21:28:35 volumio volumio[2255]: info: Loading i18n strings for locale en Feb 24 21:28:35 volumio volumio[2255]: Updating browse sources language Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:35 volumio volumio[2255]: Forking 3 albumart workers Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::initPlayerControls Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:28:35 volumio volumio[2255]: Express server listening on port 3000 Feb 24 21:28:35 volumio volumio[2255]: [Metrics] WebUI: 6s 977.36ms Feb 24 21:28:35 volumio volumio[2255]: info: CoreStateMachine::resetVolumioState Feb 24 21:28:35 volumio volumio[2255]: info: CoreStateMachine::getcurrentVolume Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::volumioRetrievevolume Feb 24 21:28:35 volumio volumio[2255]: info: Volumio Network Manager: Network status updated: 1 Feb 24 21:28:35 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Feb 24 21:28:35 volumio volumio[2255]: verbose: New Socket.io Connection to 10.1.1.169 from 10.1.1.200 UA: Mozilla/5.0 (Linux; Android 16; Pixel 10 Pro Build/BP4A.260205.001.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 24 21:28:35 volumio volumio-remote-updater[556]: [2026-02-24 21:28:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1771964911 101 Feb 24 21:28:35 volumio volumio[2255]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 21:28:35 volumio volumio[2255]: info: Discovery: Getting this device information Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:35 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:35 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: Executing start script for DAC IQaudIO DAC Plus Feb 24 21:28:36 volumio volumio[2255]: info: Reloading queue from file Feb 24 21:28:36 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 24 21:28:36 volumio volumio[2255]: info: VolumeController:: Volume=51 Mute =false Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::pushState Feb 24 21:28:36 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioPushState Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::updateTrackBlock Feb 24 21:28:36 volumio volumio[2255]: info: CorePlayQueue::getTrackBlock Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioRetrievevolume Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.115+01:00 level=INFO msg="emitting player state changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" state=STATUS_STOPPED positionMs=0 volume=51 Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.116+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" id="mnt/NAS/HD_Music/Steven Wilson/Impossible Tightrope Live in Madrid/Binaural 24bit 48kHz/1. Objects Outlive Us (Live in Madrid) (Binaural).flac" title="1 - Objects Outlive Us (Live in Madrid) (Binaural)" Feb 24 21:28:36 volumio volumio[2255]: info: Setting Device type: Raspberry PI Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::setRepeat null single undefined Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::pushState Feb 24 21:28:36 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioPushState Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::setRandom null Feb 24 21:28:36 volumio volumio[2255]: info: CoreStateMachine::pushState Feb 24 21:28:36 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioPushState Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.175+01:00 level=INFO msg="emitting player state changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" state=STATUS_STOPPED positionMs=0 volume=51 Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.176+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" id="mnt/NAS/HD_Music/Steven Wilson/Impossible Tightrope Live in Madrid/Binaural 24bit 48kHz/1. Objects Outlive Us (Live in Madrid) (Binaural).flac" title="1 - Objects Outlive Us (Live in Madrid) (Binaural)" Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.180+01:00 level=INFO msg="emitting player state changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" state=STATUS_STOPPED positionMs=0 volume=51 Feb 24 21:28:36 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:36.181+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" id="mnt/NAS/HD_Music/Steven Wilson/Impossible Tightrope Live in Madrid/Binaural 24bit 48kHz/1. Objects Outlive Us (Live in Madrid) (Binaural).flac" title="1 - Objects Outlive Us (Live in Madrid) (Binaural)" Feb 24 21:28:36 volumio volumio[2255]: Starting albumart workers Feb 24 21:28:36 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Feb 24 21:28:36 volumio volumio[2255]: Starting albumart workers Feb 24 21:28:36 volumio volumio[2255]: info: DAC script executed Feb 24 21:28:36 volumio volumio[2255]: Starting albumart workers Feb 24 21:28:36 volumio volumio[2255]: info: Completed loading Core Plugins Feb 24 21:28:36 volumio volumio[2255]: info: Preparing to generate the ALSA configuration file Feb 24 21:28:36 volumio volumio[2255]: info: Asound.conf file unchanged, so no further update is needed Feb 24 21:28:36 volumio volumio[2255]: info: Output device has changed, restarting MPD Feb 24 21:28:36 volumio volumio[2255]: info: Output device has changed, restarting Shairport Sync Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:36 volumio sudo[2354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 21:28:36 volumio sudo[2354]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:36 volumio sudo[2354]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:36 volumio sudo[2356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 21:28:36 volumio sudo[2356]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:36 volumio systemd[1]: Stopping Music Player Daemon... Feb 24 21:28:36 volumio volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 21:28:36 volumio volumio[2255]: info: ___________ START PLUGINS ___________ Feb 24 21:28:36 volumio volumio[2255]: info: ControllerMpd::onStart: Initializing MPD Feb 24 21:28:36 volumio volumio[2255]: info: Creating MPD Configuration file Feb 24 21:28:36 volumio sudo[2363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 21:28:36 volumio volumio[2255]: info: [1771964916582] CoreMusicLibrary::Adding element Media Servers Feb 24 21:28:36 volumio sudo[2363]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:36 volumio sudo[2365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 21:28:36 volumio sudo[2365]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:36 volumio sudo[2365]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:36 volumio volumio[2255]: info: UPNP Browser: Client initialized successfully Feb 24 21:28:36 volumio sudo[2367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 21:28:36 volumio sudo[2367]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:36 volumio sudo[2363]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 21:28:36 volumio volumio[2255]: info: [1771964916808] CoreMusicLibrary::Adding element Last_100 Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 21:28:36 volumio volumio[2255]: info: [1771964916823] CoreMusicLibrary::Adding element Webradio Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 21:28:36 volumio volumio[2255]: info: Initializing BBC Radios Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 21:28:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:36 volumio volumio[2255]: info: Creating Spotify config file Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: Volumio Calling Home Feb 24 21:28:37 volumio volumio[2255]: info: Cannot mount NAS HD_Music at system boot, trial number 2 ,retrying in 5 seconds Feb 24 21:28:37 volumio volumio[2255]: info: Discovery: adding 89bdad76-5c45-4cf0-a2ba-4cdf97548b11 Feb 24 21:28:37 volumio volumio[2255]: info: Discovery: Found device Volumio Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:37 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:37 volumio volumio[2255]: info: MPD Permissions set Feb 24 21:28:37 volumio volumio[2255]: info: MPD Permissions set Feb 24 21:28:37 volumio volumio[2255]: info: VolumeController:: Volume=51 Mute =false Feb 24 21:28:37 volumio volumio[2255]: info: CoreStateMachine::pushState Feb 24 21:28:37 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::volumioPushState Feb 24 21:28:37 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:37.309+01:00 level=INFO msg="emitting player state changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" state=STATUS_STOPPED positionMs=0 volume=51 Feb 24 21:28:37 volumio volumio5-onboarding[1361]: time=2026-02-24T21:28:37.309+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.1.1.200:36380 @ 0x316e870" id="mnt/NAS/HD_Music/Steven Wilson/Impossible Tightrope Live in Madrid/Binaural 24bit 48kHz/1. Objects Outlive Us (Live in Madrid) (Binaural).flac" title="1 - Objects Outlive Us (Live in Madrid) (Binaural)" Feb 24 21:28:37 volumio volumio[2255]: info: Spotify config file written Feb 24 21:28:37 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 24 21:28:37 volumio sudo[2415]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 24 21:28:37 volumio volumio[2255]: info: Volumio called home Feb 24 21:28:37 volumio sudo[2415]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio systemd[1]: Stopping go-librespot Daemon... Feb 24 21:28:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Feb 24 21:28:37 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Feb 24 21:28:37 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:28:37 volumio systemd[1]: Started go-librespot Daemon. Feb 24 21:28:37 volumio go-librespot[2421]: Librespot-go daemon starting... Feb 24 21:28:37 volumio sudo[2415]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:37 volumio go-librespot[2421]: time="2026-02-24T21:28:37+01:00" level=info msg="generated new device id: 62df84f9b62f285287c617aa4a828e73e3920cf1" Feb 24 21:28:37 volumio go-librespot[2421]: time="2026-02-24T21:28:37+01:00" level=debug msg="stored credentials found for 118988518" Feb 24 21:28:37 volumio volumio[2255]: info: Starting Shairport Sync Feb 24 21:28:37 volumio volumio[2255]: info: Starting Shairport Sync Feb 24 21:28:37 volumio volumio[2255]: info: Starting Shairport Sync Feb 24 21:28:37 volumio sudo[2433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 21:28:37 volumio sudo[2433]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:37 volumio sudo[2437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 21:28:37 volumio sudo[2437]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:37 volumio sudo[2441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 21:28:37 volumio sudo[2441]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 24 21:28:37 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:37 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:37 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 24 21:28:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 24 21:28:37 volumio go-librespot[2421]: time="2026-02-24T21:28:37+01:00" level=debug msg="obtained new client token: AADGI0YqjrerfJE/Ii8aXIBmmkToK1lEUmUYqHfvL/r/piPQbkF5xTmDFTamC8DzEQNFdyxBpMd97Se5kKz1PWLo8aUNLKpue7QWDAliKjZecJ5SZFhtay8ds2JGB7yV32o/5wR4KDmhs3Hkf/0AqWFHXJPG/BHgYZeeheic2EZxCnt+gcCdExbzbx8T5jTClbtJ9GE7+8UXzu0XGHO6GlWn/x7ky31nHebZ3HT4AHwDYn0QSHw8BFULLpZiywc=" Feb 24 21:28:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 24 21:28:37 volumio sudo[2433]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:37 volumio sudo[2437]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:37 volumio sudo[2441]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:37 volumio go-librespot[2421]: time="2026-02-24T21:28:37+01: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]" Feb 24 21:28:38 volumio go-librespot[2421]: time="2026-02-24T21:28:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Feb 24 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 24 21:28:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 24 21:28:38 volumio volumio[2255]: info: Shairport-Sync Started Feb 24 21:28:38 volumio volumio[2255]: Error adding Membership: Error: addMembership EINVAL Feb 24 21:28:38 volumio volumio[2255]: info: Shairport-Sync Started Feb 24 21:28:38 volumio volumio[2255]: info: Shairport-Sync Started Feb 24 21:28:38 volumio volumio[2255]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 24 21:28:38 volumio volumio[2255]: SPOTIFY: BQA7XpCL8nwmuKEBaueaIU6bTZVFVSD65xMdGoRb-I7u1r77sgjc6rJxEoLkFUJ6jNRpebvXZfh1YQ2JZBlqoSDRyxrG7Psxd-Am7Eep704eRhLPw3zrIHauvpvh2XMZo3KvCJ7_eMWCHLZJX5V6NY5Xzt97_GiodZ36yw8sBcAj0AKrclHepx-7mVPBoit5xh91a-3QHt9nYV71ySmvxYmaRRvT9h8e6lQR6ngmAmxCQwbee5tOVUAzm3VCKFGQhWbYZHZiX-Xv-r1_wgaoftJN-BlRxvE9pm0 Feb 24 21:28:38 volumio volumio[2255]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 24 21:28:38 volumio volumio[2255]: info: New Spotify access token = BQA7XpCL8nwmuKEBaueaIU6bTZVFVSD65xMdGoRb-I7u1r77sgjc6rJxEoLkFUJ6jNRpebvXZfh1YQ2JZBlqoSDRyxrG7Psxd-Am7Eep704eRhLPw3zrIHauvpvh2XMZo3KvCJ7_eMWCHLZJX5V6NY5Xzt97_GiodZ36yw8sBcAj0AKrclHepx-7mVPBoit5xh91a-3QHt9nYV71ySmvxYmaRRvT9h8e6lQR6ngmAmxCQwbee5tOVUAzm3VCKFGQhWbYZHZiX-Xv-r1_wgaoftJN-BlRxvE9pm0 Feb 24 21:28:38 volumio volumio[2255]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 24 21:28:38 volumio volumio[2255]: SPOTIFY: User informations: {"country":"BE","display_name":"Piotr Ingling","email":"piotr@ingling.info","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/118988518"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/118988518","id":"118988518","images":[{"height":300,"url":"https://scontent-sea5-1.xx.fbcdn.net/v/t39.30808-1/514274342_24636173399302854_8145011673428954643_n.jpg?_nc_cat=110&ccb=1-7&_nc_sid=08baa4&_nc_ohc=EWfUxXrzj-oQ7kNvwGgniI4&_nc_oc=AdnDlu2zFJOFKYbJpOaN35Qx2ONoEvSisz_YQhSxb1shNV0-hWbqSy0UDEhb_Q2RjqrREWKvr7Q1GcrpOgnnWChq&_nc_zt=24&_nc_ht=scontent-sea5-1.xx&edm=AP4hL3IEAAAA&_nc_gid=VOYRtkznxCxBD7ZKhIocDQ&_nc_tpa=Q5bMBQGVeaBCNy0NFf0_7wHxSDztG0WD6hgSXuT6DJgGTJ0lon9fyvmXiOi__2ofV7U4ALp4SKF3&oh=00_AfvHiT2H3gZXfX1qk4IYEylwu9M1cSlCqkvgwDqdc5C5JQ&oe=69A33606","width":300},{"height":64,"url":"https://scontent-sea5-1.xx.fbcdn.net/v/t39.30808-1/514274342_24636173399302854_8145011673428954643_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=110&ccb=1-7&_nc_sid=28885b&_nc_ohc=EWfUxXrzj-oQ7kNvwGgniI4&_nc_oc=AdnDlu2zFJOFKYbJpOaN35Qx2ONoEvSisz_YQhSxb1shNV0-hWbqSy0UDEhb_Q2RjqrREWKvr7Q1GcrpOgnnWChq&_nc_zt=24&_nc_ht=scontent-sea5-1.xx&edm=AP4hL3IEAAAA&_nc_gid=VOYRtkznxCxBD7ZKhIocDQ&_nc_tpa=Q5bMBQFiG0mLr1imLzbQgnKtdhRDFSJt6nVpOUSkcg3e-tojEHbP2b8XTVrsMUtej028uqpNxkdC&oh=00_AftzqQjv4_FrihJV7YQ2PYopj7_mnSAZ2J5NuSdkxMtXDQ&oe=69A33606","width":64}],"product":"premium","type":"user","uri":"spotify:user:118988518"} Feb 24 21:28:38 volumio volumio[2255]: info: Spotify Successfully logged in Feb 24 21:28:38 volumio volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 21:28:38 volumio volumio[2255]: info: [1771964918326] CoreMusicLibrary::Adding element Spotify Feb 24 21:28:38 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:38 volumio volumio[2255]: Cannot find translation for source Spotify Feb 24 21:28:38 volumio volumio[2255]: verbose: New Socket.io Connection to 10.1.1.169 from 10.1.1.200 UA: Mozilla/5.0 (Linux; Android 16; Pixel 10 Pro Build/BP4A.260205.001.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 24 21:28:38 volumio volumio[2255]: verbose: New Socket.io Connection to 10.1.1.169:3000 from 10.1.1.200 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Feb 24 21:28:38 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 21:28:38 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 21:28:40 volumio volumio[2255]: info: go-librespot daemon successfully initialized Feb 24 21:28:41 volumio volumio[2255]: verbose: New Socket.io Connection to 10.1.1.169 from 10.1.1.200 UA: Mozilla/5.0 (Linux; Android 16; Pixel 10 Pro Build/BP4A.260205.001.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:41 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:28:41 volumio volumio[2255]: info: CoreStateMachine::getQueue Feb 24 21:28:41 volumio volumio[2255]: info: CorePlayQueue::getQueue Feb 24 21:28:41 volumio volumio[2255]: info: Listing playlists Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 21:28:41 volumio volumio[2255]: info: Received Get System Info Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 21:28:41 volumio volumio[2255]: info: Discovery: Getting this device information Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:41 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 21:28:41 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:41 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 24 21:28:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 24 21:28:41 volumio systemd[1]: Stopped go-librespot Daemon. Feb 24 21:28:41 volumio systemd[1]: Started go-librespot Daemon. Feb 24 21:28:41 volumio go-librespot[2448]: Librespot-go daemon starting... Feb 24 21:28:41 volumio go-librespot[2448]: time="2026-02-24T21:28:41+01:00" level=info msg="generated new device id: b723937b22dc69938ecaa4a7c13ac27f682629b0" Feb 24 21:28:41 volumio go-librespot[2448]: time="2026-02-24T21:28:41+01:00" level=debug msg="stored credentials found for 118988518" Feb 24 21:28:41 volumio go-librespot[2448]: time="2026-02-24T21:28:41+01:00" level=debug msg="obtained new client token: AAALiVNQTf92mkYMYHXjwZMkRF4MeNI/PbZ9wPc7s0Bjw0fe4kuW5dXf2K/cnSKlbS5xHxe5ynh0tgnbb/asfd8SNULDiUrg7ejGkX8GFYSusjBkypyoq+BcH0PmGt4BcIiM1l25W0pYlAJP0XeZ668MfsqyH907+H3YA7eJjdcl6OuK7Wm3S+S5aGYhg/aagVTdqYT8R/nMLj5r7wcJxmWZ6+pCF/3KwGK0NhIyUGX/quTeGgG31tgRkB0V/TM=" Feb 24 21:28:41 volumio go-librespot[2448]: time="2026-02-24T21:28:41+01: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]" Feb 24 21:28:41 volumio go-librespot[2448]: time="2026-02-24T21:28:41+01:00" level=debug msg="completed keyexchange" Feb 24 21:28:41 volumio sudo[2471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 21:28:41 volumio sudo[2471]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:41 volumio sudo[2471]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:41 volumio sudo[2473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 21:28:41 volumio sudo[2473]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:41 volumio sudo[2473]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:42 volumio sudo[2477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 24 21:28:42 volumio sudo[2477]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:28:42 volumio sudo[2477]: pam_unix(sudo:session): session closed for user root Feb 24 21:28:42 volumio volumio[2255]: info: Upmpdcli Daemon Started Feb 24 21:28:42 volumio volumio[2255]: info: Cannot mount NAS HD_Music at system boot, trial number 3 ,retrying in 5 seconds Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="completed challenge" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="authenticated as 118988518" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="authenticated as 118988518" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="dealer connection opened" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="received connection id: ZGJjMTI1MTgtNDBjMC00ZTdkLWJhMjktMDIzOWIwYWNjNjRkK2RlYWxlcit0Y3A6Ly8wYWIxNTE3NC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQ0ExMkVDNzkxRkVCMEI4RTNBQ0Q2MzI3MEFCOENBNTI3NjhFQzg1OUI2OTMxNEZFNTUzRUU1OThBNjZGMTAxQw==" Feb 24 21:28:42 volumio go-librespot[2448]: time="2026-02-24T21:28:42+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 24 21:28:43 volumio volumio[2255]: info: Initializing connection to go-librespot Websocket Feb 24 21:28:43 volumio go-librespot[2448]: time="2026-02-24T21:28:43+01:00" level=debug msg="new websocket client" Feb 24 21:28:43 volumio volumio[2255]: info: Connection to go-librespot Websocket established Feb 24 21:28:44 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 21:28:44 volumio volumio[2255]: info: CURURI: artists://Steven%20Wilson Feb 24 21:28:44 volumio volumio[2255]: error: Failed to execute browseSource, failure: TypeError: Cannot read property 'then' of undefined Feb 24 21:28:46 volumio volumio[2255]: info: Getting Spotify volume Feb 24 21:28:46 volumio volumio[2255]: info: Spotify volume: 100 Feb 24 21:28:46 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 24 21:28:46 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:28:46 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:28:46 volumio volumio[2255]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Feb 24 21:28:46 volumio volumio[2255]: SPOTIFY: SPOTIFY VOLUME 100 Feb 24 21:28:46 volumio volumio[2255]: SPOTIFY: VOLUMIO VOLUME 51 Feb 24 21:28:46 volumio volumio[2255]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 24 21:28:46 volumio volumio[2255]: info: Setting Spotify Volume from Volumio: 51 Feb 24 21:28:47 volumio volumio[2255]: info: Cannot mount NAS HD_Music at system boot, trial number 4 ,retrying in 5 seconds Feb 24 21:28:48 volumio volumio[2255]: SPOTIFY: SETTING SPOTIFY VOLUME 51 Feb 24 21:28:48 volumio volumio[2255]: info: Sending Spotify command with payload to local API: /player/volume Feb 24 21:28:48 volumio go-librespot[2448]: time="2026-02-24T21:28:48+01:00" level=debug msg="update volume to 33422/65535" Feb 24 21:28:48 volumio go-librespot[2448]: time="2026-02-24T21:28:48+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 24 21:28:48 volumio go-librespot[2448]: time="2026-02-24T21:28:48+01:00" level=trace msg="emitting websocket event: volume" Feb 24 21:28:48 volumio volumio[2255]: SPOTIFY: received: {"type":"volume","data":{"value":51,"max":100}} Feb 24 21:28:48 volumio volumio[2255]: SPOTIFY: RECEIVED SPOTIFY VOLUME 51 Feb 24 21:28:52 volumio volumio[2255]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Feb 24 21:29:07 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 21:29:07 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:07 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 21:29:07 volumio volumio[2255]: error: Plugin music_service mpd failed to complete 'onStart' in a timely fashion Feb 24 21:29:07 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:29:07 volumio volumio[2255]: info: ----- MyVolumio plugins startup ---- Feb 24 21:29:07 volumio volumio[2255]: info: ------------------------------------------- Feb 24 21:29:07 volumio volumio[2255]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 24 21:29:14 volumio ntpd[873]: Soliciting pool server 193.121.15.225 Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin bluetooth to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin multiroom to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin metavolumio to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin cd_controller to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 24 21:29:15 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 24 21:29:16 volumio volumio[2255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 24 21:29:16 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 24 21:29:16 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:16 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:16 volumio volumio[2255]: info: Starting MyVolumio Remote Streaming Endpoints Feb 24 21:29:16 volumio volumio[2255]: info: MyVolumio login type: Token Feb 24 21:29:16 volumio volumio[2255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 24 21:29:16 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 24 21:29:18 volumio volumio[2255]: info: Starting Streaming Service Transparent Proxy Feb 24 21:29:18 volumio volumio[2255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 24 21:29:18 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 24 21:29:18 volumio volumio[2255]: info: Streaming services startup Feb 24 21:29:18 volumio volumio[2255]: info: Starting Streaming Daemon Feb 24 21:29:18 volumio sudo[2570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 24 21:29:18 volumio sudo[2570]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:29:18 volumio volumio[2255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 24 21:29:18 volumio sudo[2570]: pam_unix(sudo:session): session closed for user root Feb 24 21:29:18 volumio volumio[2255]: error: Cannot start Volumio Streaming Daemon Feb 24 21:29:18 volumio volumio[2255]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 24 21:29:18 volumio volumio[2255]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 24 21:29:18 volumio volumio[2255]: error: MyVolumio Custom Token format not valid, refreshing it Feb 24 21:29:18 volumio ntpd[873]: Soliciting pool server 2a0d:5440::24 Feb 24 21:29:19 volumio volumio[2255]: STREAMING PROXY: Starting server on port 3245 Feb 24 21:29:19 volumio volumio[2255]: Node JS runtime: 14 Feb 24 21:29:19 volumio volumio[2255]: info: MyVolumio login type: Token Feb 24 21:29:19 volumio volumio[2255]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 24 21:29:20 volumio volumio[2255]: info: MyVolumio token set successfully Feb 24 21:29:20 volumio volumio[2255]: info: MYVOLUMIO: Adding device Feb 24 21:29:20 volumio volumio[2255]: info: MYVOLUMIO: Evaluating Server Feb 24 21:29:20 volumio volumio[2255]: info: MyVolumio Plan changed: virtuoso Feb 24 21:29:20 volumio volumio[2255]: info: [MyVolumio PluginManager] Subscribed plan changed to virtuoso Feb 24 21:29:20 volumio volumio[2255]: info: Removing browser output: myVolumio user plan is not superstar Feb 24 21:29:20 volumio volumio[2255]: info: Removing audio output: Feb 24 21:29:20 volumio volumio[2255]: info: MYVOLUMIO: Adding device Feb 24 21:29:20 volumio volumio[2255]: info: MYVOLUMIO: Evaluating Server Feb 24 21:29:20 volumio ntpd[873]: Soliciting pool server 156.106.214.52 Feb 24 21:29:20 volumio volumio[2255]: info: Remote config written successfully Feb 24 21:29:20 volumio volumio[2255]: info: Starting Tunnel 1 Feb 24 21:29:20 volumio volumio[2255]: info: Starting Tunnel Connection Checker Feb 24 21:29:20 volumio volumio[2255]: info: Completed starting MyVolumio Plugin Feb 24 21:29:20 volumio volumio[2255]: info: MYVolumio Device enabled Feb 24 21:29:20 volumio volumio[2255]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Feb 24 21:29:20 volumio volumio[2255]: info: MyVolumio status changed Feb 24 21:29:20 volumio volumio[2255]: info: Streaming services startup Feb 24 21:29:20 volumio volumio[2255]: info: Starting Streaming Daemon Feb 24 21:29:20 volumio sudo[2617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 24 21:29:20 volumio sudo[2617]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:29:20 volumio volumio[2255]: info: Setting Geolocation for MyVolumio to eu2 Feb 24 21:29:20 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:20 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:20 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:20 volumio sudo[2617]: pam_unix(sudo:session): session closed for user root Feb 24 21:29:20 volumio volumio[2255]: error: Cannot start Volumio Streaming Daemon Feb 24 21:29:20 volumio volumio[2255]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 24 21:29:20 volumio volumio[2255]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 24 21:29:20 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Feb 24 21:29:20 volumio volumio[2255]: error: [MyVolumio PluginManager] Cache data is invalid! Feb 24 21:29:21 volumio volumio[2255]: info: Setting Geolocation for MyVolumio to eu2 Feb 24 21:29:21 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:21 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:21 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:21 volumio volumio[2255]: info: Successfully Added MyVolumio device Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Feb 24 21:29:21 volumio volumio[2255]: info: [1771964961727] Starting BluetoothController Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Feb 24 21:29:21 volumio volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Feb 24 21:29:22 volumio volumio[2255]: info: Preparing CD Folders Feb 24 21:29:22 volumio volumio[2255]: info: Adding CD REST API Endpoints Feb 24 21:29:22 volumio volumio[2255]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Feb 24 21:29:22 volumio volumio[2255]: info: Starting UDEV Watcher for CD Feb 24 21:29:22 volumio volumio[2255]: info: Detecting CD presence with UDEV Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Feb 24 21:29:22 volumio sudo[2634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Feb 24 21:29:22 volumio sudo[2634]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Feb 24 21:29:22 volumio sudo[2634]: pam_unix(sudo:session): session closed for user root Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Feb 24 21:29:22 volumio volumio[2255]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Feb 24 21:29:22 volumio volumio[2255]: info: Adding TIDAL REST API Endpoints Feb 24 21:29:22 volumio volumio[2255]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Feb 24 21:29:22 volumio volumio[2255]: info: Stopping AccessToken refresher cron for QOBUZ Feb 24 21:29:22 volumio volumio[2255]: info: AccessToken refresher cron started for QOBUZ Feb 24 21:29:22 volumio volumio[2255]: info: Adding QOBUZ REST API Endpoints Feb 24 21:29:22 volumio volumio[2255]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Feb 24 21:29:22 volumio volumio[2255]: [Metrics] CommandRouter: 52s 887.80ms Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::volumiosetStartupVolume Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::Close All Modals sent Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::Close All Modals sent Feb 24 21:29:22 volumio volumio[2255]: info: Updating MyVolumio device info Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: Updating MyVolumio device info Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:29:22 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Feb 24 21:29:22 volumio volumio[2255]: info: Successfully Added MyVolumio device Feb 24 21:29:22 volumio volumio[2255]: info: Bluetooth name changed to Volumio Feb 24 21:29:22 volumio volumio[2255]: info: Successfully Updated MyVolumio device Feb 24 21:29:23 volumio volumio[2255]: info: Successfully Updated MyVolumio device Feb 24 21:29:23 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 24 21:29:23 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 21:29:23 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 24 21:29:24 volumio ntpd[873]: Soliciting pool server 156.106.214.52 Feb 24 21:29:25 volumio sudo[2641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Feb 24 21:29:25 volumio sudo[2641]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:29:25 volumio sudo[2641]: pam_unix(sudo:session): session closed for user root Feb 24 21:29:25 volumio volumio[2255]: info: Volumio BT Module successfully started Feb 24 21:29:25 volumio sudo[2648]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 24 21:29:25 volumio sudo[2648]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 21:29:25 volumio autossh[1187]: received signal to exit (15) Feb 24 21:29:25 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Feb 24 21:29:25 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Feb 24 21:29:25 volumio systemd[1]: sshtunnel.service: Succeeded. Feb 24 21:29:25 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Feb 24 21:29:25 volumio volumio[2255]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 24 21:29:25 volumio volumio[2255]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 24 21:29:25 volumio systemd[1]: Started MyVolumio SSH Tunnel. Feb 24 21:29:25 volumio sudo[2648]: pam_unix(sudo:session): session closed for user root Feb 24 21:29:25 volumio autossh[2651]: port set to 0, monitoring disabled Feb 24 21:29:25 volumio autossh[2651]: starting ssh (count 1) Feb 24 21:29:25 volumio autossh[2651]: ssh child pid is 2654 Feb 24 21:29:25 volumio volumio[2255]: info: Remote SSH Started Feb 24 21:29:25 volumio volumiossh-tunnel[2650]: Warning: Permanently added '[eu2.myvolumio.org]:2222,[185.14.187.123]:2222' (RSA) to the list of known hosts. Feb 24 21:29:25 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 24 21:29:25 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:29:25 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:29:29 volumio volumio[2255]: info: BOOT COMPLETED Feb 24 21:29:31 volumio volumio[2255]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Bjorn%20Riis/2d589c0a-783d-4c98-b958-47ab036bfe91.jpg' Feb 24 21:29:31 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 21:29:31 volumio volumio[2255]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Carol%20Kidd/2e42b6a0-98a9-462d-a339-b9896885d653.jpg' Feb 24 21:29:31 volumio volumio[2255]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Cassandra%20Wilson/ead981da-eea9-4350-b69f-b63fa36e878f.jpg' Feb 24 21:29:32 volumio volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 24 21:29:32 volumio volumio[2255]: info: CoreCommandRouter::volumioGetState Feb 24 21:29:32 volumio volumio[2255]: info: CorePlayQueue::getTrack 0 Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::volumioGetBrowseSources Feb 24 21:29:36 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 21:29:37 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 21:29:37 volumio volumio[2255]: info: CURURI: music-library Feb 24 21:29:37 volumio volumio[2255]: error: Failed to execute browseSource, failure: TypeError: Cannot read property 'then' of undefined Feb 24 21:29:42 volumio nmbd[696]: [2026/02/24 21:29:42.770920, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 24 21:29:42 volumio nmbd[696]: query_name_response: Multiple (2) responses received for a query on subnet 10.1.1.169 for name WORKGROUP<1d>. Feb 24 21:29:42 volumio nmbd[696]: This response was from IP 10.1.1.75, reporting an IP address of 10.1.1.75. Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: info: Retrieving Cloud Streaming UI Feb 24 21:29:51 volumio volumio[2255]: info: Getting Tidal Cloud Configuration Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: info: Getting Qobuz Cloud Configuration Feb 24 21:29:51 volumio volumio[2255]: info: Asking plugin for UI Config Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: info: Getting Spotify Cloud Configuration Feb 24 21:29:51 volumio volumio[2255]: info: Asking plugin for UI Config Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: info: Saving Spotify Acccount Feb 24 21:29:51 volumio volumio[2255]: info: Got it Feb 24 21:29:51 volumio volumio[2255]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 24 21:29:51 volumio volumio[2255]: info: Got Tidal Cloud Configuration Feb 24 21:29:51 volumio volumio[2255]: info: Got it Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:29:51 volumio volumio[2255]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::volumioGetBrowseSources Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::volumioGetBrowseSources Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::volumioGetBrowseSources Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 21:29:51 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 24 21:29:55 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 21:29:56 volumio volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Feb 24 21:29:56 volumio volumio[2255]: verbose: ControllerMpd::sendMpdCommand rescan Feb 24 21:29:56 volumio volumio[2255]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:29:56 volumio volumio[2255]: TypeError: Cannot read property 'then' of undefined Feb 24 21:29:56 volumio volumio[2255]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Feb 24 21:29:56 volumio volumio[2255]: at ControllerMpd.rescanDb (/volumio/app/plugins/music_service/mpd/index.js:1899:15) Feb 24 21:29:56 volumio volumio[2255]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Feb 24 21:29:56 volumio volumio[2255]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1098:26) Feb 24 21:29:56 volumio volumio[2255]: at Socket.emit (events.js:315:20) Feb 24 21:29:56 volumio volumio[2255]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Feb 24 21:29:56 volumio volumio[2255]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Feb 24 21:29:56 volumio volumio[2255]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:29:56 volumio sudo[2710]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-24 21:28 Feb 24 21:29:56 volumio sudo[2710]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"