Oct 16 18:08:31 volumio ntpd[1008]: CLOCK: time stepped by 23157839.802206 Oct 16 18:08:31 volumio ntpd[1008]: CLOCK: time changed from 2026-01-21 to 2026-10-16 Oct 16 18:08:31 volumio ntpd[1008]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 16 18:08:33 volumio volumio-remote-updater[796]: [2026-10-16 18:08:33] [connect] Successful connection Oct 16 18:08:36 volumio volumio[1208]: info: Loading plugin "ytmusic"... Oct 16 18:08:37 volumio volumio[1208]: info: Plugin now_playing is not enabled Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "outputs"... Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "albumart"... Oct 16 18:08:37 volumio volumio[1208]: info: Plugin example_plugin is not enabled Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "inputs"... Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "updater_comm"... Oct 16 18:08:37 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Oct 16 18:08:37 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Oct 16 18:08:37 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Oct 16 18:08:37 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 16 18:08:37 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Oct 16 18:08:37 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Oct 16 18:08:37 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Oct 16 18:08:37 volumio volumio[1208]: info: Plugin mpdemulation is not enabled Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "rest_api"... Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "websocket"... Oct 16 18:08:37 volumio volumio[1208]: info: Starting Socket.io Server version 1.7.4 Oct 16 18:08:37 volumio volumio[1208]: info: Loading plugin "radio_paradise"... Oct 16 18:08:37 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Oct 16 18:08:37 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Oct 16 18:08:38 volumio volumio[1208]: info: Applying required configuration parameters for plugin radio_paradise Oct 16 18:08:38 volumio volumio[1208]: info: [1792154318327] [RadioParadise] API delay: 5 Oct 16 18:08:38 volumio volumio[1208]: info: Loading plugin "backup_restore"... Oct 16 18:08:38 volumio volumio[1478]: Forking 3 albumart workers Oct 16 18:08:39 volumio volumio[1208]: info: Applying required configuration parameters for plugin backup_restore Oct 16 18:08:39 volumio volumio[1208]: info: Loading plugin "rpi_eeprom_config"... Oct 16 18:08:43 volumio volumio[1517]: Starting albumart workers Oct 16 18:08:43 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Oct 16 18:08:43 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 18:08:43 volumio volumio[1516]: Starting albumart workers Oct 16 18:08:43 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 18:08:43 volumio upmpdcli[1546]: Could not open config: /tmp/upmpdcli.conf Oct 16 18:08:43 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 16 18:08:43 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 16 18:08:43 volumio volumio[1518]: Starting albumart workers Oct 16 18:08:46 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 16 18:08:46 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 16 18:08:48 volumio volumio-remote-updater[796]: [2026-10-16 18:08:48] [connect] Successful connection Oct 16 18:08:48 volumio volumio[1208]: info: Applying required configuration parameters for plugin rpi_eeprom_config Oct 16 18:08:49 volumio volumio[1208]: info: [RpiEepromConfig] Hardware capabilities loaded Oct 16 18:08:49 volumio volumio[1208]: info: Loading plugin "rpi_eeprom_updater"... Oct 16 18:08:49 volumio volumio[1208]: info: Applying required configuration parameters for plugin rpi_eeprom_updater Oct 16 18:08:50 volumio volumio[1208]: info: Loading plugin "serialampcontroller"... Oct 16 18:08:52 volumio volumio[1208]: info: Applying required configuration parameters for plugin serialampcontroller Oct 16 18:08:52 volumio volumio[1208]: info: Applying required configuration parameters for plugin serialampcontroller Oct 16 18:08:52 volumio volumio[1208]: info: Plugin touch_display is not enabled Oct 16 18:08:52 volumio volumio[1208]: info: Loading i18n strings for locale en Oct 16 18:08:52 volumio volumio[1208]: Updating browse sources language Oct 16 18:08:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::initPlayerControls Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 18:08:56 volumio volumio[1208]: Express server listening on port 3000 Oct 16 18:08:56 volumio volumio[1208]: [Metrics] WebUI: 38s 155.74ms Oct 16 18:08:56 volumio volumio[1208]: info: CoreStateMachine::resetVolumioState Oct 16 18:08:56 volumio volumio[1208]: info: CoreStateMachine::getcurrentVolume Oct 16 18:08:56 volumio volumio[1208]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 18:08:56 volumio volumio[1208]: info: Volumio Network Manager: Network status updated: 2 Oct 16 18:08:56 volumio sudo[1607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 18:08:56 volumio sudo[1607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:56 volumio sudo[1609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 18:08:56 volumio sudo[1609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:56 volumio sudo[1607]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:56 volumio sudo[1609]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:57 volumio volumio[1208]: info: VolumeController:: Volume=98 Mute =false Oct 16 18:08:57 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 16 18:08:57 volumio volumio[1208]: info: CoreStateMachine::updateTrackBlock Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrackBlock Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:08:57 volumio volumio[1208]: info: Setting Device type: Raspberry PI Oct 16 18:08:57 volumio volumio[1208]: info: VolumeController:: Volume=98 Mute =false Oct 16 18:08:57 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 16 18:08:57 volumio volumio[1208]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 18:08:57 volumio volumio[1208]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Oct 16 18:08:57 volumio volumio[1208]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: A device disappeared from network Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: A device disappeared from network Oct 16 18:08:57 volumio sudo[1626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 18:08:57 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: adding adfff08c-fe7b-499e-9d1f-7fb97479a526 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: Found device Volumio Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: this is already registered, adfff08c-fe7b-499e-9d1f-7fb97479a526 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: Found device Volumio Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: this is already registered, adfff08c-fe7b-499e-9d1f-7fb97479a526 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: Found device Volumio Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: this is already registered, adfff08c-fe7b-499e-9d1f-7fb97479a526 Oct 16 18:08:57 volumio volumio[1208]: info: Discovery: Found device Volumio Oct 16 18:08:57 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:08:57 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:58 volumio volumio[1208]: info: Reloading queue from file Oct 16 18:08:58 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Oct 16 18:08:58 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 18:08:58 volumio volumio[1208]: info: Completed loading Core Plugins Oct 16 18:08:58 volumio volumio[1208]: info: Preparing to generate the ALSA configuration file Oct 16 18:08:58 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 16 18:08:58 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:58 volumio volumio[1208]: info: Upmpdcli Daemon Started Oct 16 18:08:58 volumio volumio[1208]: info: CoreStateMachine::setRepeat true single undefined Oct 16 18:08:58 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 16 18:08:58 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 16 18:08:58 volumio volumio[1208]: info: CoreStateMachine::setRandom false Oct 16 18:08:58 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 16 18:08:58 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 16 18:08:58 volumio volumio[1208]: info: Asound.conf file unchanged, so no further update is needed Oct 16 18:08:58 volumio volumio[1208]: info: Output device has changed, restarting MPD Oct 16 18:08:58 volumio volumio[1208]: info: Output device has changed, restarting Shairport Sync Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:58 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:08:59 volumio sudo[1641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 18:08:59 volumio sudo[1641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:59 volumio sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 18:08:59 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:59 volumio sudo[1641]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:59 volumio volumio[1208]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 18:08:59 volumio volumio[1208]: info: ___________ START PLUGINS ___________ Oct 16 18:08:59 volumio volumio[1208]: info: ControllerMpd::onStart: Initializing MPD Oct 16 18:08:59 volumio volumio[1208]: info: Creating MPD Configuration file Oct 16 18:08:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 18:08:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:08:59 volumio volumio[1208]: info: [1792154339239] CoreMusicLibrary::Adding element Media Servers Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:08:59 volumio volumio[1208]: info: UPNP Browser: Client initialized successfully Oct 16 18:08:59 volumio sudo[1653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 18:08:59 volumio sudo[1653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:59 volumio sudo[1653]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:08:59 volumio sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 18:08:59 volumio sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:08:59 volumio sudo[1654]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 18:08:59 volumio sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 18:08:59 volumio sudo[1661]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 18:08:59 volumio sudo[1654]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:59 volumio volumio[1208]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:08:59 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 16 18:08:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 18:08:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 16 18:08:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 18:08:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 18:08:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 18:08:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 18:08:59 volumio volumio[1208]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:08:59 volumio volumio[1208]: info: [1792154339552] CoreMusicLibrary::Adding element Last_100 Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:08:59 volumio sudo[1670]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 18:08:59 volumio sudo[1670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 18:08:59 volumio sudo[1671]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 18:08:59 volumio volumio[1208]: info: [1792154339573] CoreMusicLibrary::Adding element Webradio Oct 16 18:08:59 volumio sudo[1670]: pam_unix(sudo:session): session closed for user root Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 18:08:59 volumio volumio[1208]: info: Initializing BBC Radios Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:08:59 volumio volumio[1208]: info: [1792154339884] CoreMusicLibrary::Adding element SoundCloud Oct 16 18:08:59 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:08:59 volumio volumio[1208]: Cannot find translation for source SoundCloud Oct 16 18:08:59 volumio volumio[1208]: info: Creating Spotify config file Oct 16 18:09:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:03 volumio volumio-remote-updater[796]: [2026-10-16 18:09:03] [connect] Successful connection Oct 16 18:09:07 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:09:07 volumio volumio[1208]: info: [1792154347706] CoreMusicLibrary::Adding element YouTube2 Oct 16 18:09:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:09:07 volumio volumio[1208]: Cannot find translation for source SoundCloud Oct 16 18:09:07 volumio volumio[1208]: Cannot find translation for source YouTube2 Oct 16 18:09:07 volumio volumio[1208]: info: [ytcr] Data store TTL expired - clearing it... Oct 16 18:09:08 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:09:08 volumio volumio[1208]: info: [1792154348083] CoreMusicLibrary::Adding element YouTube Music Oct 16 18:09:08 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source SoundCloud Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source YouTube2 Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source YouTube Music Oct 16 18:09:08 volumio volumio[1208]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 18:09:08 volumio volumio[1208]: info: [1792154348108] CoreMusicLibrary::Adding element Radio Paradise Oct 16 18:09:08 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source SoundCloud Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source YouTube2 Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source YouTube Music Oct 16 18:09:08 volumio volumio[1208]: Cannot find translation for source Radio Paradise Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Starting Raspberry Pi EEPROM Configuration Manager Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Detected full model string: Raspberry Pi 4 Model B Rev 1.4 Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Matched to capability profile: Raspberry Pi 4 Model B Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Detected model: Raspberry Pi 4 Model B Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Boot modes: sd, usb Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Using rpi-eeprom-config at: /usr/bin/rpi-eeprom-config Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Backup directory ensured: /data/configuration/system_controller/rpi_eeprom_config/backup Oct 16 18:09:08 volumio volumio[1208]: info: [RpiEepromConfig] Plugin started successfully Oct 16 18:09:09 volumio volumio[1208]: info: [RpiEepromUpdater] Plugin started successfully Oct 16 18:09:09 volumio volumio[1208]: info: Volumio Calling Home Oct 16 18:09:10 volumio volumio[1208]: info: MPD Permissions set Oct 16 18:09:10 volumio volumio[1208]: info: MPD Permissions set Oct 16 18:09:10 volumio volumio[1208]: info: Spotify config file written Oct 16 18:09:10 volumio volumio[1208]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 16 18:09:10 volumio volumio[1208]: info: No need to fix Spotify hosts Oct 16 18:09:11 volumio sudo[1731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 18:09:11 volumio sudo[1731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:09:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 18:09:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 16 18:09:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 18:09:11 volumio go-librespot[1733]: go-librespot daemon starting... Oct 16 18:09:11 volumio sudo[1731]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:12 volumio volumio[1208]: error: [SERIALAMPCONTROLLER] onStart: Error: The selected Interface does not exist or the selected amp does not support it. Check Settings. Oct 16 18:09:12 volumio go-librespot[1734]: time="2026-10-16T18:09:12+05:30" level=info msg="running go-librespot 0.4.0" Oct 16 18:09:12 volumio go-librespot[1734]: time="2026-10-16T18:09:12+05:30" level=debug msg="app state loaded" Oct 16 18:09:12 volumio go-librespot[1734]: time="2026-10-16T18:09:12+05:30" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 18:09:12 volumio volumio[1208]: info: Volumio called home Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 18:09:12 volumio volumio[1208]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 16 18:09:13 volumio volumio[1208]: info: Starting Shairport Sync Oct 16 18:09:13 volumio volumio[1208]: info: Starting Shairport Sync Oct 16 18:09:13 volumio volumio[1208]: info: Starting Shairport Sync Oct 16 18:09:13 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:09:13 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:09:13 volumio sudo[1754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 18:09:13 volumio sudo[1752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 18:09:13 volumio sudo[1754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:09:13 volumio sudo[1752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:09:13 volumio sudo[1756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 18:09:13 volumio sudo[1756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 18:09:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 18:09:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 18:09:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio systemd[1]: shairport-sync.service: Consumed 1.457s CPU time. Oct 16 18:09:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 18:09:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 18:09:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio sudo[1754]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:13 volumio sudo[1752]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 18:09:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 18:09:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio go-librespot[1734]: time="2026-10-16T18:09:13+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 18:09:13 volumio go-librespot[1734]: time="2026-10-16T18:09:13+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 18:09:13 volumio go-librespot[1734]: time="2026-10-16T18:09:13+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 18:09:13 volumio go-librespot[1734]: time="2026-10-16T18:09:13+05:30" level=info msg="zeroconf server listening on port 34545" Oct 16 18:09:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 18:09:13 volumio sudo[1756]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:13 volumio volumio[1208]: info: Shairport-Sync Started Oct 16 18:09:13 volumio volumio[1208]: Error adding Membership: Error: addMembership EINVAL Oct 16 18:09:13 volumio volumio[1208]: info: Shairport-Sync Started Oct 16 18:09:13 volumio volumio[1208]: info: Shairport-Sync Started Oct 16 18:09:13 volumio mpd[1672]: 2026-10-16T18:09:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 18:09:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 18:09:14 volumio sudo[1656]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:14 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Oct 16 18:09:14 volumio go-librespot[1734]: time="2026-10-16T18:09:14+05:30" level=debug msg="obtained new client token: AAGzJqztuXB/hIVAmFVmgWA67oR3S0lMjNzBOVzo5nm2wbazhteqoK7WOuW3W8JhGKOtiSQrGCkX/Ngfhjz6FYp8sP578Crm8IzFH7WarKx6Xeq3YADWFP40f3ByDoP4PIx7Dia13mTDiWo4qZwkt0/U1xffhaI3aFHButfVGhQBiucSyQbAzKcTCD5IyXpsOArJlNly/v1r+E0wd0aTsw+VY3aWpQC82ny92BeWtyzuQMJn/iRhWoEg" Oct 16 18:09:14 volumio go-librespot[1734]: time="2026-10-16T18:09:14+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Oct 16 18:09:14 volumio volumio[1208]: error: MPD error: The expression evaluated to a falsy value: Oct 16 18:09:14 volumio volumio[1208]: assert.ok(self.idling) Oct 16 18:09:14 volumio volumio[1208]: error: The expression evaluated to a falsy value: Oct 16 18:09:14 volumio volumio[1208]: assert.ok(self.idling) Oct 16 18:09:14 volumio go-librespot[1734]: time="2026-10-16T18:09:14+05:30" level=debug msg="completed keyexchange" Oct 16 18:09:14 volumio go-librespot[1734]: time="2026-10-16T18:09:14+05:30" level=debug msg="completed challenge" Oct 16 18:09:14 volumio volumio[1208]: error: updateQueue error: null Oct 16 18:09:14 volumio volumio[1208]: info: MPD running with PID1672 Oct 16 18:09:14 volumio volumio[1208]: ,establishing connection Oct 16 18:09:14 volumio go-librespot[1734]: time="2026-10-16T18:09:14+05:30" level=info msg="authenticated AP" username="31************************sq" Oct 16 18:09:15 volumio volumio[1208]: error: updateQueue error: null Oct 16 18:09:15 volumio go-librespot[1734]: time="2026-10-16T18:09:15+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 18:09:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 18:09:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 18:09:15 volumio volumio[1208]: info: go-librespot daemon successfully initialized Oct 16 18:09:17 volumio volumio[1208]: info: [yt-cast-receiver] DIAL server listening on port 8098 Oct 16 18:09:17 volumio volumio[1208]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 18:09:17 volumio volumio[1208]: info: VolumeController:: Volume=98 Mute =false Oct 16 18:09:17 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Oct 16 18:09:17 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:09:17 volumio volumio[1208]: info: CoreStateMachine::pushState Oct 16 18:09:17 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Oct 16 18:09:17 volumio volumio[1208]: info: CoreCommandRouter::volumioPushState Oct 16 18:09:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Oct 16 18:09:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 18:09:18 volumio volumio-remote-updater[796]: [2026-10-16 18:09:18] [connect] Successful connection Oct 16 18:09:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 18:09:18 volumio go-librespot[1801]: go-librespot daemon starting... Oct 16 18:09:18 volumio go-librespot[1802]: time="2026-10-16T18:09:18+05:30" level=info msg="running go-librespot 0.4.0" Oct 16 18:09:18 volumio go-librespot[1802]: time="2026-10-16T18:09:18+05:30" level=debug msg="app state loaded" Oct 16 18:09:18 volumio go-librespot[1802]: time="2026-10-16T18:09:18+05:30" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=info msg="zeroconf server listening on port 37673" Oct 16 18:09:19 volumio volumio[1208]: info: Completed starting Core Plugins Oct 16 18:09:19 volumio volumio[1208]: info: ------------------------------------------- Oct 16 18:09:19 volumio volumio[1208]: info: ----- MyVolumio plugins startup ---- Oct 16 18:09:19 volumio volumio[1208]: info: ------------------------------------------- Oct 16 18:09:19 volumio volumio[1208]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 18:09:19 volumio volumio[1208]: info: Initializing connection to go-librespot Websocket Oct 16 18:09:19 volumio volumio-remote-updater[796]: [2026-10-16 18:09:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792154358 101 Oct 16 18:09:19 volumio volumio[1208]: 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 Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="new websocket client" Oct 16 18:09:19 volumio volumio[1208]: info: Connection to go-librespot Websocket established Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="obtained new client token: AAHobJolbo7hqIJ4dxz1ytGKPXqdn3gKR0wWIjMhjuGj1DJxPW4+nv1rylJ3h0dU5a0VfG+BSli2NjID7AvuyIA0Sjae6sqrZfwqbfOdneyxmgP34DAvAsvrH0Mj66/62XjOTBFkIJyN6hH3q2iUN1Xr9xWUGqi43+/dL15P0KPFWWkwq4l1BzeoNtTJVQORGzMF3V1vJ3jQ8mId9q82NyZYa2XjhcD/enN4tXmRFWm26Janlc6VYpx2LA4=" Oct 16 18:09:19 volumio go-librespot[1802]: time="2026-10-16T18:09:19+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Oct 16 18:09:20 volumio go-librespot[1802]: time="2026-10-16T18:09:20+05:30" level=debug msg="completed keyexchange" Oct 16 18:09:20 volumio go-librespot[1802]: time="2026-10-16T18:09:20+05:30" level=debug msg="completed challenge" Oct 16 18:09:20 volumio go-librespot[1802]: time="2026-10-16T18:09:20+05:30" level=info msg="authenticated AP" username="31************************sq" Oct 16 18:09:20 volumio go-librespot[1802]: time="2026-10-16T18:09:20+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 18:09:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 18:09:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 18:09:20 volumio volumio[1208]: info: Connection to go-librespot Websocket closed Oct 16 18:09:22 volumio volumio[1208]: info: Getting Spotify volume Oct 16 18:09:22 volumio volumio[1208]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 18:09:22 volumio volumio[1208]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 18:09:22 volumio volumio[1208]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 16 18:09:22 volumio volumio[1208]: errno: -111, Oct 16 18:09:22 volumio volumio[1208]: code: 'ECONNREFUSED', Oct 16 18:09:22 volumio volumio[1208]: syscall: 'connect', Oct 16 18:09:22 volumio volumio[1208]: address: '127.0.0.1', Oct 16 18:09:22 volumio volumio[1208]: port: 9879, Oct 16 18:09:22 volumio volumio[1208]: response: undefined Oct 16 18:09:22 volumio volumio[1208]: } Oct 16 18:09:22 volumio volumio[1208]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 18:09:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Oct 16 18:09:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 18:09:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 18:09:23 volumio go-librespot[1827]: go-librespot daemon starting... Oct 16 18:09:23 volumio go-librespot[1828]: time="2026-10-16T18:09:23+05:30" level=info msg="running go-librespot 0.4.0" Oct 16 18:09:23 volumio go-librespot[1828]: time="2026-10-16T18:09:23+05:30" level=debug msg="app state loaded" Oct 16 18:09:23 volumio go-librespot[1828]: time="2026-10-16T18:09:23+05:30" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 18:09:24 volumio go-librespot[1828]: time="2026-10-16T18:09:24+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 16 18:09:24 volumio go-librespot[1828]: time="2026-10-16T18:09:24+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 16 18:09:24 volumio go-librespot[1828]: time="2026-10-16T18:09:24+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 16 18:09:24 volumio go-librespot[1828]: time="2026-10-16T18:09:24+05:30" level=info msg="zeroconf server listening on port 32915" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=debug msg="obtained new client token: AAGh7yq1Z+Ewl0VaRhJnXwjRevBHt8aJBUL6EaDi6Ts7dDM2N4XhLqqPhqUKdY2OeUFe3oI6RxmYV/ZMvcOldOgm2IraVqZm/cdiMnGbWyTolnE8yY7Ha+S/69LWF/XgGRk4xFrmxxOq+LcZZocZEivcJfJy3nTgTnpju0DmvBtkO5ylNKlZLyR5peXnbSuIxi6xeHA5O0r2v/fXZppFsHvCkQ/1eSk9RUQjjmCHzfscOIDpydzVbqAitNo=" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=debug msg="completed keyexchange" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=debug msg="completed challenge" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=info msg="authenticated AP" username="31************************sq" Oct 16 18:09:25 volumio go-librespot[1828]: time="2026-10-16T18:09:25+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 18:09:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 18:09:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 18:09:26 volumio sudo[1852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 18:08' Oct 16 18:09:26 volumio sudo[1852]: 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"