Apr 11 09:28:36 volumio go-librespot[29871]: time="2026-04-11T09:28:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Apr 11 09:28:37 volumio go-librespot[29871]: time="2026-04-11T09:28:37+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:28:38 volumio go-librespot[29871]: time="2026-04-11T09:28:38+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:38 volumio go-librespot[29871]: time="2026-04-11T09:28:38+01:00" level=debug msg="completed challenge" Apr 11 09:28:38 volumio go-librespot[29871]: time="2026-04-11T09:28:38+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:38 volumio go-librespot[29871]: time="2026-04-11T09:28:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:38 volumio volumio[29588]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 11 09:28:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:28:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:28:38 volumio volumio[29588]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:28:38 volumio volumio[29588]: Error: socket hang up Apr 11 09:28:38 volumio volumio[29588]: at connResetException (node:internal/errors:720:14) Apr 11 09:28:38 volumio volumio[29588]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 11 09:28:38 volumio volumio[29588]: at Socket.emit (node:events:526:35) Apr 11 09:28:38 volumio volumio[29588]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 11 09:28:38 volumio volumio[29588]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 11 09:28:38 volumio volumio[29588]: code: 'ECONNRESET', Apr 11 09:28:38 volumio volumio[29588]: response: undefined Apr 11 09:28:38 volumio volumio[29588]: } Apr 11 09:28:38 volumio volumio[29588]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:28:38 volumio sudo[30854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 09:27' Apr 11 09:28:38 volumio sudo[30854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:38 volumio sudo[30854]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:38 volumio volumio-remote-updater[945]: [2026-04-11 09:28:38] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 11 09:28:38 volumio volumio-remote-updater[945]: [2026-04-11 09:28:38] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 11 09:28:38 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:28:38 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 11 09:28:38 volumio systemd[1]: volumio.service: Consumed 11.310s CPU time. Apr 11 09:28:38 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:28:38 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:28:38 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 114275. Apr 11 09:28:38 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:28:38 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 11 09:28:38 volumio systemd[1]: volumio.service: Consumed 11.310s CPU time. Apr 11 09:28:38 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 11 09:28:38 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:28:39 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:39 volumio volumio[30893]: info: ----- Volumio3 ---- Apr 11 09:28:39 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:39 volumio volumio[30893]: info: ----- System startup ---- Apr 11 09:28:39 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:39 volumio volumio[30893]: info: MYVOLUMIO Environment detected Apr 11 09:28:39 volumio volumio[30893]: info: Plugin folders cleanup Apr 11 09:28:39 volumio volumio[30893]: info: Scanning into folder /volumio/app/plugins/ Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category audio_interface Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category miscellanea Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category music_service Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category plugins.json Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category system_controller Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category user_interface Apr 11 09:28:39 volumio volumio[30893]: info: Scanning into folder /data/plugins/ Apr 11 09:28:39 volumio volumio[30893]: info: Scanning category music_service Apr 11 09:28:39 volumio volumio[30893]: info: Plugin folders cleanup completed Apr 11 09:28:39 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:39 volumio volumio[30893]: info: ----- Core plugins startup ---- Apr 11 09:28:39 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:39 volumio volumio[30893]: info: Loading plugins from folder /volumio/app/plugins/ Apr 11 09:28:39 volumio volumio[30893]: info: Adding plugin upnp to MyMusic Plugins Apr 11 09:28:39 volumio volumio[30893]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 11 09:28:39 volumio volumio[30893]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 11 09:28:39 volumio volumio[30893]: info: Loading plugins from folder /data/plugins/ Apr 11 09:28:39 volumio volumio[30893]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 11 09:28:39 volumio volumio[30893]: info: Loading plugin "system"... Apr 11 09:28:39 volumio volumio[30893]: info: Loading plugin "appearance"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "network"... Apr 11 09:28:40 volumio volumio[30893]: info: Refreshing Cached IP Addresses Apr 11 09:28:40 volumio sudo[30921]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:28:40 volumio sudo[30921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:40 volumio sudo[30923]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:28:40 volumio sudo[30923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:40 volumio sudo[30921]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:40 volumio sudo[30923]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "services"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "alsa_controller"... Apr 11 09:28:40 volumio sudo[30932]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 09:28:40 volumio sudo[30932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:40 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "wizard"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "networkfs"... Apr 11 09:28:40 volumio volumio[30893]: info: Starting Udev Watcher for removable devices Apr 11 09:28:40 volumio volumio[30893]: info: Mounting Device 0ACB-A1DE Apr 11 09:28:40 volumio sudo[30960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:28:40 volumio sudo[30960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:40 volumio sudo[30960]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:40 volumio volumio[30893]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:28:40 volumio volumio[30893]: dmesg(1) may have more information after failed mount system call. Apr 11 09:28:40 volumio volumio[30893]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:28:40 volumio volumio[30893]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:28:40 volumio volumio[30893]: dmesg(1) may have more information after failed mount system call. Apr 11 09:28:40 volumio volumio[30893]: info: Ignoring mount for partition: boot Apr 11 09:28:40 volumio volumio[30893]: info: Ignoring mount for partition: volumio Apr 11 09:28:40 volumio volumio[30893]: info: Ignoring mount for partition: volumio_data Apr 11 09:28:40 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "volumio_command_line_client"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "upnp"... Apr 11 09:28:40 volumio volumio[30893]: info: [1775896120102] Starting Upmpd Daemon Apr 11 09:28:40 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "my_music"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "mpd"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "upnp_browser"... Apr 11 09:28:40 volumio volumio[30893]: info: Starting UPNP Browser Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "alarm-clock"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "airplay_emulation"... Apr 11 09:28:40 volumio volumio[30893]: info: Starting Shairport Sync Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "last_100"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "webradio"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "i2s_dacs"... Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "volumiodiscovery"... Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** For more information see Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:40 volumio volumio[30893]: *** WARNING *** For more information see Apr 11 09:28:40 volumio node[30893]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:40 volumio node[30893]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:40 volumio node[30893]: *** WARNING *** For more information see Apr 11 09:28:40 volumio node[30893]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:40 volumio node[30893]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:40 volumio node[30893]: *** WARNING *** For more information see Apr 11 09:28:40 volumio volumio[30893]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 09:28:40 volumio volumio[30893]: info: Discovery: Started advertising with name: Volumio Apr 11 09:28:40 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:40 volumio volumio[30893]: info: Loading plugin "spop"... Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "ytmusic"... Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "outputs"... Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "albumart"... Apr 11 09:28:41 volumio volumio[30893]: info: Plugin example_plugin is not enabled Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "inputs"... Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "updater_comm"... Apr 11 09:28:41 volumio volumio[30893]: info: Plugin mpdemulation is not enabled Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "rest_api"... Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "websocket"... Apr 11 09:28:41 volumio volumio[30893]: info: Starting Socket.io Server version 1.7.4 Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "podcast"... Apr 11 09:28:41 volumio volumio[30893]: info: ControllerPodcast::constructor Apr 11 09:28:41 volumio volumio[30893]: info: Loading plugin "rtlsdr_radio"... Apr 11 09:28:41 volumio volumio[30964]: Forking 3 albumart workers Apr 11 09:28:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 11 09:28:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:41 volumio go-librespot[30974]: go-librespot daemon starting... Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=debug msg="app state loaded" Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:28:41 volumio volumio[30893]: info: Loading i18n strings for locale en Apr 11 09:28:41 volumio volumio[30893]: Updating browse sources language Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::initPlayerControls Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: Express server listening on port 3000 Apr 11 09:28:41 volumio volumio[30893]: [Metrics] WebUI: 2s 296.15ms Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::resetVolumioState Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::getcurrentVolume Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:28:41 volumio volumio[30893]: info: Volumio Network Manager: Network status updated: 2 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: Reloading queue from file Apr 11 09:28:41 volumio volumio[30893]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::pushState Apr 11 09:28:41 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::updateTrackBlock Apr 11 09:28:41 volumio volumio[30893]: info: CorePlayQueue::getTrackBlock Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::setRepeat null single undefined Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::pushState Apr 11 09:28:41 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::setRandom true Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::pushState Apr 11 09:28:41 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:41 volumio volumio[30893]: info: Setting Device type: Raspberry PI Apr 11 09:28:41 volumio volumio[30893]: info: Completed loading Core Plugins Apr 11 09:28:41 volumio volumio[30893]: info: Preparing to generate the ALSA configuration file Apr 11 09:28:41 volumio volumio[30893]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 11 09:28:41 volumio volumio[30893]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 11 09:28:41 volumio volumio[30893]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 11 09:28:41 volumio volumio[30893]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:28:41 volumio volumio[30893]: info: CoreStateMachine::pushState Apr 11 09:28:41 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:41 volumio volumio[30893]: info: Asound.conf file unchanged, so no further update is needed Apr 11 09:28:41 volumio volumio[30893]: info: Output device has changed, restarting MPD Apr 11 09:28:41 volumio volumio[30893]: info: Output device has changed, restarting Shairport Sync Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:41 volumio sudo[31031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:28:41 volumio sudo[31031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:41 volumio sudo[31032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:28:41 volumio sudo[31032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:41 volumio sudo[31031]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:41 volumio volumio[30893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:41 volumio volumio[30893]: info: ___________ START PLUGINS ___________ Apr 11 09:28:41 volumio volumio[30893]: info: ControllerMpd::onStart: Initializing MPD Apr 11 09:28:41 volumio volumio[30893]: info: Creating MPD Configuration file Apr 11 09:28:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:28:41 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:28:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:28:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:28:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:28:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:41 volumio go-librespot[30986]: time="2026-04-11T09:28:41+01:00" level=info msg="zeroconf server listening on port 41751" Apr 11 09:28:41 volumio volumio[30893]: info: [1775896121835] CoreMusicLibrary::Adding element Media Servers Apr 11 09:28:41 volumio sudo[31048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:28:41 volumio sudo[31048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:41 volumio sudo[31042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:41 volumio sudo[31042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:41 volumio volumio[30893]: info: UPNP Browser: Client initialized successfully Apr 11 09:28:41 volumio sudo[31042]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:28:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:41 volumio volumio[30976]: Starting albumart workers Apr 11 09:28:41 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:28:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:28:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:28:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:28:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:28:41 volumio volumio[30893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:28:41 volumio volumio[30893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:41 volumio volumio[30893]: info: [1775896121893] CoreMusicLibrary::Adding element Last_100 Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:41 volumio volumio[30893]: info: [1775896121896] CoreMusicLibrary::Adding element Webradio Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:41 volumio volumio[30893]: info: Initializing BBC Radios Apr 11 09:28:41 volumio volumio[30975]: Starting albumart workers Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:41 volumio volumio[30893]: info: Creating Spotify config file Apr 11 09:28:41 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:41 volumio sudo[31057]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 09:28:41 volumio sudo[31057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 09:28:41 volumio sudo[31057]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio volumio[30977]: Starting albumart workers Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:42 volumio volumio[30893]: info: [1775896122069] CoreMusicLibrary::Adding element YouTube Music Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source YouTube Music Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:42 volumio volumio[30893]: info: [1775896122074] CoreMusicLibrary::Adding element Podcast Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source YouTube Music Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source Podcast Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Starting plugin Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 11 09:28:42 volumio volumio[30893]: info: Volumio Calling Home Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Database loaded at: 2026-04-11T08:28:42.144Z Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 11 09:28:42 volumio go-librespot[30986]: time="2026-04-11T09:28:42+01:00" level=debug msg="obtained new client token: AAAEHz5GFEry+suw1Q+zMdk1bOzej63sbv9WBj8/LS0Fw2DAdPO8XH/OAFz5WrgpG/HU8GosUzKUxmFZuizBYdtXFlBI4DDywbjUF9elp15CKyKlBDVdHzO5NjPccJFdfKVwkDKv6ZfV9n9tlUGP9+svQqlSd9JLWw+e/4rp+q+eoz199sYuA1A961Wbt0l2P6+T/T6RkJ2mNUdEs82XGVRrBVKmAFDP+s7dxgHWq0GLtWUw3VhraE0=" Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:42 volumio volumio[30893]: info: [1775896122197] CoreMusicLibrary::Adding element FM/DAB Radio Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source YouTube Music Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source Podcast Apr 11 09:28:42 volumio volumio[30893]: Cannot find translation for source FM/DAB Radio Apr 11 09:28:42 volumio volumio[30893]: info: [RTL-SDR Radio] Plugin started successfully Apr 11 09:28:42 volumio volumio[30893]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:28:42 volumio volumio[30893]: info: Discovery: Found device Volumio Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:42 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:42 volumio volumio[30893]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:28:42 volumio volumio[30893]: info: Discovery: Found device Volumio Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:42 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:42 volumio volumio[30893]: info: MPD Permissions set Apr 11 09:28:42 volumio volumio[30893]: info: MPD Permissions set Apr 11 09:28:42 volumio volumio[30893]: info: Spotify config file written Apr 11 09:28:42 volumio sudo[31092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 09:28:42 volumio sudo[31092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:42 volumio volumio[30893]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 11 09:28:42 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 11 09:28:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:42 volumio sudo[31092]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio go-librespot[31109]: go-librespot daemon starting... Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:42 volumio volumio[30893]: info: No need to fix Spotify hosts Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=debug msg="app state loaded" Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:28:42 volumio volumio[30893]: info: Starting Shairport Sync Apr 11 09:28:42 volumio volumio[30893]: info: Starting Shairport Sync Apr 11 09:28:42 volumio volumio[30893]: info: Starting Shairport Sync Apr 11 09:28:42 volumio sudo[31124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:42 volumio sudo[31124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:42 volumio sudo[31126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:42 volumio sudo[31128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:42 volumio sudo[31128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:42 volumio sudo[31126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:42 volumio volumio[30893]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:42 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 09:28:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 09:28:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:42 volumio systemd[1]: shairport-sync.service: Consumed 2.103s CPU time. Apr 11 09:28:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:42 volumio sudo[31128]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio sudo[31126]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio sudo[31124]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio volumio[30893]: info: Shairport-Sync Started Apr 11 09:28:42 volumio volumio[30893]: Error adding Membership: Error: addMembership EINVAL Apr 11 09:28:42 volumio volumio[30893]: info: Shairport-Sync Started Apr 11 09:28:42 volumio volumio[30893]: info: Shairport-Sync Started Apr 11 09:28:42 volumio volumio[30893]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 11 09:28:42 volumio mpd[31077]: 2026-04-11T09:28:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 09:28:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 09:28:42 volumio sudo[31032]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio sudo[31048]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:42 volumio volumio[30893]: error: updateQueue error: null Apr 11 09:28:42 volumio volumio[30893]: info: Completed starting Core Plugins Apr 11 09:28:42 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:42 volumio volumio[30893]: info: ----- MyVolumio plugins startup ---- Apr 11 09:28:42 volumio volumio[30893]: info: ------------------------------------------- Apr 11 09:28:42 volumio volumio[30893]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 09:28:42 volumio volumio[30893]: error: updateQueue error: null Apr 11 09:28:42 volumio volumio[30893]: info: MPD running with PID31077 Apr 11 09:28:42 volumio volumio[30893]: ,establishing connection Apr 11 09:28:42 volumio volumio[30893]: error: updateQueue error: null Apr 11 09:28:42 volumio volumio[30893]: info: Volumio called home Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:28:42 volumio go-librespot[31117]: time="2026-04-11T09:28:42+01:00" level=info msg="zeroconf server listening on port 40515" Apr 11 09:28:43 volumio go-librespot[31117]: time="2026-04-11T09:28:43+01:00" level=debug msg="obtained new client token: AABFvHHlkXCtHBCZltGbTnvsopEMFHi8EUmL9q8jgZqk3TbPffQZOSKaoP6y0xE9gjt3GxYIa1Vw6IK5XCsNuWGVnLLOWNwHS+euY7L2NeC4+Yk+WV9RG4L1wVo++drEOTzNIJKOJ7Nyn2/ZfM2DztoMofvgumIClzwY6LMbp/WN1OQjldauC54yO0e9YGClw5LF2KJuOn3pfHIkUST2cgNDN5cfa5RlJaquBs1133wXQ6Ptf4ehIJU=" Apr 11 09:28:43 volumio go-librespot[31117]: time="2026-04-11T09:28:43+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:28:43 volumio go-librespot[31117]: time="2026-04-11T09:28:43+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:43 volumio go-librespot[31117]: time="2026-04-11T09:28:43+01:00" level=debug msg="completed challenge" Apr 11 09:28:43 volumio volumio-remote-updater[945]: [2026-04-11 09:28:43] [connect] Successful connection Apr 11 09:28:43 volumio volumio-remote-updater[945]: [2026-04-11 09:28:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1775896123 101 Apr 11 09:28:43 volumio volumio[30893]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 11 09:28:43 volumio go-librespot[31117]: time="2026-04-11T09:28:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:43 volumio sudo[30932]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="completed challenge" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=debug msg="completed challenge" Apr 11 09:28:44 volumio go-librespot[31117]: time="2026-04-11T09:28:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:45 volumio volumio[30893]: info: go-librespot daemon successfully initialized Apr 11 09:28:45 volumio go-librespot[31117]: time="2026-04-11T09:28:45+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 11 09:28:45 volumio go-librespot[31117]: time="2026-04-11T09:28:45+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:45 volumio go-librespot[31117]: time="2026-04-11T09:28:45+01:00" level=debug msg="completed challenge" Apr 11 09:28:45 volumio go-librespot[31117]: time="2026-04-11T09:28:45+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:46 volumio go-librespot[31117]: time="2026-04-11T09:28:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 11 09:28:46 volumio go-librespot[31117]: time="2026-04-11T09:28:46+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:46 volumio go-librespot[31117]: time="2026-04-11T09:28:46+01:00" level=debug msg="completed challenge" Apr 11 09:28:46 volumio go-librespot[31117]: time="2026-04-11T09:28:46+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:47 volumio go-librespot[31117]: time="2026-04-11T09:28:47+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:28:47 volumio go-librespot[31117]: time="2026-04-11T09:28:47+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:47 volumio go-librespot[31117]: time="2026-04-11T09:28:47+01:00" level=debug msg="completed challenge" Apr 11 09:28:47 volumio go-librespot[31117]: time="2026-04-11T09:28:47+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:47 volumio go-librespot[31117]: time="2026-04-11T09:28:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:28:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:28:48 volumio volumio[30893]: info: Initializing connection to go-librespot Websocket Apr 11 09:28:48 volumio volumio[30893]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 09:28:50 volumio sudo[31171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:28:50 volumio sudo[31171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:50 volumio sudo[31173]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:28:50 volumio sudo[31171]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:50 volumio sudo[31173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:50 volumio sudo[31173]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:50 volumio sudo[31177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 09:28:50 volumio sudo[31177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:50 volumio sudo[31177]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:50 volumio volumio[30893]: info: Upmpdcli Daemon Started Apr 11 09:28:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 11 09:28:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:50 volumio go-librespot[31179]: go-librespot daemon starting... Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="app state loaded" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=info msg="zeroconf server listening on port 33469" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="obtained new client token: AACkVacFDy8MwwFdM8lSAlyngVcJe7HRCWezbW09rv+hq8C2j7JLyo6RoUJxzi+s4bGzyn7uxQjAOit67/M/xZ5l/eA/2Lx672alPam/3DLmoNUSJbO28Y8eW67DAbg6Y5D8AWKSBkAsW7dUIUgJohyCSyMB80ZIMnMFqecxJ3jPKIUNHcRRByngaK4ekxi+aYANVvoiPowhTDrcBNY6fHhVKQXT8JNjNbzEoWxnEDgXVnF+1MUls4AJtg==" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=debug msg="completed challenge" Apr 11 09:28:50 volumio go-librespot[31180]: time="2026-04-11T09:28:50+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 09:28:51 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:51 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:51 volumio volumio[30893]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 09:28:51 volumio volumio[30893]: info: MyVolumio login type: Token Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=debug msg="completed challenge" Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 09:28:51 volumio volumio[30893]: info: Streaming services startup Apr 11 09:28:51 volumio volumio[30893]: info: Starting Streaming Daemon Apr 11 09:28:51 volumio sudo[31191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:28:51 volumio sudo[31191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:51 volumio volumio[30893]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 09:28:51 volumio sudo[31191]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:51 volumio volumio[30893]: info: Initializing connection to go-librespot Websocket Apr 11 09:28:51 volumio volumio[30893]: error: Cannot start Volumio Streaming Daemon Apr 11 09:28:51 volumio volumio[30893]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:28:51 volumio volumio[30893]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:28:51 volumio go-librespot[31180]: time="2026-04-11T09:28:51+01:00" level=debug msg="new websocket client" Apr 11 09:28:51 volumio volumio[30893]: info: Connection to go-librespot Websocket established Apr 11 09:28:52 volumio volumio[30893]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 09:28:52 volumio go-librespot[31180]: time="2026-04-11T09:28:52+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 11 09:28:52 volumio go-librespot[31180]: time="2026-04-11T09:28:52+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:52 volumio go-librespot[31180]: time="2026-04-11T09:28:52+01:00" level=debug msg="completed challenge" Apr 11 09:28:52 volumio volumio[30893]: info: MyVolumio token set successfully Apr 11 09:28:52 volumio volumio[30893]: info: MYVOLUMIO: Adding device Apr 11 09:28:52 volumio volumio[30893]: info: MYVOLUMIO: Evaluating Server Apr 11 09:28:52 volumio go-librespot[31180]: time="2026-04-11T09:28:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:52 volumio volumio[30893]: info: MyVolumio status changed Apr 11 09:28:52 volumio volumio[30893]: info: Streaming services startup Apr 11 09:28:52 volumio volumio[30893]: info: Starting Streaming Daemon Apr 11 09:28:52 volumio volumio[30893]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 09:28:52 volumio volumio[30893]: info: Removing audio output: Apr 11 09:28:52 volumio volumio[30893]: info: Stoppping Tunnel 1 Apr 11 09:28:52 volumio sudo[31218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:28:52 volumio sudo[31218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:52 volumio sudo[31220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 11 09:28:52 volumio sudo[31220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio sudo[31218]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:52 volumio volumio[30893]: error: Cannot start Volumio Streaming Daemon Apr 11 09:28:52 volumio volumio[30893]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:28:52 volumio volumio[30893]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:28:52 volumio sudo[31220]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:52 volumio volumio[30893]: info: Remote SSH Stopped Apr 11 09:28:52 volumio volumio[30893]: info: Setting Geolocation for MyVolumio to eu3 Apr 11 09:28:52 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:52 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:52 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:53 volumio go-librespot[31180]: time="2026-04-11T09:28:53+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Apr 11 09:28:53 volumio volumio[30893]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 11 09:28:53 volumio go-librespot[31180]: time="2026-04-11T09:28:53+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:28:53 volumio go-librespot[31180]: time="2026-04-11T09:28:53+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:53 volumio go-librespot[31180]: time="2026-04-11T09:28:53+01:00" level=debug msg="completed challenge" Apr 11 09:28:53 volumio go-librespot[31180]: time="2026-04-11T09:28:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:53 volumio volumio[30893]: info: Updating MyVolumio device info Apr 11 09:28:53 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:53 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:53 volumio volumio[30893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:54 volumio volumio[30893]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="completed challenge" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:54 volumio volumio[30893]: info: Getting Spotify volume Apr 11 09:28:54 volumio volumio[30893]: 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 11 09:28:54 volumio volumio[30893]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:54 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:54 volumio volumio[30893]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 11 09:28:54 volumio volumio[30893]: SPOTIFY: SPOTIFY VOLUME undefined Apr 11 09:28:54 volumio volumio[30893]: SPOTIFY: VOLUMIO VOLUME 0 Apr 11 09:28:54 volumio volumio[30893]: info: Aligning Spotify Volume to Volumio Volume Apr 11 09:28:54 volumio volumio[30893]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:54 volumio volumio[30893]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:54 volumio volumio[30893]: info: Setting Spotify Volume from Volumio: 0 Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=debug msg="completed challenge" Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:54 volumio go-librespot[31180]: time="2026-04-11T09:28:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:28:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:28:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:28:54 volumio volumio[30893]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:28:54 volumio volumio[30893]: Error: socket hang up Apr 11 09:28:54 volumio volumio[30893]: at connResetException (node:internal/errors:720:14) Apr 11 09:28:54 volumio volumio[30893]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 11 09:28:54 volumio volumio[30893]: at Socket.emit (node:events:526:35) Apr 11 09:28:54 volumio volumio[30893]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 11 09:28:54 volumio volumio[30893]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 11 09:28:54 volumio volumio[30893]: code: 'ECONNRESET', Apr 11 09:28:54 volumio volumio[30893]: response: undefined Apr 11 09:28:54 volumio volumio[30893]: } Apr 11 09:28:54 volumio volumio[30893]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:28:55 volumio sudo[31237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 09:27' Apr 11 09:28:55 volumio sudo[31237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:55 volumio sudo[31237]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:55 volumio volumio-remote-updater[945]: [2026-04-11 09:28:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 11 09:28:55 volumio volumio-remote-updater[945]: [2026-04-11 09:28:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 11 09:28:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:28:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 11 09:28:55 volumio systemd[1]: volumio.service: Consumed 8.898s CPU time. Apr 11 09:28:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:28:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:28:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 114276. Apr 11 09:28:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:28:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 11 09:28:55 volumio systemd[1]: volumio.service: Consumed 8.898s CPU time. Apr 11 09:28:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 11 09:28:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:28:55 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:55 volumio volumio[31258]: info: ----- Volumio3 ---- Apr 11 09:28:55 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:55 volumio volumio[31258]: info: ----- System startup ---- Apr 11 09:28:55 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:56 volumio volumio[31258]: info: MYVOLUMIO Environment detected Apr 11 09:28:56 volumio volumio[31258]: info: Plugin folders cleanup Apr 11 09:28:56 volumio volumio[31258]: info: Scanning into folder /volumio/app/plugins/ Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category audio_interface Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category miscellanea Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category music_service Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category plugins.json Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category system_controller Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category user_interface Apr 11 09:28:56 volumio volumio[31258]: info: Scanning into folder /data/plugins/ Apr 11 09:28:56 volumio volumio[31258]: info: Scanning category music_service Apr 11 09:28:56 volumio volumio[31258]: info: Plugin folders cleanup completed Apr 11 09:28:56 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:56 volumio volumio[31258]: info: ----- Core plugins startup ---- Apr 11 09:28:56 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugins from folder /volumio/app/plugins/ Apr 11 09:28:56 volumio volumio[31258]: info: Adding plugin upnp to MyMusic Plugins Apr 11 09:28:56 volumio volumio[31258]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 11 09:28:56 volumio volumio[31258]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugins from folder /data/plugins/ Apr 11 09:28:56 volumio volumio[31258]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "system"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "appearance"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "network"... Apr 11 09:28:56 volumio volumio[31258]: info: Refreshing Cached IP Addresses Apr 11 09:28:56 volumio sudo[31286]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:28:56 volumio sudo[31286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:56 volumio sudo[31288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:28:56 volumio sudo[31288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:56 volumio sudo[31286]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:56 volumio sudo[31288]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "services"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "alsa_controller"... Apr 11 09:28:56 volumio sudo[31297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 09:28:56 volumio sudo[31297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:56 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "wizard"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "networkfs"... Apr 11 09:28:56 volumio volumio[31258]: info: Starting Udev Watcher for removable devices Apr 11 09:28:56 volumio volumio[31258]: info: Mounting Device 0ACB-A1DE Apr 11 09:28:56 volumio sudo[31325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:28:56 volumio sudo[31325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:56 volumio sudo[31325]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:56 volumio volumio[31258]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:28:56 volumio volumio[31258]: dmesg(1) may have more information after failed mount system call. Apr 11 09:28:56 volumio volumio[31258]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:28:56 volumio volumio[31258]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:28:56 volumio volumio[31258]: dmesg(1) may have more information after failed mount system call. Apr 11 09:28:56 volumio volumio[31258]: info: Ignoring mount for partition: boot Apr 11 09:28:56 volumio volumio[31258]: info: Ignoring mount for partition: volumio Apr 11 09:28:56 volumio volumio[31258]: info: Ignoring mount for partition: volumio_data Apr 11 09:28:56 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "volumio_command_line_client"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "upnp"... Apr 11 09:28:56 volumio volumio[31258]: info: [1775896136624] Starting Upmpd Daemon Apr 11 09:28:56 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "my_music"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "mpd"... Apr 11 09:28:56 volumio volumio[31258]: info: Loading plugin "upnp_browser"... Apr 11 09:28:57 volumio volumio[31258]: info: Starting UPNP Browser Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "alarm-clock"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "airplay_emulation"... Apr 11 09:28:57 volumio volumio[31258]: info: Starting Shairport Sync Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "last_100"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "webradio"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "i2s_dacs"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "volumiodiscovery"... Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** For more information see Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:57 volumio volumio[31258]: *** WARNING *** For more information see Apr 11 09:28:57 volumio node[31258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:57 volumio node[31258]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:57 volumio node[31258]: *** WARNING *** For more information see Apr 11 09:28:57 volumio node[31258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:28:57 volumio node[31258]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:28:57 volumio node[31258]: *** WARNING *** For more information see Apr 11 09:28:57 volumio volumio[31258]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 09:28:57 volumio volumio[31258]: info: Discovery: Started advertising with name: Volumio Apr 11 09:28:57 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "spop"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "ytmusic"... Apr 11 09:28:57 volumio kernel: hwmon hwmon3: Undervoltage detected! Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "outputs"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "albumart"... Apr 11 09:28:57 volumio volumio[31258]: info: Plugin example_plugin is not enabled Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "inputs"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "updater_comm"... Apr 11 09:28:57 volumio volumio[31258]: info: Plugin mpdemulation is not enabled Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "rest_api"... Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "websocket"... Apr 11 09:28:57 volumio volumio[31258]: info: Starting Socket.io Server version 1.7.4 Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "podcast"... Apr 11 09:28:57 volumio volumio[31258]: info: ControllerPodcast::constructor Apr 11 09:28:57 volumio volumio[31258]: info: Loading plugin "rtlsdr_radio"... Apr 11 09:28:57 volumio volumio[31331]: Forking 3 albumart workers Apr 11 09:28:58 volumio volumio[31258]: info: Loading i18n strings for locale en Apr 11 09:28:58 volumio volumio[31258]: Updating browse sources language Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 11 09:28:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:58 volumio go-librespot[31371]: go-librespot daemon starting... Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::initPlayerControls Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=debug msg="app state loaded" Apr 11 09:28:58 volumio volumio[31258]: Express server listening on port 3000 Apr 11 09:28:58 volumio volumio[31258]: [Metrics] WebUI: 2s 359.58ms Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::resetVolumioState Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::getcurrentVolume Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:28:58 volumio volumio[31258]: info: Volumio Network Manager: Network status updated: 2 Apr 11 09:28:58 volumio volumio[31258]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::pushState Apr 11 09:28:58 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::updateTrackBlock Apr 11 09:28:58 volumio volumio[31258]: info: CorePlayQueue::getTrackBlock Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: Reloading queue from file Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::setRepeat null single undefined Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::pushState Apr 11 09:28:58 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::setRandom true Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::pushState Apr 11 09:28:58 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:58 volumio volumio[31258]: info: Setting Device type: Raspberry PI Apr 11 09:28:58 volumio volumio[31258]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 11 09:28:58 volumio volumio[31258]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 11 09:28:58 volumio volumio[31258]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 11 09:28:58 volumio volumio[31258]: info: Completed loading Core Plugins Apr 11 09:28:58 volumio volumio[31258]: info: Preparing to generate the ALSA configuration file Apr 11 09:28:58 volumio volumio[31258]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:28:58 volumio volumio[31258]: info: CoreStateMachine::pushState Apr 11 09:28:58 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioPushState Apr 11 09:28:58 volumio volumio[31258]: info: Asound.conf file unchanged, so no further update is needed Apr 11 09:28:58 volumio volumio[31258]: info: Output device has changed, restarting MPD Apr 11 09:28:58 volumio volumio[31258]: info: Output device has changed, restarting Shairport Sync Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio sudo[31395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:28:58 volumio sudo[31395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio sudo[31399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:28:58 volumio sudo[31399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio volumio[31258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:58 volumio volumio[31258]: info: ___________ START PLUGINS ___________ Apr 11 09:28:58 volumio sudo[31395]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:58 volumio volumio[31258]: info: ControllerMpd::onStart: Initializing MPD Apr 11 09:28:58 volumio volumio[31341]: Starting albumart workers Apr 11 09:28:58 volumio volumio[31258]: info: Creating MPD Configuration file Apr 11 09:28:58 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138408] CoreMusicLibrary::Adding element Media Servers Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio sudo[31405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:28:58 volumio sudo[31405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio volumio[31258]: info: UPNP Browser: Client initialized successfully Apr 11 09:28:58 volumio sudo[31405]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:58 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:28:58 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:28:58 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:28:58 volumio sudo[31407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:28:58 volumio volumio[31343]: Starting albumart workers Apr 11 09:28:58 volumio sudo[31407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:28:58 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:28:58 volumio volumio[31258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138473] CoreMusicLibrary::Adding element Last_100 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138474] CoreMusicLibrary::Adding element Webradio Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:58 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:28:58 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:28:58 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:28:58 volumio volumio[31258]: info: Initializing BBC Radios Apr 11 09:28:58 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:28:58 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:28:58 volumio volumio[31342]: Starting albumart workers Apr 11 09:28:58 volumio sudo[31423]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 09:28:58 volumio sudo[31423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:28:58 volumio sudo[31423]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: Creating Spotify config file Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:28:58 volumio go-librespot[31372]: time="2026-04-11T09:28:58+01:00" level=info msg="zeroconf server listening on port 38237" Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138769] CoreMusicLibrary::Adding element YouTube Music Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source YouTube Music Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138772] CoreMusicLibrary::Adding element Podcast Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source YouTube Music Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source Podcast Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Starting plugin Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 11 09:28:58 volumio volumio[31258]: info: Volumio Calling Home Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Database loaded at: 2026-04-11T08:28:58.816Z Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:28:58 volumio volumio[31258]: info: [1775896138849] CoreMusicLibrary::Adding element FM/DAB Radio Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source YouTube Music Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source Podcast Apr 11 09:28:58 volumio volumio[31258]: Cannot find translation for source FM/DAB Radio Apr 11 09:28:58 volumio volumio[31258]: info: [RTL-SDR Radio] Plugin started successfully Apr 11 09:28:58 volumio volumio[31258]: info: MPD Permissions set Apr 11 09:28:58 volumio volumio[31258]: info: MPD Permissions set Apr 11 09:28:58 volumio volumio[31258]: info: Spotify config file written Apr 11 09:28:58 volumio sudo[31466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 09:28:58 volumio sudo[31466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio volumio[31258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 11 09:28:58 volumio systemd[1]: go-librespot-daemon.service: Killing process 31377 (go-librespot) with signal SIGKILL. Apr 11 09:28:58 volumio systemd[1]: go-librespot-daemon.service: Killing process 31431 (go-librespot) with signal SIGKILL. Apr 11 09:28:58 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:28:58 volumio volumio[31258]: info: No need to fix Spotify hosts Apr 11 09:28:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:28:58 volumio go-librespot[31473]: go-librespot daemon starting... Apr 11 09:28:58 volumio sudo[31466]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:58 volumio volumio[31258]: info: Starting Shairport Sync Apr 11 09:28:58 volumio go-librespot[31479]: time="2026-04-11T09:28:58+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:28:58 volumio go-librespot[31479]: time="2026-04-11T09:28:58+01:00" level=debug msg="app state loaded" Apr 11 09:28:58 volumio go-librespot[31479]: time="2026-04-11T09:28:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:28:58 volumio volumio[31258]: info: Starting Shairport Sync Apr 11 09:28:58 volumio sudo[31486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:58 volumio sudo[31486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio volumio[31258]: info: Starting Shairport Sync Apr 11 09:28:58 volumio sudo[31489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:58 volumio sudo[31489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio sudo[31491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:28:58 volumio sudo[31491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:28:58 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 09:28:58 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 09:28:58 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:58 volumio systemd[1]: shairport-sync.service: Consumed 1.546s CPU time. Apr 11 09:28:59 volumio volumio[31258]: info: Volumio called home Apr 11 09:28:59 volumio volumio[31258]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:28:59 volumio volumio[31258]: info: Discovery: Found device Volumio Apr 11 09:28:59 volumio volumio[31258]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:59 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:59 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:59 volumio sudo[31486]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:59 volumio volumio[31258]: info: Shairport-Sync Started Apr 11 09:28:59 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 09:28:59 volumio volumio[31258]: Error adding Membership: Error: addMembership EINVAL Apr 11 09:28:59 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 09:28:59 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:59 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:28:59 volumio sudo[31491]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:59 volumio sudo[31489]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:59 volumio volumio[31258]: info: Shairport-Sync Started Apr 11 09:28:59 volumio volumio[31258]: info: Shairport-Sync Started Apr 11 09:28:59 volumio volumio[31258]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:59 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:59 volumio volumio[31258]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:28:59 volumio volumio[31258]: info: Discovery: Found device Volumio Apr 11 09:28:59 volumio volumio[31258]: info: CoreCommandRouter::volumioGetState Apr 11 09:28:59 volumio volumio[31258]: info: CorePlayQueue::getTrack 0 Apr 11 09:28:59 volumio mpd[31437]: 2026-04-11T09:28:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 09:28:59 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 09:28:59 volumio sudo[31399]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:59 volumio sudo[31407]: pam_unix(sudo:session): session closed for user root Apr 11 09:28:59 volumio volumio[31258]: info: Completed starting Core Plugins Apr 11 09:28:59 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:59 volumio volumio[31258]: info: ----- MyVolumio plugins startup ---- Apr 11 09:28:59 volumio volumio[31258]: info: ------------------------------------------- Apr 11 09:28:59 volumio volumio[31258]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 09:28:59 volumio volumio[31258]: error: MPD error: The expression evaluated to a falsy value: Apr 11 09:28:59 volumio volumio[31258]: assert.ok(self.idling) Apr 11 09:28:59 volumio volumio[31258]: error: The expression evaluated to a falsy value: Apr 11 09:28:59 volumio volumio[31258]: assert.ok(self.idling) Apr 11 09:28:59 volumio volumio[31258]: info: MPD running with PID31437 Apr 11 09:28:59 volumio volumio[31258]: ,establishing connection Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 11 09:28:59 volumio volumio[31258]: error: updateQueue error: null Apr 11 09:28:59 volumio volumio[31258]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 11 09:28:59 volumio volumio[31258]: error: updateQueue error: null Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=info msg="zeroconf server listening on port 45255" Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="obtained new client token: AAD35GZhxWTBQsotoxWy+m8KWO+uTXXDvBgJFye6SyCM2VtB7ulswtt/U/EQR3LKZebeUebK4M09Rfl3BzMUm8jhXlu7e7kK1kUzhLPWauzA2lylAm9sAo2bywZgrFRqy6fXCt/xxw884iFdMU0YUSpfvUgTeQeKjRkPoVv7J9zf6q7KbllF9d9erKlsde2ge2TQ587RparvtNovPidjfGCU6vtfqPEDoz+H0WHzJjWWB+cVkECCfEz0Hw==" Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:28:59 volumio kernel: hwmon hwmon3: Voltage normalised Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="completed keyexchange" Apr 11 09:28:59 volumio go-librespot[31479]: time="2026-04-11T09:28:59+01:00" level=debug msg="completed challenge" Apr 11 09:29:00 volumio go-librespot[31479]: time="2026-04-11T09:29:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:00 volumio volumio-remote-updater[945]: [2026-04-11 09:29:00] [connect] Successful connection Apr 11 09:29:00 volumio volumio-remote-updater[945]: [2026-04-11 09:29:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1775896140 101 Apr 11 09:29:00 volumio volumio[31258]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 11 09:29:00 volumio sudo[31297]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:00 volumio go-librespot[31479]: time="2026-04-11T09:29:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:00 volumio go-librespot[31479]: time="2026-04-11T09:29:00+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:00 volumio go-librespot[31479]: time="2026-04-11T09:29:00+01:00" level=debug msg="completed challenge" Apr 11 09:29:00 volumio go-librespot[31479]: time="2026-04-11T09:29:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="completed challenge" Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 11 09:29:01 volumio volumio[31258]: info: go-librespot daemon successfully initialized Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:01 volumio go-librespot[31479]: time="2026-04-11T09:29:01+01:00" level=debug msg="completed challenge" Apr 11 09:29:02 volumio go-librespot[31479]: time="2026-04-11T09:29:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:02 volumio go-librespot[31479]: time="2026-04-11T09:29:02+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 11 09:29:02 volumio go-librespot[31479]: time="2026-04-11T09:29:02+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:02 volumio go-librespot[31479]: time="2026-04-11T09:29:02+01:00" level=debug msg="completed challenge" Apr 11 09:29:02 volumio go-librespot[31479]: time="2026-04-11T09:29:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:03 volumio go-librespot[31479]: time="2026-04-11T09:29:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 11 09:29:03 volumio go-librespot[31479]: time="2026-04-11T09:29:03+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:03 volumio go-librespot[31479]: time="2026-04-11T09:29:03+01:00" level=debug msg="completed challenge" Apr 11 09:29:03 volumio go-librespot[31479]: time="2026-04-11T09:29:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:03 volumio go-librespot[31479]: time="2026-04-11T09:29:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:04 volumio volumio[31258]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:04 volumio volumio[31258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 09:29:06 volumio sudo[31535]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:29:06 volumio sudo[31535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:06 volumio sudo[31537]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:29:06 volumio sudo[31537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:06 volumio sudo[31535]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:06 volumio sudo[31537]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:06 volumio sudo[31539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 09:29:06 volumio sudo[31539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 11 09:29:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:06 volumio go-librespot[31543]: go-librespot daemon starting... Apr 11 09:29:06 volumio sudo[31539]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:06 volumio volumio[31258]: info: Upmpdcli Daemon Started Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="app state loaded" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=info msg="zeroconf server listening on port 42053" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="obtained new client token: AADl4e/27GBRcx7XpAuq/7M6WLm9uX7yW3WvQIs3mkjP2hTHK5imvU8o/YoJ+87oYGR0xVrtdkrBkZ4HECIPaPQGc/8BCFwhfSupe+LV1QiMe3JbE7JYmjvF8EOQJs+YQ09EyE3dtcP5zFCh6s0D61/eb4wAH9wMeBO2M9QvZAqiEMSlOGU50T4AukjmDOlvbwXZ5ueEl2M6O/2rlOSnji/8WawJZps5POBq8NCCNXhoRLSIFtrHyo4BQg==" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:06 volumio go-librespot[31544]: time="2026-04-11T09:29:06+01:00" level=debug msg="completed challenge" Apr 11 09:29:07 volumio go-librespot[31544]: time="2026-04-11T09:29:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:07 volumio go-librespot[31544]: time="2026-04-11T09:29:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:07 volumio go-librespot[31544]: time="2026-04-11T09:29:07+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:07 volumio go-librespot[31544]: time="2026-04-11T09:29:07+01:00" level=debug msg="completed challenge" Apr 11 09:29:07 volumio go-librespot[31544]: time="2026-04-11T09:29:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 09:29:07 volumio volumio[31258]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 09:29:07 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:07 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:07 volumio volumio[31258]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 09:29:08 volumio volumio[31258]: info: MyVolumio login type: Token Apr 11 09:29:08 volumio volumio[31258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 09:29:08 volumio volumio[31258]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 11 09:29:08 volumio volumio[31258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 09:29:08 volumio volumio[31258]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 09:29:08 volumio volumio[31258]: info: Streaming services startup Apr 11 09:29:08 volumio volumio[31258]: info: Starting Streaming Daemon Apr 11 09:29:08 volumio sudo[31554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:08 volumio sudo[31554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:08 volumio volumio[31258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 09:29:08 volumio sudo[31554]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:08 volumio volumio[31258]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:08 volumio volumio[31258]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:08 volumio volumio[31258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:08 volumio volumio[31258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=debug msg="new websocket client" Apr 11 09:29:08 volumio volumio[31258]: info: Connection to go-librespot Websocket established Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=debug msg="completed challenge" Apr 11 09:29:08 volumio go-librespot[31544]: time="2026-04-11T09:29:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:08 volumio volumio[31258]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 09:29:09 volumio volumio[31258]: info: MyVolumio token set successfully Apr 11 09:29:09 volumio volumio[31258]: info: MYVOLUMIO: Adding device Apr 11 09:29:09 volumio volumio[31258]: info: MYVOLUMIO: Evaluating Server Apr 11 09:29:09 volumio go-librespot[31544]: time="2026-04-11T09:29:09+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 11 09:29:09 volumio go-librespot[31544]: time="2026-04-11T09:29:09+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:09 volumio go-librespot[31544]: time="2026-04-11T09:29:09+01:00" level=debug msg="completed challenge" Apr 11 09:29:09 volumio volumio[31258]: info: MyVolumio status changed Apr 11 09:29:09 volumio volumio[31258]: info: Streaming services startup Apr 11 09:29:09 volumio volumio[31258]: info: Starting Streaming Daemon Apr 11 09:29:09 volumio volumio[31258]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 09:29:09 volumio volumio[31258]: info: Removing audio output: Apr 11 09:29:09 volumio volumio[31258]: info: Stoppping Tunnel 1 Apr 11 09:29:09 volumio sudo[31582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:09 volumio sudo[31582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:09 volumio sudo[31584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 11 09:29:09 volumio sudo[31584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio sudo[31582]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:09 volumio volumio[31258]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:09 volumio volumio[31258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:09 volumio volumio[31258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:09 volumio sudo[31584]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:09 volumio volumio[31258]: info: Remote SSH Stopped Apr 11 09:29:09 volumio go-librespot[31544]: time="2026-04-11T09:29:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:09 volumio volumio[31258]: info: Setting Geolocation for MyVolumio to eu3 Apr 11 09:29:09 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:09 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:09 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:09 volumio volumio[31258]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 11 09:29:10 volumio go-librespot[31544]: time="2026-04-11T09:29:10+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:29:10 volumio go-librespot[31544]: time="2026-04-11T09:29:10+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:10 volumio go-librespot[31544]: time="2026-04-11T09:29:10+01:00" level=debug msg="completed challenge" Apr 11 09:29:10 volumio volumio[31258]: info: Updating MyVolumio device info Apr 11 09:29:10 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:10 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:10 volumio volumio[31258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:10 volumio go-librespot[31544]: time="2026-04-11T09:29:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:10 volumio volumio[31258]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 11 09:29:11 volumio go-librespot[31544]: time="2026-04-11T09:29:11+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:11 volumio go-librespot[31544]: time="2026-04-11T09:29:11+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:11 volumio go-librespot[31544]: time="2026-04-11T09:29:11+01:00" level=debug msg="completed challenge" Apr 11 09:29:11 volumio go-librespot[31544]: time="2026-04-11T09:29:11+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:11 volumio go-librespot[31544]: time="2026-04-11T09:29:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:11 volumio volumio[31258]: info: Connection to go-librespot Websocket closed Apr 11 09:29:11 volumio volumio[31258]: info: Getting Spotify volume Apr 11 09:29:11 volumio volumio[31258]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:11 volumio volumio[31258]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 09:29:11 volumio volumio[31258]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 11 09:29:11 volumio volumio[31258]: errno: -111, Apr 11 09:29:11 volumio volumio[31258]: code: 'ECONNREFUSED', Apr 11 09:29:11 volumio volumio[31258]: syscall: 'connect', Apr 11 09:29:11 volumio volumio[31258]: address: '127.0.0.1', Apr 11 09:29:11 volumio volumio[31258]: port: 9879, Apr 11 09:29:11 volumio volumio[31258]: response: undefined Apr 11 09:29:11 volumio volumio[31258]: } Apr 11 09:29:11 volumio volumio[31258]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:11 volumio sudo[31601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 09:28' Apr 11 09:29:11 volumio sudo[31601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:11 volumio sudo[31601]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:11 volumio volumio-remote-updater[945]: [2026-04-11 09:29:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 11 09:29:11 volumio volumio-remote-updater[945]: [2026-04-11 09:29:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 11 09:29:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 11 09:29:11 volumio systemd[1]: volumio.service: Consumed 9.001s CPU time. Apr 11 09:29:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:29:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:29:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 114277. Apr 11 09:29:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:29:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 11 09:29:12 volumio systemd[1]: volumio.service: Consumed 9.001s CPU time. Apr 11 09:29:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 11 09:29:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:29:12 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:12 volumio volumio[31616]: info: ----- Volumio3 ---- Apr 11 09:29:12 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:12 volumio volumio[31616]: info: ----- System startup ---- Apr 11 09:29:12 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:12 volumio volumio[31616]: info: MYVOLUMIO Environment detected Apr 11 09:29:12 volumio volumio[31616]: info: Plugin folders cleanup Apr 11 09:29:12 volumio volumio[31616]: info: Scanning into folder /volumio/app/plugins/ Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category audio_interface Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category miscellanea Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category music_service Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category plugins.json Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category system_controller Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category user_interface Apr 11 09:29:12 volumio volumio[31616]: info: Scanning into folder /data/plugins/ Apr 11 09:29:12 volumio volumio[31616]: info: Scanning category music_service Apr 11 09:29:12 volumio volumio[31616]: info: Plugin folders cleanup completed Apr 11 09:29:12 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:12 volumio volumio[31616]: info: ----- Core plugins startup ---- Apr 11 09:29:12 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:12 volumio volumio[31616]: info: Loading plugins from folder /volumio/app/plugins/ Apr 11 09:29:12 volumio volumio[31616]: info: Adding plugin upnp to MyMusic Plugins Apr 11 09:29:12 volumio volumio[31616]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 11 09:29:12 volumio volumio[31616]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 11 09:29:12 volumio volumio[31616]: info: Loading plugins from folder /data/plugins/ Apr 11 09:29:12 volumio volumio[31616]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 11 09:29:12 volumio volumio[31616]: info: Loading plugin "system"... Apr 11 09:29:12 volumio volumio[31616]: info: Loading plugin "appearance"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "network"... Apr 11 09:29:13 volumio volumio[31616]: info: Refreshing Cached IP Addresses Apr 11 09:29:13 volumio sudo[31644]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:29:13 volumio sudo[31644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:13 volumio sudo[31646]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:29:13 volumio sudo[31646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:13 volumio sudo[31644]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:13 volumio sudo[31646]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "services"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "alsa_controller"... Apr 11 09:29:13 volumio sudo[31655]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 09:29:13 volumio sudo[31655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:13 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "wizard"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "networkfs"... Apr 11 09:29:13 volumio volumio[31616]: info: Starting Udev Watcher for removable devices Apr 11 09:29:13 volumio volumio[31616]: info: Mounting Device 0ACB-A1DE Apr 11 09:29:13 volumio sudo[31683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:29:13 volumio sudo[31683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:13 volumio sudo[31683]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:13 volumio volumio[31616]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:29:13 volumio volumio[31616]: dmesg(1) may have more information after failed mount system call. Apr 11 09:29:13 volumio volumio[31616]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:29:13 volumio volumio[31616]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:29:13 volumio volumio[31616]: dmesg(1) may have more information after failed mount system call. Apr 11 09:29:13 volumio volumio[31616]: info: Ignoring mount for partition: boot Apr 11 09:29:13 volumio volumio[31616]: info: Ignoring mount for partition: volumio Apr 11 09:29:13 volumio volumio[31616]: info: Ignoring mount for partition: volumio_data Apr 11 09:29:13 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "volumio_command_line_client"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "upnp"... Apr 11 09:29:13 volumio volumio[31616]: info: [1775896153346] Starting Upmpd Daemon Apr 11 09:29:13 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "my_music"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "mpd"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "upnp_browser"... Apr 11 09:29:13 volumio volumio[31616]: info: Starting UPNP Browser Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "alarm-clock"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "airplay_emulation"... Apr 11 09:29:13 volumio volumio[31616]: info: Starting Shairport Sync Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "last_100"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "webradio"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "i2s_dacs"... Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "volumiodiscovery"... Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** For more information see Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:13 volumio volumio[31616]: *** WARNING *** For more information see Apr 11 09:29:13 volumio node[31616]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:13 volumio node[31616]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:13 volumio node[31616]: *** WARNING *** For more information see Apr 11 09:29:13 volumio node[31616]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:13 volumio node[31616]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:13 volumio node[31616]: *** WARNING *** For more information see Apr 11 09:29:13 volumio volumio[31616]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 09:29:13 volumio volumio[31616]: info: Discovery: Started advertising with name: Volumio Apr 11 09:29:13 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:13 volumio volumio[31616]: info: Loading plugin "spop"... Apr 11 09:29:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 11 09:29:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:14 volumio go-librespot[31687]: go-librespot daemon starting... Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=debug msg="app state loaded" Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "ytmusic"... Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "outputs"... Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "albumart"... Apr 11 09:29:14 volumio volumio[31616]: info: Plugin example_plugin is not enabled Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "inputs"... Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "updater_comm"... Apr 11 09:29:14 volumio volumio[31616]: info: Plugin mpdemulation is not enabled Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "rest_api"... Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "websocket"... Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:14 volumio volumio[31616]: info: Starting Socket.io Server version 1.7.4 Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "podcast"... Apr 11 09:29:14 volumio go-librespot[31688]: time="2026-04-11T09:29:14+01:00" level=info msg="zeroconf server listening on port 36125" Apr 11 09:29:14 volumio volumio[31616]: info: ControllerPodcast::constructor Apr 11 09:29:14 volumio volumio[31616]: info: Loading plugin "rtlsdr_radio"... Apr 11 09:29:14 volumio volumio[31695]: Forking 3 albumart workers Apr 11 09:29:14 volumio volumio[31616]: info: Loading i18n strings for locale en Apr 11 09:29:14 volumio volumio[31616]: Updating browse sources language Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::initPlayerControls Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: Express server listening on port 3000 Apr 11 09:29:14 volumio volumio[31616]: [Metrics] WebUI: 2s 320.63ms Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::resetVolumioState Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::getcurrentVolume Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:29:14 volumio volumio[31616]: info: Volumio Network Manager: Network status updated: 2 Apr 11 09:29:14 volumio volumio[31616]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::pushState Apr 11 09:29:14 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::updateTrackBlock Apr 11 09:29:14 volumio volumio[31616]: info: CorePlayQueue::getTrackBlock Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:14 volumio volumio[31616]: info: Reloading queue from file Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::setRepeat null single undefined Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::pushState Apr 11 09:29:14 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::setRandom true Apr 11 09:29:14 volumio volumio[31616]: info: CoreStateMachine::pushState Apr 11 09:29:14 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:29:14 volumio volumio[31616]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:14 volumio volumio[31616]: info: Setting Device type: Raspberry PI Apr 11 09:29:14 volumio volumio[31616]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 11 09:29:14 volumio volumio[31616]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 11 09:29:15 volumio volumio[31616]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 11 09:29:15 volumio volumio[31616]: info: Completed loading Core Plugins Apr 11 09:29:15 volumio volumio[31616]: info: Preparing to generate the ALSA configuration file Apr 11 09:29:15 volumio volumio[31707]: Starting albumart workers Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=debug msg="obtained new client token: AAAfyBQMnTUMIH2DypgGHTUBjCM1+Nz5NPl5cpsGUHgtlTTG8kVnx6o5FA+rvb9gEZ/qlsT6ZOAwgE2R2qPenvVIMI7ADv9MGLZ7csPz6QJmDp4LgOfyU2TjHYXCQKFD/jEvKpF65CUUtesAkjOHP1LynRsjdvz129k150/JrnnE+BV0lGAbl1ERq8fHQaM7GM20D8ZRuoA8UI1RN24AWPgUn5PcO9rbKt56+NaaSPNcTircKAWBo1N/og==" Apr 11 09:29:15 volumio volumio[31616]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:29:15 volumio volumio[31616]: info: CoreStateMachine::pushState Apr 11 09:29:15 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:15 volumio volumio[31708]: Starting albumart workers Apr 11 09:29:15 volumio volumio[31616]: info: Asound.conf file unchanged, so no further update is needed Apr 11 09:29:15 volumio volumio[31616]: info: Output device has changed, restarting MPD Apr 11 09:29:15 volumio volumio[31616]: info: Output device has changed, restarting Shairport Sync Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio sudo[31753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:29:15 volumio sudo[31753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio sudo[31753]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio sudo[31755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:29:15 volumio sudo[31755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio volumio[31616]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:15 volumio volumio[31616]: info: ___________ START PLUGINS ___________ Apr 11 09:29:15 volumio volumio[31616]: info: ControllerMpd::onStart: Initializing MPD Apr 11 09:29:15 volumio volumio[31616]: info: Creating MPD Configuration file Apr 11 09:29:15 volumio sudo[31763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:29:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 09:29:15 volumio sudo[31763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio sudo[31763]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155137] CoreMusicLibrary::Adding element Media Servers Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio volumio[31616]: info: UPNP Browser: Client initialized successfully Apr 11 09:29:15 volumio sudo[31766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:29:15 volumio sudo[31766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:29:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:29:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio volumio[31709]: Starting albumart workers Apr 11 09:29:15 volumio volumio[31616]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:29:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:29:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:29:15 volumio volumio[31616]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155213] CoreMusicLibrary::Adding element Last_100 Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155222] CoreMusicLibrary::Adding element Webradio Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:15 volumio volumio[31616]: info: Initializing BBC Radios Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: Creating Spotify config file Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio sudo[31779]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 09:29:15 volumio sudo[31779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 09:29:15 volumio sudo[31779]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=debug msg="completed challenge" Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155420] CoreMusicLibrary::Adding element YouTube Music Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source YouTube Music Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155424] CoreMusicLibrary::Adding element Podcast Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source YouTube Music Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source Podcast Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Starting plugin Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 11 09:29:15 volumio volumio[31616]: info: Volumio Calling Home Apr 11 09:29:15 volumio go-librespot[31688]: time="2026-04-11T09:29:15+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Database loaded at: 2026-04-11T08:29:15.469Z Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:15 volumio volumio[31616]: info: [1775896155502] CoreMusicLibrary::Adding element FM/DAB Radio Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source YouTube Music Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source Podcast Apr 11 09:29:15 volumio volumio[31616]: Cannot find translation for source FM/DAB Radio Apr 11 09:29:15 volumio volumio[31616]: info: [RTL-SDR Radio] Plugin started successfully Apr 11 09:29:15 volumio volumio[31616]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:29:15 volumio volumio[31616]: info: Discovery: Found device Volumio Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:15 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:15 volumio volumio[31616]: info: MPD Permissions set Apr 11 09:29:15 volumio volumio[31616]: info: MPD Permissions set Apr 11 09:29:15 volumio volumio[31616]: info: Spotify config file written Apr 11 09:29:15 volumio sudo[31821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 09:29:15 volumio sudo[31821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio volumio[31616]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 11 09:29:15 volumio systemd[1]: go-librespot-daemon.service: Killing process 31693 (go-librespot) with signal SIGKILL. Apr 11 09:29:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:15 volumio volumio[31616]: info: No need to fix Spotify hosts Apr 11 09:29:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:15 volumio go-librespot[31828]: go-librespot daemon starting... Apr 11 09:29:15 volumio sudo[31821]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio volumio[31616]: info: Starting Shairport Sync Apr 11 09:29:15 volumio volumio[31616]: info: Starting Shairport Sync Apr 11 09:29:15 volumio go-librespot[31834]: time="2026-04-11T09:29:15+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:15 volumio go-librespot[31834]: time="2026-04-11T09:29:15+01:00" level=debug msg="app state loaded" Apr 11 09:29:15 volumio volumio[31616]: info: Starting Shairport Sync Apr 11 09:29:15 volumio go-librespot[31834]: time="2026-04-11T09:29:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:15 volumio sudo[31841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:15 volumio sudo[31841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio sudo[31843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:15 volumio volumio[31616]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:29:15 volumio sudo[31845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:15 volumio volumio[31616]: info: Discovery: Found device Volumio Apr 11 09:29:15 volumio sudo[31845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:15 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:15 volumio sudo[31843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:15 volumio volumio[31616]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:15 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 09:29:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 09:29:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:29:15 volumio systemd[1]: shairport-sync.service: Consumed 1.545s CPU time. Apr 11 09:29:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:29:15 volumio sudo[31843]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio sudo[31841]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio sudo[31845]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:15 volumio volumio[31616]: info: Shairport-Sync Started Apr 11 09:29:15 volumio volumio[31616]: Error adding Membership: Error: addMembership EINVAL Apr 11 09:29:15 volumio volumio[31616]: info: Shairport-Sync Started Apr 11 09:29:15 volumio volumio[31616]: info: Shairport-Sync Started Apr 11 09:29:15 volumio volumio[31616]: info: Volumio called home Apr 11 09:29:15 volumio volumio[31616]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 11 09:29:16 volumio mpd[31800]: 2026-04-11T09:29:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 09:29:16 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 09:29:16 volumio sudo[31755]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:16 volumio sudo[31766]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:16 volumio volumio[31616]: info: Completed starting Core Plugins Apr 11 09:29:16 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:16 volumio volumio[31616]: info: ----- MyVolumio plugins startup ---- Apr 11 09:29:16 volumio volumio[31616]: info: ------------------------------------------- Apr 11 09:29:16 volumio volumio[31616]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 09:29:16 volumio volumio[31616]: error: MPD error: The expression evaluated to a falsy value: Apr 11 09:29:16 volumio volumio[31616]: assert.ok(self.idling) Apr 11 09:29:16 volumio volumio[31616]: error: The expression evaluated to a falsy value: Apr 11 09:29:16 volumio volumio[31616]: assert.ok(self.idling) Apr 11 09:29:16 volumio volumio[31616]: info: MPD running with PID31800 Apr 11 09:29:16 volumio volumio[31616]: ,establishing connection Apr 11 09:29:16 volumio volumio[31616]: error: updateQueue error: null Apr 11 09:29:16 volumio volumio[31616]: error: updateQueue error: null Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=info msg="zeroconf server listening on port 41363" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="obtained new client token: AABoLuVWzrcR4MdiRhgFTMXm/am+dV1EK/FMVyQY6esqXusapoOSyq5q3jGpDykm8GXMe6D6132UGtFq/l9+d3y5KTIe7vMvBntTYG//oo7Y8kkkIXQczhngFcdw5kQM1zxcyfs2mIjQTVr4JNzMHVLBzzi4muAsPg+pyqXk3Dzsh4QuNI+1KhxWenEsOrcywMYUVyk27JvKiJKpW7QW5q2/B+io/+LdzaAyIKWBiNpka0oCp6RvkrYKyg==" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:16 volumio volumio-remote-updater[945]: [2026-04-11 09:29:16] [connect] Successful connection Apr 11 09:29:16 volumio volumio-remote-updater[945]: [2026-04-11 09:29:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1775896156 101 Apr 11 09:29:16 volumio volumio[31616]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=debug msg="completed challenge" Apr 11 09:29:16 volumio go-librespot[31834]: time="2026-04-11T09:29:16+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:17 volumio sudo[31655]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:17 volumio go-librespot[31834]: time="2026-04-11T09:29:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:17 volumio go-librespot[31834]: time="2026-04-11T09:29:17+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:17 volumio go-librespot[31834]: time="2026-04-11T09:29:17+01:00" level=debug msg="completed challenge" Apr 11 09:29:17 volumio go-librespot[31834]: time="2026-04-11T09:29:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="completed challenge" Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:18 volumio volumio[31616]: info: go-librespot daemon successfully initialized Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:18 volumio go-librespot[31834]: time="2026-04-11T09:29:18+01:00" level=debug msg="completed challenge" Apr 11 09:29:19 volumio go-librespot[31834]: time="2026-04-11T09:29:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:20 volumio go-librespot[31834]: time="2026-04-11T09:29:20+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Apr 11 09:29:20 volumio go-librespot[31834]: time="2026-04-11T09:29:20+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:29:20 volumio go-librespot[31834]: time="2026-04-11T09:29:20+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:20 volumio go-librespot[31834]: time="2026-04-11T09:29:20+01:00" level=debug msg="completed challenge" Apr 11 09:29:20 volumio go-librespot[31834]: time="2026-04-11T09:29:20+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:21 volumio go-librespot[31834]: time="2026-04-11T09:29:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:21 volumio go-librespot[31834]: time="2026-04-11T09:29:21+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:21 volumio go-librespot[31834]: time="2026-04-11T09:29:21+01:00" level=debug msg="completed challenge" Apr 11 09:29:21 volumio go-librespot[31834]: time="2026-04-11T09:29:21+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:21 volumio go-librespot[31834]: time="2026-04-11T09:29:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:21 volumio volumio[31616]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:21 volumio volumio[31616]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 09:29:23 volumio sudo[31889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:29:23 volumio sudo[31889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:23 volumio sudo[31891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:29:23 volumio sudo[31891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:23 volumio sudo[31889]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:23 volumio sudo[31891]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:23 volumio sudo[31895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 09:29:23 volumio sudo[31895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:23 volumio sudo[31895]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:23 volumio volumio[31616]: info: Upmpdcli Daemon Started Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 09:29:24 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:24 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:24 volumio volumio[31616]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 09:29:24 volumio volumio[31616]: info: MyVolumio login type: Token Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 09:29:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 11 09:29:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:24 volumio go-librespot[31897]: go-librespot daemon starting... Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="app state loaded" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=info msg="zeroconf server listening on port 37971" Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 09:29:24 volumio volumio[31616]: info: Streaming services startup Apr 11 09:29:24 volumio volumio[31616]: info: Starting Streaming Daemon Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="obtained new client token: AAC75cunnkI4eYeutXQvWjQw+o5rizVXm+EipoMRK4G6XMn9pluEDCb2vcjDCmYejWurv6+JXrQDzzQtqv441uX6vH0DE0wQz5nHSVId7ZjYXFeD7LHdvdzoxoRRHlQ2U36BqDIw7OG3UTXP5Wlzs0Y4rdxY/EhbJaRX2dScgS7rBB1aNR2nU6esyxsHhH9zPJHCEL8MEQQaVL4J7+YbaCgUcDLt7y1smUFOIhCw7yWu8chgnQFlz89bFA==" Apr 11 09:29:24 volumio sudo[31908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:24 volumio sudo[31908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:24 volumio volumio[31616]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 09:29:24 volumio sudo[31908]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:24 volumio volumio[31616]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:24 volumio volumio[31616]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:24 volumio volumio[31616]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:24 volumio volumio[31616]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="new websocket client" Apr 11 09:29:24 volumio volumio[31616]: info: Connection to go-librespot Websocket established Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:24 volumio go-librespot[31898]: time="2026-04-11T09:29:24+01:00" level=debug msg="completed challenge" Apr 11 09:29:25 volumio go-librespot[31898]: time="2026-04-11T09:29:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:25 volumio volumio[31616]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 09:29:25 volumio go-librespot[31898]: time="2026-04-11T09:29:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:25 volumio go-librespot[31898]: time="2026-04-11T09:29:25+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:25 volumio go-librespot[31898]: time="2026-04-11T09:29:25+01:00" level=debug msg="completed challenge" Apr 11 09:29:25 volumio go-librespot[31898]: time="2026-04-11T09:29:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:25 volumio volumio[31616]: info: MyVolumio token set successfully Apr 11 09:29:25 volumio volumio[31616]: info: MYVOLUMIO: Adding device Apr 11 09:29:25 volumio volumio[31616]: info: MYVOLUMIO: Evaluating Server Apr 11 09:29:25 volumio volumio[31616]: info: MyVolumio status changed Apr 11 09:29:25 volumio volumio[31616]: info: Streaming services startup Apr 11 09:29:25 volumio volumio[31616]: info: Starting Streaming Daemon Apr 11 09:29:25 volumio volumio[31616]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 09:29:25 volumio volumio[31616]: info: Removing audio output: Apr 11 09:29:25 volumio volumio[31616]: info: Stoppping Tunnel 1 Apr 11 09:29:25 volumio sudo[31936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:25 volumio sudo[31936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:25 volumio sudo[31938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 11 09:29:25 volumio sudo[31938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio sudo[31936]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:25 volumio volumio[31616]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:25 volumio volumio[31616]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:25 volumio volumio[31616]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:25 volumio sudo[31938]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:25 volumio volumio[31616]: info: Remote SSH Stopped Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:29:26 volumio volumio[31616]: info: Setting Geolocation for MyVolumio to eu3 Apr 11 09:29:26 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:26 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:26 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=debug msg="completed challenge" Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:26 volumio volumio[31616]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 11 09:29:26 volumio go-librespot[31898]: time="2026-04-11T09:29:26+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=debug msg="completed challenge" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:27 volumio volumio[31616]: info: Updating MyVolumio device info Apr 11 09:29:27 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:27 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:27 volumio volumio[31616]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:27 volumio volumio[31616]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=debug msg="completed challenge" Apr 11 09:29:27 volumio go-librespot[31898]: time="2026-04-11T09:29:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:27 volumio volumio[31616]: info: Getting Spotify volume Apr 11 09:29:27 volumio volumio[31616]: 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 11 09:29:27 volumio volumio[31616]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:27 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:27 volumio volumio[31616]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Apr 11 09:29:27 volumio volumio[31616]: SPOTIFY: SPOTIFY VOLUME undefined Apr 11 09:29:27 volumio volumio[31616]: SPOTIFY: VOLUMIO VOLUME 0 Apr 11 09:29:27 volumio volumio[31616]: info: Aligning Spotify Volume to Volumio Volume Apr 11 09:29:27 volumio volumio[31616]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:27 volumio volumio[31616]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:27 volumio volumio[31616]: info: Setting Spotify Volume from Volumio: 0 Apr 11 09:29:28 volumio go-librespot[31898]: time="2026-04-11T09:29:28+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:28 volumio go-librespot[31898]: time="2026-04-11T09:29:28+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:28 volumio go-librespot[31898]: time="2026-04-11T09:29:28+01:00" level=debug msg="completed challenge" Apr 11 09:29:28 volumio go-librespot[31898]: time="2026-04-11T09:29:28+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:28 volumio go-librespot[31898]: time="2026-04-11T09:29:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:28 volumio volumio[31616]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:28 volumio volumio[31616]: Error: socket hang up Apr 11 09:29:28 volumio volumio[31616]: at connResetException (node:internal/errors:720:14) Apr 11 09:29:28 volumio volumio[31616]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 11 09:29:28 volumio volumio[31616]: at Socket.emit (node:events:526:35) Apr 11 09:29:28 volumio volumio[31616]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 11 09:29:28 volumio volumio[31616]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 11 09:29:28 volumio volumio[31616]: code: 'ECONNRESET', Apr 11 09:29:28 volumio volumio[31616]: response: undefined Apr 11 09:29:28 volumio volumio[31616]: } Apr 11 09:29:28 volumio volumio[31616]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:28 volumio sudo[31955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 09:28' Apr 11 09:29:28 volumio sudo[31955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:28 volumio sudo[31955]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:28 volumio volumio-remote-updater[945]: [2026-04-11 09:29:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 11 09:29:28 volumio volumio-remote-updater[945]: [2026-04-11 09:29:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 11 09:29:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 11 09:29:28 volumio systemd[1]: volumio.service: Consumed 8.965s CPU time. Apr 11 09:29:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:29:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:29:29 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 114278. Apr 11 09:29:29 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 11 09:29:29 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 11 09:29:29 volumio systemd[1]: volumio.service: Consumed 8.965s CPU time. Apr 11 09:29:29 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 11 09:29:29 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 11 09:29:29 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:29 volumio volumio[31977]: info: ----- Volumio3 ---- Apr 11 09:29:29 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:29 volumio volumio[31977]: info: ----- System startup ---- Apr 11 09:29:29 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:29 volumio volumio[31977]: info: MYVOLUMIO Environment detected Apr 11 09:29:29 volumio volumio[31977]: info: Plugin folders cleanup Apr 11 09:29:29 volumio volumio[31977]: info: Scanning into folder /volumio/app/plugins/ Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category audio_interface Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category miscellanea Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category music_service Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category plugins.json Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category system_controller Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category user_interface Apr 11 09:29:29 volumio volumio[31977]: info: Scanning into folder /data/plugins/ Apr 11 09:29:29 volumio volumio[31977]: info: Scanning category music_service Apr 11 09:29:29 volumio volumio[31977]: info: Plugin folders cleanup completed Apr 11 09:29:29 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:29 volumio volumio[31977]: info: ----- Core plugins startup ---- Apr 11 09:29:29 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:29 volumio volumio[31977]: info: Loading plugins from folder /volumio/app/plugins/ Apr 11 09:29:29 volumio volumio[31977]: info: Adding plugin upnp to MyMusic Plugins Apr 11 09:29:29 volumio volumio[31977]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 11 09:29:29 volumio volumio[31977]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 11 09:29:29 volumio volumio[31977]: info: Loading plugins from folder /data/plugins/ Apr 11 09:29:29 volumio volumio[31977]: info: Adding plugin rtlsdr_radio to MyMusic Plugins Apr 11 09:29:29 volumio volumio[31977]: info: Loading plugin "system"... Apr 11 09:29:29 volumio volumio[31977]: info: Loading plugin "appearance"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "network"... Apr 11 09:29:30 volumio volumio[31977]: info: Refreshing Cached IP Addresses Apr 11 09:29:30 volumio sudo[32005]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:29:30 volumio sudo[32005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:30 volumio sudo[32007]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:29:30 volumio sudo[32007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:30 volumio sudo[32005]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:30 volumio sudo[32007]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "services"... Apr 11 09:29:30 volumio sudo[32016]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "alsa_controller"... Apr 11 09:29:30 volumio sudo[32016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:30 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "wizard"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "networkfs"... Apr 11 09:29:30 volumio volumio[31977]: info: Starting Udev Watcher for removable devices Apr 11 09:29:30 volumio volumio[31977]: info: Mounting Device 0ACB-A1DE Apr 11 09:29:30 volumio sudo[32044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0ACB-A1DE -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:29:30 volumio sudo[32044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:30 volumio sudo[32044]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:30 volumio volumio[31977]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:29:30 volumio volumio[31977]: dmesg(1) may have more information after failed mount system call. Apr 11 09:29:30 volumio volumio[31977]: error: Failed to mount 0ACB-A1DE: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0ACB-A1DE" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 11 09:29:30 volumio volumio[31977]: mount: /media/0ACB-A1DE: /dev/sda1 already mounted on /media/0ACB-A1DE. Apr 11 09:29:30 volumio volumio[31977]: dmesg(1) may have more information after failed mount system call. Apr 11 09:29:30 volumio volumio[31977]: info: Ignoring mount for partition: boot Apr 11 09:29:30 volumio volumio[31977]: info: Ignoring mount for partition: volumio Apr 11 09:29:30 volumio volumio[31977]: info: Ignoring mount for partition: volumio_data Apr 11 09:29:30 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "volumio_command_line_client"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "upnp"... Apr 11 09:29:30 volumio volumio[31977]: info: [1775896170363] Starting Upmpd Daemon Apr 11 09:29:30 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "my_music"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "mpd"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "upnp_browser"... Apr 11 09:29:30 volumio volumio[31977]: info: Starting UPNP Browser Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "alarm-clock"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "airplay_emulation"... Apr 11 09:29:30 volumio volumio[31977]: info: Starting Shairport Sync Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "last_100"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "webradio"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "i2s_dacs"... Apr 11 09:29:30 volumio volumio[31977]: info: Loading plugin "volumiodiscovery"... Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** For more information see Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:30 volumio volumio[31977]: *** WARNING *** For more information see Apr 11 09:29:30 volumio node[31977]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:30 volumio node[31977]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:30 volumio node[31977]: *** WARNING *** For more information see Apr 11 09:29:30 volumio node[31977]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 11 09:29:30 volumio node[31977]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 11 09:29:30 volumio node[31977]: *** WARNING *** For more information see Apr 11 09:29:30 volumio volumio[31977]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 11 09:29:31 volumio volumio[31977]: info: Discovery: Started advertising with name: Volumio Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "spop"... Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "ytmusic"... Apr 11 09:29:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 11 09:29:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:31 volumio go-librespot[32048]: go-librespot daemon starting... Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=debug msg="app state loaded" Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "outputs"... Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "albumart"... Apr 11 09:29:31 volumio volumio[31977]: info: Plugin example_plugin is not enabled Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "inputs"... Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "updater_comm"... Apr 11 09:29:31 volumio volumio[31977]: info: Plugin mpdemulation is not enabled Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "rest_api"... Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "websocket"... Apr 11 09:29:31 volumio volumio[31977]: info: Starting Socket.io Server version 1.7.4 Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "podcast"... Apr 11 09:29:31 volumio volumio[31977]: info: ControllerPodcast::constructor Apr 11 09:29:31 volumio volumio[31977]: info: Loading plugin "rtlsdr_radio"... Apr 11 09:29:31 volumio volumio[32055]: Forking 3 albumart workers Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:31 volumio go-librespot[32049]: time="2026-04-11T09:29:31+01:00" level=info msg="zeroconf server listening on port 45173" Apr 11 09:29:31 volumio volumio[31977]: info: Loading i18n strings for locale en Apr 11 09:29:31 volumio volumio[31977]: Updating browse sources language Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::initPlayerControls Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: Express server listening on port 3000 Apr 11 09:29:31 volumio volumio[31977]: [Metrics] WebUI: 2s 334.71ms Apr 11 09:29:31 volumio volumio[31977]: info: CoreStateMachine::resetVolumioState Apr 11 09:29:31 volumio volumio[31977]: info: CoreStateMachine::getcurrentVolume Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:29:31 volumio volumio[31977]: info: Volumio Network Manager: Network status updated: 2 Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:31 volumio volumio[31977]: info: Reloading queue from file Apr 11 09:29:31 volumio volumio[31977]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:29:31 volumio volumio[31977]: info: CoreStateMachine::pushState Apr 11 09:29:31 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:31 volumio volumio[31977]: info: CoreStateMachine::updateTrackBlock Apr 11 09:29:31 volumio volumio[31977]: info: CorePlayQueue::getTrackBlock Apr 11 09:29:31 volumio volumio[31977]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 09:29:32 volumio volumio[31977]: info: CoreStateMachine::setRepeat null single undefined Apr 11 09:29:32 volumio volumio[31977]: info: CoreStateMachine::pushState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:32 volumio volumio[31977]: info: CoreStateMachine::setRandom true Apr 11 09:29:32 volumio volumio[31977]: info: CoreStateMachine::pushState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:32 volumio volumio[31977]: info: Setting Device type: Raspberry PI Apr 11 09:29:32 volumio volumio[31977]: info: Completed loading Core Plugins Apr 11 09:29:32 volumio volumio[31977]: info: Preparing to generate the ALSA configuration file Apr 11 09:29:32 volumio volumio[31977]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 11 09:29:32 volumio volumio[31977]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Apr 11 09:29:32 volumio volumio[31977]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 11 09:29:32 volumio volumio[31977]: info: Asound.conf file unchanged, so no further update is needed Apr 11 09:29:32 volumio volumio[31977]: info: Output device has changed, restarting MPD Apr 11 09:29:32 volumio volumio[31977]: info: Output device has changed, restarting Shairport Sync Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio sudo[32114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:29:32 volumio sudo[32114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio sudo[32116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:29:32 volumio sudo[32116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio sudo[32114]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio volumio[31977]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:32 volumio volumio[31977]: info: ___________ START PLUGINS ___________ Apr 11 09:29:32 volumio volumio[31977]: info: ControllerMpd::onStart: Initializing MPD Apr 11 09:29:32 volumio volumio[31977]: info: Creating MPD Configuration file Apr 11 09:29:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172097] CoreMusicLibrary::Adding element Media Servers Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio volumio[32068]: Starting albumart workers Apr 11 09:29:32 volumio volumio[31977]: info: UPNP Browser: Client initialized successfully Apr 11 09:29:32 volumio sudo[32124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 09:29:32 volumio sudo[32124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio sudo[32126]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 09:29:32 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:29:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:29:32 volumio sudo[32124]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:29:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:29:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:29:32 volumio sudo[32126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio volumio[31977]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio volumio[32067]: Starting albumart workers Apr 11 09:29:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:29:32 volumio volumio[31977]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172150] CoreMusicLibrary::Adding element Last_100 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172152] CoreMusicLibrary::Adding element Webradio Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:32 volumio volumio[31977]: info: Initializing BBC Radios Apr 11 09:29:32 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 09:29:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 09:29:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 09:29:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 09:29:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 09:29:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 09:29:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: Creating Spotify config file Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[32066]: Starting albumart workers Apr 11 09:29:32 volumio go-librespot[32049]: time="2026-04-11T09:29:32+01:00" level=debug msg="obtained new client token: AAAQu6As3WX0nOW2PY5L7SA82Cu8PeDqS4D2+BWEJDDOcFqKIIqhyM/khjqt247W3MhHb4FsNV4EnhxLjKumrPTOtcu1zYoX96m/ruMWIEuU/9SrwIaofnE0LHMzT9/aJKgl7kNr8ZN0eZYNGgMY1o04TeTK29C03/T+j7Wn5wzRAtcaItkY28DcpHbiW+mrtymyFIijtDHdnuEph0vyvRatmwxFrwe4esTl4qMdGX/5Td9ClfFaoHM=" Apr 11 09:29:32 volumio sudo[32148]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 09:29:32 volumio sudo[32148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 09:29:32 volumio sudo[32148]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio go-librespot[32049]: time="2026-04-11T09:29:32+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172376] CoreMusicLibrary::Adding element YouTube Music Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source YouTube Music Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172382] CoreMusicLibrary::Adding element Podcast Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source YouTube Music Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source Podcast Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Starting plugin Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Loaded i18n strings for language: en Apr 11 09:29:32 volumio volumio[31977]: info: Volumio Calling Home Apr 11 09:29:32 volumio go-librespot[32049]: time="2026-04-11T09:29:32+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:32 volumio go-librespot[32049]: time="2026-04-11T09:29:32+01:00" level=debug msg="completed challenge" Apr 11 09:29:32 volumio go-librespot[32049]: time="2026-04-11T09:29:32+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] snd-aloop already loaded Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] No stations database found, creating v2 Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Database loaded at: 2026-04-11T08:29:32.438Z Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Loading blocklist from: /data/plugins/music_service/rtlsdr_radio/blocklist.json Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Got 21 phrases from file Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Updated metadata blocklist Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Metadata module now has 21 phrases Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Management server started on port 3456 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 09:29:32 volumio volumio[31977]: info: [1775896172495] CoreMusicLibrary::Adding element FM/DAB Radio Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source YouTube Music Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source Podcast Apr 11 09:29:32 volumio volumio[31977]: Cannot find translation for source FM/DAB Radio Apr 11 09:29:32 volumio volumio[31977]: info: [RTL-SDR Radio] Plugin started successfully Apr 11 09:29:32 volumio volumio[31977]: info: MPD Permissions set Apr 11 09:29:32 volumio volumio[31977]: info: MPD Permissions set Apr 11 09:29:32 volumio volumio[31977]: info: VolumeController:: Volume=36 Mute =true Apr 11 09:29:32 volumio volumio[31977]: info: CoreStateMachine::pushState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioPushState Apr 11 09:29:32 volumio volumio[31977]: info: Spotify config file written Apr 11 09:29:32 volumio sudo[32183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 09:29:32 volumio sudo[32183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio volumio[31977]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 09:29:32 volumio volumio[31977]: info: No need to fix Spotify hosts Apr 11 09:29:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:32 volumio sudo[32183]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio go-librespot[32193]: go-librespot daemon starting... Apr 11 09:29:32 volumio volumio[31977]: info: Volumio called home Apr 11 09:29:32 volumio volumio[31977]: info: Discovery: adding 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:29:32 volumio volumio[31977]: info: Discovery: Found device Volumio Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio go-librespot[32196]: time="2026-04-11T09:29:32+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:32 volumio go-librespot[32196]: time="2026-04-11T09:29:32+01:00" level=debug msg="app state loaded" Apr 11 09:29:32 volumio volumio[31977]: info: Discovery: this is already registered, 072f109f-54a2-4344-b8c4-538b45da7e51 Apr 11 09:29:32 volumio go-librespot[32196]: time="2026-04-11T09:29:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:32 volumio volumio[31977]: info: Discovery: Found device Volumio Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio volumio[31977]: info: Starting Shairport Sync Apr 11 09:29:32 volumio volumio[31977]: info: Starting Shairport Sync Apr 11 09:29:32 volumio volumio[31977]: info: Starting Shairport Sync Apr 11 09:29:32 volumio sudo[32203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:32 volumio sudo[32203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio sudo[32205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:32 volumio sudo[32208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 09:29:32 volumio sudo[32208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio sudo[32205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:32 volumio volumio[31977]: info: CoreCommandRouter::volumioGetState Apr 11 09:29:32 volumio volumio[31977]: info: CorePlayQueue::getTrack 0 Apr 11 09:29:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 09:29:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 09:29:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:29:32 volumio systemd[1]: shairport-sync.service: Consumed 1.540s CPU time. Apr 11 09:29:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 09:29:32 volumio sudo[32208]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio sudo[32205]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio sudo[32203]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:32 volumio volumio[31977]: info: Shairport-Sync Started Apr 11 09:29:32 volumio volumio[31977]: Error adding Membership: Error: addMembership EINVAL Apr 11 09:29:32 volumio volumio[31977]: info: Shairport-Sync Started Apr 11 09:29:32 volumio volumio[31977]: info: Shairport-Sync Started Apr 11 09:29:32 volumio volumio[31977]: info: An error occurred while refreshing Spotify Token Error: Bad Request Apr 11 09:29:33 volumio mpd[32155]: 2026-04-11T09:29:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 09:29:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 09:29:33 volumio sudo[32116]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:33 volumio sudo[32126]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:33 volumio volumio[31977]: info: Completed starting Core Plugins Apr 11 09:29:33 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:33 volumio volumio[31977]: info: ----- MyVolumio plugins startup ---- Apr 11 09:29:33 volumio volumio[31977]: info: ------------------------------------------- Apr 11 09:29:33 volumio volumio[31977]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 09:29:33 volumio volumio[31977]: error: MPD error: The expression evaluated to a falsy value: Apr 11 09:29:33 volumio volumio[31977]: assert.ok(self.idling) Apr 11 09:29:33 volumio volumio[31977]: error: The expression evaluated to a falsy value: Apr 11 09:29:33 volumio volumio[31977]: assert.ok(self.idling) Apr 11 09:29:33 volumio volumio[31977]: info: MPD running with PID32155 Apr 11 09:29:33 volumio volumio[31977]: ,establishing connection Apr 11 09:29:33 volumio volumio[31977]: error: updateQueue error: null Apr 11 09:29:33 volumio volumio[31977]: error: updateQueue error: null Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=info msg="zeroconf server listening on port 39019" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="obtained new client token: AABB2S8JoOxagX6lRxQmMgfW0CblVL6W4s9VuzxWJvAQMzNeFhfdWTac0fSK+Ahi9AWF5CP5PLJSR5H28cif1giri2h0CVZBxNqO2XIs9M5htNyowazqHsS3ydvr/4nsnitLLgrWMBLuiNUy1Ek+m2jNow5nQyBIX57D1/XeoeegyXupDTnlO9dqOEuvHbqj7vJYsPjfIIZXvSU55wbKZdpCTwbMBjQZ63OGqJeoIjNBJofuGZL8CQINlA==" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=debug msg="completed challenge" Apr 11 09:29:33 volumio go-librespot[32196]: time="2026-04-11T09:29:33+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:33 volumio volumio-remote-updater[945]: [2026-04-11 09:29:33] [connect] Successful connection Apr 11 09:29:33 volumio volumio-remote-updater[945]: [2026-04-11 09:29:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1775896173 101 Apr 11 09:29:33 volumio volumio[31977]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Apr 11 09:29:34 volumio sudo[32016]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="completed challenge" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=debug msg="completed challenge" Apr 11 09:29:34 volumio go-librespot[32196]: time="2026-04-11T09:29:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:35 volumio go-librespot[32196]: time="2026-04-11T09:29:35+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 11 09:29:35 volumio volumio[31977]: info: go-librespot daemon successfully initialized Apr 11 09:29:35 volumio go-librespot[32196]: time="2026-04-11T09:29:35+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:35 volumio go-librespot[32196]: time="2026-04-11T09:29:35+01:00" level=debug msg="completed challenge" Apr 11 09:29:35 volumio go-librespot[32196]: time="2026-04-11T09:29:35+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:36 volumio go-librespot[32196]: time="2026-04-11T09:29:36+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 11 09:29:36 volumio go-librespot[32196]: time="2026-04-11T09:29:36+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:36 volumio go-librespot[32196]: time="2026-04-11T09:29:36+01:00" level=debug msg="completed challenge" Apr 11 09:29:36 volumio go-librespot[32196]: time="2026-04-11T09:29:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:37 volumio go-librespot[32196]: time="2026-04-11T09:29:37+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:29:37 volumio go-librespot[32196]: time="2026-04-11T09:29:37+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:37 volumio go-librespot[32196]: time="2026-04-11T09:29:37+01:00" level=debug msg="completed challenge" Apr 11 09:29:37 volumio go-librespot[32196]: time="2026-04-11T09:29:37+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:37 volumio go-librespot[32196]: time="2026-04-11T09:29:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:38 volumio volumio[31977]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:38 volumio volumio[31977]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 09:29:40 volumio sudo[32250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 09:29:40 volumio sudo[32250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:40 volumio sudo[32252]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 09:29:40 volumio sudo[32252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:40 volumio sudo[32250]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:40 volumio sudo[32252]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:40 volumio sudo[32254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 11 09:29:40 volumio sudo[32254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:40 volumio sudo[32254]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:40 volumio volumio[31977]: info: Upmpdcli Daemon Started Apr 11 09:29:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 11 09:29:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 09:29:40 volumio go-librespot[32258]: go-librespot daemon starting... Apr 11 09:29:40 volumio go-librespot[32259]: time="2026-04-11T09:29:40+01:00" level=info msg="running go-librespot 0.6.2" Apr 11 09:29:40 volumio go-librespot[32259]: time="2026-04-11T09:29:40+01:00" level=debug msg="app state loaded" Apr 11 09:29:40 volumio go-librespot[32259]: time="2026-04-11T09:29:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=info msg="zeroconf server listening on port 36919" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="obtained new client token: AABaZhJr11wfunghD9Sd3WWZ9pkslkxK61rYQKHks/zDzmPR7oOIiB6cdlOfu3xPQhMX263N1gh4LnkhG5TbU3tmsqToKAodE6uf1z1+O6NXwfzfumaA58YDHTiGbk/ZXYNnQogdAj8TtV6crtzQ82/0p71Nx1KAfYryGmvvJ+PetettyMBogQuGbLxmqyzG2G6KrabzmErgw+JhVfa6WCeSR7QqpbyH+yxTjjJe6KY2uhlYht1s8dQ=" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="completed challenge" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 09:29:41 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:41 volumio volumio[31977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 09:29:41 volumio volumio[31977]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 09:29:41 volumio volumio[31977]: info: MyVolumio login type: Token Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="completed challenge" Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 09:29:41 volumio volumio[31977]: info: Streaming services startup Apr 11 09:29:41 volumio volumio[31977]: info: Starting Streaming Daemon Apr 11 09:29:41 volumio sudo[32269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:41 volumio sudo[32269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:41 volumio volumio[31977]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 09:29:41 volumio sudo[32269]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:41 volumio volumio[31977]: info: Initializing connection to go-librespot Websocket Apr 11 09:29:41 volumio volumio[31977]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:41 volumio volumio[31977]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:41 volumio volumio[31977]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:41 volumio go-librespot[32259]: time="2026-04-11T09:29:41+01:00" level=debug msg="new websocket client" Apr 11 09:29:41 volumio volumio[31977]: info: Connection to go-librespot Websocket established Apr 11 09:29:42 volumio go-librespot[32259]: time="2026-04-11T09:29:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 11 09:29:42 volumio go-librespot[32259]: time="2026-04-11T09:29:42+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:42 volumio go-librespot[32259]: time="2026-04-11T09:29:42+01:00" level=debug msg="completed challenge" Apr 11 09:29:42 volumio go-librespot[32259]: time="2026-04-11T09:29:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:42 volumio volumio[31977]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 09:29:42 volumio volumio[31977]: info: MyVolumio token set successfully Apr 11 09:29:42 volumio volumio[31977]: info: MYVOLUMIO: Adding device Apr 11 09:29:42 volumio volumio[31977]: info: MYVOLUMIO: Evaluating Server Apr 11 09:29:42 volumio volumio[31977]: info: MyVolumio status changed Apr 11 09:29:42 volumio volumio[31977]: info: Streaming services startup Apr 11 09:29:42 volumio volumio[31977]: info: Starting Streaming Daemon Apr 11 09:29:42 volumio volumio[31977]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 09:29:42 volumio volumio[31977]: info: Removing audio output: Apr 11 09:29:42 volumio volumio[31977]: info: Stoppping Tunnel 1 Apr 11 09:29:42 volumio sudo[32297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 09:29:42 volumio sudo[32297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:42 volumio sudo[32299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 11 09:29:42 volumio sudo[32299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 09:29:42 volumio sudo[32297]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:42 volumio volumio[31977]: error: Cannot start Volumio Streaming Daemon Apr 11 09:29:42 volumio volumio[31977]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 09:29:42 volumio volumio[31977]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 09:29:42 volumio sudo[32299]: pam_unix(sudo:session): session closed for user root Apr 11 09:29:42 volumio volumio[31977]: info: Remote SSH Stopped Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=debug msg="completed challenge" Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:43 volumio go-librespot[32259]: time="2026-04-11T09:29:43+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=debug msg="completed challenge" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=debug msg="completed keyexchange" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=debug msg="completed challenge" Apr 11 09:29:44 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:45 volumio go-librespot[32259]: time="2026-04-11T09:29:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Apr 11 09:29:45 volumio volumio[31977]: info: Getting Spotify volume Apr 11 09:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 09:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 09:29:45 volumio volumio[31977]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:45 volumio volumio[31977]: Error: connect ECONNRESET 127.0.0.1:9879 Apr 11 09:29:45 volumio volumio[31977]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 11 09:29:45 volumio volumio[31977]: errno: -104, Apr 11 09:29:45 volumio volumio[31977]: code: 'ECONNRESET', Apr 11 09:29:45 volumio volumio[31977]: syscall: 'connect', Apr 11 09:29:45 volumio volumio[31977]: address: '127.0.0.1', Apr 11 09:29:45 volumio volumio[31977]: port: 9879, Apr 11 09:29:45 volumio volumio[31977]: response: undefined Apr 11 09:29:45 volumio volumio[31977]: } Apr 11 09:29:45 volumio volumio[31977]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 09:29:45 volumio sudo[32316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 09:28' Apr 11 09:29:45 volumio sudo[32316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"