Jan 28 11:19:17 volumio-livingroom go-librespot[14456]: time="2026-01-28T11:19:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:34610->104.199.241.202:80: read: connection reset by peer" Jan 28 11:19:17 volumio-livingroom go-librespot[14456]: time="2026-01-28T11:19:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:34610->104.199.241.202:80: read: connection reset by peer" Jan 28 11:19:17 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:17 volumio-livingroom volumio[14266]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 28 11:19:17 volumio-livingroom volumio[14266]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 28 11:19:17 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:19:17 volumio-livingroom volumio[14266]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:17 volumio-livingroom volumio[14266]: Error: socket hang up Jan 28 11:19:17 volumio-livingroom volumio[14266]: at connResetException (node:internal/errors:720:14) Jan 28 11:19:17 volumio-livingroom volumio[14266]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:19:17 volumio-livingroom volumio[14266]: at Socket.emit (node:events:526:35) Jan 28 11:19:17 volumio-livingroom volumio[14266]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:19:17 volumio-livingroom volumio[14266]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:19:17 volumio-livingroom volumio[14266]: code: 'ECONNRESET', Jan 28 11:19:17 volumio-livingroom volumio[14266]: response: undefined Jan 28 11:19:17 volumio-livingroom volumio[14266]: } Jan 28 11:19:17 volumio-livingroom volumio[14266]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:17 volumio-livingroom sudo[15174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:18' Jan 28 11:19:17 volumio-livingroom sudo[15174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:17 volumio-livingroom sudo[15174]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:17 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:19:17 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:19:17 volumio-livingroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:17 volumio-livingroom systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:19:17 volumio-livingroom systemd[1]: volumio.service: Consumed 11.180s CPU time. Jan 28 11:19:17 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:17 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:17 volumio-livingroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 44. Jan 28 11:19:17 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:17 volumio-livingroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:19:17 volumio-livingroom systemd[1]: volumio.service: Consumed 11.180s CPU time. Jan 28 11:19:17 volumio-livingroom systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:19:17 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ----- Volumio3 ---- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ----- System startup ---- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: MYVOLUMIO Environment detected Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Plugin folders cleanup Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category audio_interface Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category miscellanea Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category music_service Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category plugins.json Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category system_controller Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category user_interface Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning into folder /data/plugins/ Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Scanning category music_service Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Plugin folders cleanup completed Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ----- Core plugins startup ---- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Loading plugins from folder /data/plugins/ Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Loading plugin "system"... Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Loading plugin "appearance"... Jan 28 11:19:18 volumio-livingroom volumio[15211]: info: Loading plugin "network"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Refreshing Cached IP Addresses Jan 28 11:19:19 volumio-livingroom sudo[15239]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:19:19 volumio-livingroom sudo[15239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:19 volumio-livingroom sudo[15241]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:19:19 volumio-livingroom sudo[15241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:19 volumio-livingroom sudo[15239]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:19 volumio-livingroom sudo[15241]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "services"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "alsa_controller"... Jan 28 11:19:19 volumio-livingroom sudo[15258]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:19:19 volumio-livingroom sudo[15258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "wizard"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "networkfs"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Starting Udev Watcher for removable devices Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Ignoring mount for partition: boot Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Ignoring mount for partition: volumio Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Ignoring mount for partition: volumio_data Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "upnp"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: [1769595559070] Starting Upmpd Daemon Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "my_music"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "mpd"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "upnp_browser"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Starting UPNP Browser Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "alarm-clock"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "airplay_emulation"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Starting Shairport Sync Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "last_100"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "webradio"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "i2s_dacs"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "volumiodiscovery"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** For more information see Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:19 volumio-livingroom volumio[15211]: *** WARNING *** For more information see Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** For more information see Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:19 volumio-livingroom node[15211]: *** WARNING *** For more information see Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Discovery: Started advertising with name: Volumio LivingRoom Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "spop"... Jan 28 11:19:19 volumio-livingroom volumio[15211]: info: Loading plugin "ytcr"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "ytmusic"... Jan 28 11:19:20 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:20 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:20 volumio-livingroom go-librespot[15274]: go-librespot daemon starting... Jan 28 11:19:20 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:20+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:20 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:20+01:00" level=debug msg="app state loaded" Jan 28 11:19:20 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "outputs"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "albumart"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Plugin example_plugin is not enabled Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "inputs"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "updater_comm"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Plugin mpdemulation is not enabled Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "rest_api"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading plugin "websocket"... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Loading i18n strings for locale en Jan 28 11:19:20 volumio-livingroom volumio[15211]: Updating browse sources language Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::initPlayerControls Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: Express server listening on port 3000 Jan 28 11:19:20 volumio-livingroom volumio[15211]: [Metrics] WebUI: 2s 313.58ms Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::resetVolumioState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::getcurrentVolume Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Volumio Network Manager: Network status updated: 2 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Reloading queue from file Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::pushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::updateTrackBlock Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrackBlock Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::pushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::setRandom null Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::pushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Setting Device type: Raspberry PI Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: USB Boot Capable - System SBC Revision found in cpuinfo: e04171 Jan 28 11:19:20 volumio-livingroom volumio[15281]: Forking 3 albumart workers Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Completed loading Core Plugins Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Preparing to generate the ALSA configuration file Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreStateMachine::pushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Output device has changed, restarting MPD Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Output device has changed, restarting Shairport Sync Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:20 volumio-livingroom sudo[15338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:20 volumio-livingroom sudo[15338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:20 volumio-livingroom sudo[15341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:20 volumio-livingroom sudo[15341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:20 volumio-livingroom sudo[15338]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: ___________ START PLUGINS ___________ Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Creating MPD Configuration file Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: [1769595560869] CoreMusicLibrary::Adding element Media Servers Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:20 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:19:20 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:19:20 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: UPNP Browser: Client initialized successfully Jan 28 11:19:20 volumio-livingroom sudo[15349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:20 volumio-livingroom sudo[15351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:20 volumio-livingroom sudo[15351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:20 volumio-livingroom sudo[15349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:20 volumio-livingroom sudo[15349]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:20 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:19:20 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:19:20 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:19:20 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:19:20 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:19:20 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: [1769595560937] CoreMusicLibrary::Adding element Last_100 Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: [1769595560939] CoreMusicLibrary::Adding element Webradio Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:20 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:20 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:19:20 volumio-livingroom volumio[15211]: info: Initializing BBC Radios Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:21 volumio-livingroom sudo[15365]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:19:21 volumio-livingroom sudo[15365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Creating Spotify config file Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom sudo[15365]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:21+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]" Jan 28 11:19:21 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:21+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]" Jan 28 11:19:21 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:21+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]" Jan 28 11:19:21 volumio-livingroom go-librespot[15275]: time="2026-01-28T11:19:21+01:00" level=info msg="zeroconf server listening on port 35187" Jan 28 11:19:21 volumio-livingroom volumio[15303]: Starting albumart workers Jan 28 11:19:21 volumio-livingroom volumio[15305]: Starting albumart workers Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: [1769595561273] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:21 volumio-livingroom volumio[15211]: Cannot find translation for source YouTube Music Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Volumio Calling Home Jan 28 11:19:21 volumio-livingroom volumio[15304]: Starting albumart workers Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Discovery: adding 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: MPD Permissions set Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: MPD Permissions set Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Spotify config file written Jan 28 11:19:21 volumio-livingroom sudo[15387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:19:21 volumio-livingroom sudo[15387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:21 volumio-livingroom volumio[15211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:19:21 volumio-livingroom systemd[1]: go-librespot-daemon.service: Killing process 15277 (go-librespot) with signal SIGKILL. Jan 28 11:19:21 volumio-livingroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:21 volumio-livingroom go-librespot[15389]: go-librespot daemon starting... Jan 28 11:19:21 volumio-livingroom sudo[15387]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:21+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:21 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:21+01:00" level=debug msg="app state loaded" Jan 28 11:19:21 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: No need to fix Spotify hosts Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Starting Shairport Sync Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Starting Shairport Sync Jan 28 11:19:21 volumio-livingroom sudo[15413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:21 volumio-livingroom sudo[15413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Starting Shairport Sync Jan 28 11:19:21 volumio-livingroom sudo[15418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:21 volumio-livingroom sudo[15418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:19:21 volumio-livingroom systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:21 volumio-livingroom systemd[1]: shairport-sync.service: Consumed 1.834s CPU time. Jan 28 11:19:21 volumio-livingroom sudo[15424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:21 volumio-livingroom sudo[15424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:21 volumio-livingroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:21 volumio-livingroom sudo[15413]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Shairport-Sync Started Jan 28 11:19:21 volumio-livingroom volumio[15211]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:19:21 volumio-livingroom systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:19:21 volumio-livingroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:21 volumio-livingroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:21 volumio-livingroom sudo[15424]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom sudo[15418]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Volumio called home Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Shairport-Sync Started Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Shairport-Sync Started Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:21 volumio-livingroom mpd[15380]: 2026-01-28T11:19:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Discovery: this is already registered, 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:21 volumio-livingroom systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:21 volumio-livingroom sudo[15351]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom sudo[15341]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:21 volumio-livingroom volumio[15211]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:19:21 volumio-livingroom volumio[15211]: assert.ok(self.idling) Jan 28 11:19:21 volumio-livingroom volumio[15211]: error: The expression evaluated to a falsy value: Jan 28 11:19:21 volumio-livingroom volumio[15211]: assert.ok(self.idling) Jan 28 11:19:21 volumio-livingroom volumio[15211]: error: updateQueue error: null Jan 28 11:19:21 volumio-livingroom volumio[15211]: info: MPD running with PID15380 Jan 28 11:19:21 volumio-livingroom volumio[15211]: ,establishing connection Jan 28 11:19:21 volumio-livingroom volumio[15211]: error: updateQueue error: null Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+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]" Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+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]" Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+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]" Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+01:00" level=info msg="zeroconf server listening on port 41343" Jan 28 11:19:22 volumio-livingroom sudo[15258]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+01:00" level=debug msg="obtained new client token: AADOCHDZctd+Ym4qmmwtQeoY6pq8zMtknIzam6PojuwFrMlLhDOYe81Ezel4xticUcKVzBVqSbJYwWrjhdDjZJJu9tD/VuK2LzmPAX473KXsLZwVaZLB8VOJMkWEkoEVF4yZapvdCJjnBk7qMEkeXBjAwzNmi56+0CY8vdk8zxeL2ZBeB551I0uv/mbcBEGJL1Bk1oEMSUATE8XidtTQwcUO8JO7JQQUGMSb4m1ABnnyhqXoHdYh5XgJ" Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:22 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:22+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:44314->104.199.65.9:4070: read: connection reset by peer" Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CoreStateMachine::pushState Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: Completed starting Core Plugins Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: ----- MyVolumio plugins startup ---- Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: ------------------------------------------- Jan 28 11:19:22 volumio-livingroom volumio[15211]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:19:22 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:22] [connect] Successful connection Jan 28 11:19:22 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769595562 101 Jan 28 11:19:22 volumio-livingroom volumio[15211]: 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 Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:40578->104.199.65.9:443: read: connection reset by peer" Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=debug msg="completed challenge" Jan 28 11:19:23 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:23+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:24 volumio-livingroom volumio[15211]: info: go-librespot daemon successfully initialized Jan 28 11:19:24 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:24+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 11:19:24 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:24+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:24 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:24+01:00" level=debug msg="completed challenge" Jan 28 11:19:24 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:24+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:25 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 28 11:19:25 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:25+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:25 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:25+01:00" level=debug msg="completed challenge" Jan 28 11:19:25 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:26 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:26+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:19:26 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:36922->104.199.241.202:80: read: connection reset by peer" Jan 28 11:19:26 volumio-livingroom go-librespot[15395]: time="2026-01-28T11:19:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:36922->104.199.241.202:80: read: connection reset by peer" Jan 28 11:19:26 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:26 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:19:26 volumio-livingroom volumio[15211]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:19:27 volumio-livingroom volumio[15211]: info: Initializing connection to go-librespot Websocket Jan 28 11:19:27 volumio-livingroom volumio[15211]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:19:29 volumio-livingroom sudo[15487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:19:29 volumio-livingroom sudo[15487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:29 volumio-livingroom sudo[15489]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:19:29 volumio-livingroom sudo[15487]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:29 volumio-livingroom sudo[15489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:29 volumio-livingroom sudo[15489]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:29 volumio-livingroom sudo[15493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:19:29 volumio-livingroom sudo[15493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:29 volumio-livingroom sudo[15493]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:29 volumio-livingroom volumio[15211]: info: Upmpdcli Daemon Started Jan 28 11:19:29 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:19:29 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:29 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:29 volumio-livingroom go-librespot[15495]: go-librespot daemon starting... Jan 28 11:19:29 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:29+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:29 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:29+01:00" level=debug msg="app state loaded" Jan 28 11:19:29 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+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]" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+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]" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+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]" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+01:00" level=info msg="zeroconf server listening on port 33773" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+01:00" level=debug msg="obtained new client token: AAAsEw0fx7WvHGE1Pfo/WiReDcRILatRWyeh+f0COVDy2fqiNbFkuoGycAG6jQi+0paXhLrbu6Kfpl17mMJU8gjxVm4BEET/JLvAqX5ZKtCvBlu6xq7jIceeHLBvTR/uV5JVXpsx3kMY5Z0M+IuaZMjDoXmfd7oz3nY7gf3KK/BYyB76B4ndiPeru5SoeDy2f6M3SHifYVCOYbKH3zPfiKZ6lucQKD8CXaZB4TcnCwNErggZsmW9tYf0" Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:30 volumio-livingroom volumio[15211]: info: Initializing connection to go-librespot Websocket Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+01:00" level=debug msg="new websocket client" Jan 28 11:19:30 volumio-livingroom volumio[15211]: info: Connection to go-librespot Websocket established Jan 28 11:19:30 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:30+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:33852->104.199.65.9:4070: read: connection reset by peer" Jan 28 11:19:31 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:31+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:19:31 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:31+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:31 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:31+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:19:32 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:32+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:37836->104.199.65.9:80: read: connection reset by peer" Jan 28 11:19:32 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:32+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 11:19:33 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:33+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:33 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:33+01:00" level=debug msg="completed challenge" Jan 28 11:19:33 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:33+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: Getting Spotify volume Jan 28 11:19:33 volumio-livingroom volumio[15211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:33 volumio-livingroom volumio[15211]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Jan 28 11:19:33 volumio-livingroom volumio[15211]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:19:33 volumio-livingroom volumio[15211]: SPOTIFY: VOLUMIO VOLUME 50 Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:33 volumio-livingroom volumio[15211]: info: Setting Spotify Volume from Volumio: 50 Jan 28 11:19:33 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 28 11:19:34 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:34+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:34 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:34+01:00" level=debug msg="completed challenge" Jan 28 11:19:34 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:35 volumio-livingroom volumio[15211]: SPOTIFY: SETTING SPOTIFY VOLUME 50 Jan 28 11:19:35 volumio-livingroom volumio[15211]: info: Sending Spotify command with payload to local API: /player/volume Jan 28 11:19:35 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:35+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:19:35 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:35+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:35 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:35+01:00" level=debug msg="completed challenge" Jan 28 11:19:36 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:36+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:36 volumio-livingroom go-librespot[15496]: time="2026-01-28T11:19:36+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 " Jan 28 11:19:36 volumio-livingroom volumio[15211]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 28 11:19:36 volumio-livingroom volumio[15211]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:36 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:36 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:19:36 volumio-livingroom volumio[15211]: Error: socket hang up Jan 28 11:19:36 volumio-livingroom volumio[15211]: at connResetException (node:internal/errors:720:14) Jan 28 11:19:36 volumio-livingroom volumio[15211]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:19:36 volumio-livingroom volumio[15211]: at Socket.emit (node:events:526:35) Jan 28 11:19:36 volumio-livingroom volumio[15211]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:19:36 volumio-livingroom volumio[15211]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:19:36 volumio-livingroom volumio[15211]: code: 'ECONNRESET', Jan 28 11:19:36 volumio-livingroom volumio[15211]: response: undefined Jan 28 11:19:36 volumio-livingroom volumio[15211]: } Jan 28 11:19:36 volumio-livingroom volumio[15211]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:36 volumio-livingroom sudo[15519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:18' Jan 28 11:19:36 volumio-livingroom sudo[15519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:36 volumio-livingroom sudo[15519]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:36 volumio-livingroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:36 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:19:36 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:19:36 volumio-livingroom systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:19:36 volumio-livingroom systemd[1]: volumio.service: Consumed 7.963s CPU time. Jan 28 11:19:36 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:36 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:36 volumio-livingroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 45. Jan 28 11:19:36 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:36 volumio-livingroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:19:36 volumio-livingroom systemd[1]: volumio.service: Consumed 7.963s CPU time. Jan 28 11:19:36 volumio-livingroom systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:19:36 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ----- Volumio3 ---- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ----- System startup ---- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: MYVOLUMIO Environment detected Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Plugin folders cleanup Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category audio_interface Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category miscellanea Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category music_service Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category plugins.json Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category system_controller Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category user_interface Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning into folder /data/plugins/ Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Scanning category music_service Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Plugin folders cleanup completed Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ----- Core plugins startup ---- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugins from folder /data/plugins/ Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "system"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "appearance"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "network"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Refreshing Cached IP Addresses Jan 28 11:19:37 volumio-livingroom sudo[15569]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:19:37 volumio-livingroom sudo[15569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:37 volumio-livingroom sudo[15571]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:19:37 volumio-livingroom sudo[15571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:37 volumio-livingroom sudo[15569]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:37 volumio-livingroom sudo[15571]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "services"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "alsa_controller"... Jan 28 11:19:37 volumio-livingroom sudo[15580]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:19:37 volumio-livingroom sudo[15580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "wizard"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "networkfs"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Starting Udev Watcher for removable devices Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Ignoring mount for partition: boot Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Ignoring mount for partition: volumio Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Ignoring mount for partition: volumio_data Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "upnp"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: [1769595577886] Starting Upmpd Daemon Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "my_music"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "mpd"... Jan 28 11:19:37 volumio-livingroom volumio[15541]: info: Loading plugin "upnp_browser"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Starting UPNP Browser Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "alarm-clock"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "airplay_emulation"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Starting Shairport Sync Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "last_100"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "webradio"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "i2s_dacs"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "volumiodiscovery"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** For more information see Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** For more information see Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:38 volumio-livingroom volumio[15541]: *** WARNING *** For more information see Jan 28 11:19:38 volumio-livingroom node[15541]: *** WARNING *** For more information see Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Discovery: Started advertising with name: Volumio LivingRoom Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "spop"... Jan 28 11:19:38 volumio-livingroom volumio[15541]: info: Loading plugin "ytcr"... Jan 28 11:19:39 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:19:39 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "ytmusic"... Jan 28 11:19:39 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:39 volumio-livingroom go-librespot[15604]: go-librespot daemon starting... Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+01:00" level=debug msg="app state loaded" Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "outputs"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "albumart"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Plugin example_plugin is not enabled Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "inputs"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "updater_comm"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Plugin mpdemulation is not enabled Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "rest_api"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading plugin "websocket"... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Loading i18n strings for locale en Jan 28 11:19:39 volumio-livingroom volumio[15541]: Updating browse sources language Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::initPlayerControls Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: Express server listening on port 3000 Jan 28 11:19:39 volumio-livingroom volumio[15541]: [Metrics] WebUI: 2s 337.63ms Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::resetVolumioState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::getcurrentVolume Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Volumio Network Manager: Network status updated: 2 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Reloading queue from file Jan 28 11:19:39 volumio-livingroom volumio[15611]: Forking 3 albumart workers Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::pushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::updateTrackBlock Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrackBlock Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::pushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::setRandom null Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::pushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Setting Device type: Raspberry PI Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Completed loading Core Plugins Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Preparing to generate the ALSA configuration file Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: USB Boot Capable - System SBC Revision found in cpuinfo: e04171 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreStateMachine::pushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Output device has changed, restarting MPD Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Output device has changed, restarting Shairport Sync Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:39 volumio-livingroom sudo[15670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:39 volumio-livingroom sudo[15670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:39 volumio-livingroom sudo[15670]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:39 volumio-livingroom sudo[15672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:39 volumio-livingroom sudo[15672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: ___________ START PLUGINS ___________ Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Creating MPD Configuration file Jan 28 11:19:39 volumio-livingroom systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: [1769595579711] CoreMusicLibrary::Adding element Media Servers Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:39 volumio-livingroom sudo[15682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:39 volumio-livingroom sudo[15682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:39 volumio-livingroom sudo[15680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:39 volumio-livingroom sudo[15680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:39 volumio-livingroom sudo[15680]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: UPNP Browser: Client initialized successfully Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:39 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:19:39 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:19:39 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:19:39 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:19:39 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: [1769595579765] CoreMusicLibrary::Adding element Last_100 Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: [1769595579766] CoreMusicLibrary::Adding element Webradio Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:39 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:19:39 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Initializing BBC Radios Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: Creating Spotify config file Jan 28 11:19:39 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:39 volumio-livingroom sudo[15694]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:19:39 volumio-livingroom sudo[15694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:19:39 volumio-livingroom sudo[15694]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+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]" Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+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]" Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+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]" Jan 28 11:19:39 volumio-livingroom go-librespot[15605]: time="2026-01-28T11:19:39+01:00" level=info msg="zeroconf server listening on port 42649" Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: [1769595580022] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:40 volumio-livingroom volumio[15541]: Cannot find translation for source YouTube Music Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Volumio Calling Home Jan 28 11:19:40 volumio-livingroom volumio[15634]: Starting albumart workers Jan 28 11:19:40 volumio-livingroom volumio[15633]: Starting albumart workers Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Discovery: adding 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Discovery: this is already registered, 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:40 volumio-livingroom volumio[15632]: Starting albumart workers Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: MPD Permissions set Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: MPD Permissions set Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Spotify config file written Jan 28 11:19:40 volumio-livingroom sudo[15717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:19:40 volumio-livingroom sudo[15717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:40 volumio-livingroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:19:40 volumio-livingroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:19:40 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:40 volumio-livingroom volumio[15541]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:40 volumio-livingroom go-librespot[15719]: go-librespot daemon starting... Jan 28 11:19:40 volumio-livingroom sudo[15717]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+01:00" level=debug msg="app state loaded" Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: No need to fix Spotify hosts Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Starting Shairport Sync Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Starting Shairport Sync Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Starting Shairport Sync Jan 28 11:19:40 volumio-livingroom sudo[15741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:40 volumio-livingroom sudo[15741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:40 volumio-livingroom sudo[15737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:40 volumio-livingroom sudo[15737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:40 volumio-livingroom sudo[15739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:40 volumio-livingroom sudo[15739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:40 volumio-livingroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:19:40 volumio-livingroom systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:19:40 volumio-livingroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:40 volumio-livingroom systemd[1]: shairport-sync.service: Consumed 1.545s CPU time. Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Volumio called home Jan 28 11:19:40 volumio-livingroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:40 volumio-livingroom sudo[15739]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom sudo[15737]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom sudo[15741]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Shairport-Sync Started Jan 28 11:19:40 volumio-livingroom volumio[15541]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Shairport-Sync Started Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: Shairport-Sync Started Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:40 volumio-livingroom mpd[15709]: 2026-01-28T11:19:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:19:40 volumio-livingroom systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:19:40 volumio-livingroom sudo[15682]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom sudo[15672]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+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]" Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+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]" Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+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]" Jan 28 11:19:40 volumio-livingroom volumio[15541]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:19:40 volumio-livingroom volumio[15541]: assert.ok(self.idling) Jan 28 11:19:40 volumio-livingroom volumio[15541]: error: The expression evaluated to a falsy value: Jan 28 11:19:40 volumio-livingroom volumio[15541]: assert.ok(self.idling) Jan 28 11:19:40 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:40+01:00" level=info msg="zeroconf server listening on port 43089" Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: MPD running with PID15709 Jan 28 11:19:40 volumio-livingroom volumio[15541]: ,establishing connection Jan 28 11:19:40 volumio-livingroom volumio[15541]: error: updateQueue error: null Jan 28 11:19:40 volumio-livingroom volumio[15541]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 11:19:40 volumio-livingroom volumio[15541]: error: updateQueue error: null Jan 28 11:19:41 volumio-livingroom sudo[15580]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=debug msg="obtained new client token: AAANDY448H6dYo58VDtlAx9ulMBsVJVM+g4uk2QWjQjDU1GCGDTEpEH4LcpfQG3JwhpKHolnKTFVY61VhZ0iidAdU4jdaNiLWw+RnhW9V47liXrSIZ5eqtmv2d0PAuEq8M4Kv0YOiQnIRsn3wiSBED8r8mGfTZ6wHcJQrTrBAESbC9zGp7gSx7YcbAxvC8/Kbf5AQgnYHRuMUt+aBxyGS5ZYCCs0qsNf60FmNvsR7r1+wy9o7Q8cLA==" Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:40436->104.199.65.9:4070: read: connection reset by peer" Jan 28 11:19:41 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:41] [connect] Successful connection Jan 28 11:19:41 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769595581 101 Jan 28 11:19:41 volumio-livingroom volumio[15541]: 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 Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CoreStateMachine::pushState Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: Completed starting Core Plugins Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: ----- MyVolumio plugins startup ---- Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: ------------------------------------------- Jan 28 11:19:41 volumio-livingroom volumio[15541]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=debug msg="completed challenge" Jan 28 11:19:41 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:41+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:42 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:19:42 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:42+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:40002->104.199.65.9:80: read: connection reset by peer" Jan 28 11:19:43 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:43+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 11:19:43 volumio-livingroom volumio[15541]: info: go-librespot daemon successfully initialized Jan 28 11:19:43 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:43+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:43 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:43+01:00" level=debug msg="completed challenge" Jan 28 11:19:43 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:44 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 28 11:19:44 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:44+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:44 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:44+01:00" level=debug msg="completed challenge" Jan 28 11:19:44 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:45 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:45+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:19:45 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:45+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:45 volumio-livingroom go-librespot[15725]: time="2026-01-28T11:19:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:45 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:45 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:19:45 volumio-livingroom volumio[15541]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:19:46 volumio-livingroom volumio[15541]: info: Initializing connection to go-librespot Websocket Jan 28 11:19:46 volumio-livingroom volumio[15541]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:19:47 volumio-livingroom sudo[15804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:19:47 volumio-livingroom sudo[15804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:47 volumio-livingroom sudo[15806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:19:47 volumio-livingroom sudo[15804]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:47 volumio-livingroom sudo[15806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:47 volumio-livingroom sudo[15806]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:47 volumio-livingroom sudo[15810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:19:47 volumio-livingroom sudo[15810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:47 volumio-livingroom sudo[15810]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:47 volumio-livingroom volumio[15541]: info: Upmpdcli Daemon Started Jan 28 11:19:48 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:19:48 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:48 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:48 volumio-livingroom go-librespot[15812]: go-librespot daemon starting... Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+01:00" level=debug msg="app state loaded" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+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]" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+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]" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+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]" Jan 28 11:19:48 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:48+01:00" level=info msg="zeroconf server listening on port 40385" Jan 28 11:19:49 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:49+01:00" level=debug msg="obtained new client token: AABk4HaKosSDhDWbhXt8WKvOqV1pPzadYLGjCxZsaNfxK4YCKageSZZDexydeUyP+vugYOa3TeFQZivbbG8uH0a0rZD6aBAtSRmJZXW96OAGj7NJ/0nenly0HWlAklJWstGvPT9MFo7icBpYDLxHsQe0GsQesKpWHw+FtVKCYNvW5FolJlxVNPDH6a86ExMh+FR8JPoCFxmVfm25EJvna1rBOARavuAi5seTMI5d3YuLLb9C5SNOsA==" Jan 28 11:19:49 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:49+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:49 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:49+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:49 volumio-livingroom volumio[15541]: info: Initializing connection to go-librespot Websocket Jan 28 11:19:49 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:49+01:00" level=debug msg="new websocket client" Jan 28 11:19:49 volumio-livingroom volumio[15541]: info: Connection to go-librespot Websocket established Jan 28 11:19:49 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:49+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" Jan 28 11:19:50 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:19:50 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:50+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:50 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:50+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 11:19:50 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:50+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:50 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:50+01:00" level=debug msg="completed challenge" Jan 28 11:19:51 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:51+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:51 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:51+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" Jan 28 11:19:52 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:52+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:19:52 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:52+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:52 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:52+01:00" level=debug msg="completed challenge" Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: Getting Spotify volume Jan 28 11:19:52 volumio-livingroom volumio[15541]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:52 volumio-livingroom volumio[15541]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Jan 28 11:19:52 volumio-livingroom volumio[15541]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:19:52 volumio-livingroom volumio[15541]: SPOTIFY: VOLUMIO VOLUME 50 Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:52 volumio-livingroom volumio[15541]: info: Setting Spotify Volume from Volumio: 50 Jan 28 11:19:52 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:53 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:53+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:53 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:53+01:00" level=debug msg="completed keyexchange" Jan 28 11:19:53 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:53+01:00" level=debug msg="completed challenge" Jan 28 11:19:53 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:19:53 volumio-livingroom volumio[15541]: SPOTIFY: SETTING SPOTIFY VOLUME 50 Jan 28 11:19:53 volumio-livingroom volumio[15541]: info: Sending Spotify command with payload to local API: /player/volume Jan 28 11:19:53 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:53+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" Jan 28 11:19:54 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:54+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:19:54 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:57434->104.199.65.9:80: read: connection reset by peer" Jan 28 11:19:54 volumio-livingroom go-librespot[15813]: time="2026-01-28T11:19:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:57434->104.199.65.9:80: read: connection reset by peer" Jan 28 11:19:54 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:54 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:19:54 volumio-livingroom volumio[15541]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 28 11:19:54 volumio-livingroom volumio[15541]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:54 volumio-livingroom volumio[15541]: Error: socket hang up Jan 28 11:19:54 volumio-livingroom volumio[15541]: at connResetException (node:internal/errors:720:14) Jan 28 11:19:54 volumio-livingroom volumio[15541]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:19:54 volumio-livingroom volumio[15541]: at Socket.emit (node:events:526:35) Jan 28 11:19:54 volumio-livingroom volumio[15541]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:19:54 volumio-livingroom volumio[15541]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:19:54 volumio-livingroom volumio[15541]: code: 'ECONNRESET', Jan 28 11:19:54 volumio-livingroom volumio[15541]: response: undefined Jan 28 11:19:54 volumio-livingroom volumio[15541]: } Jan 28 11:19:54 volumio-livingroom volumio[15541]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:19:54 volumio-livingroom sudo[15836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:18' Jan 28 11:19:54 volumio-livingroom sudo[15836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:54 volumio-livingroom sudo[15836]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:54 volumio-livingroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:19:54 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:19:54 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:19:54 volumio-livingroom systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:19:54 volumio-livingroom systemd[1]: volumio.service: Consumed 8.061s CPU time. Jan 28 11:19:54 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:54 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:54 volumio-livingroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 46. Jan 28 11:19:54 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:19:54 volumio-livingroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:19:54 volumio-livingroom systemd[1]: volumio.service: Consumed 8.061s CPU time. Jan 28 11:19:54 volumio-livingroom systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:19:54 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ----- Volumio3 ---- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ----- System startup ---- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: MYVOLUMIO Environment detected Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Plugin folders cleanup Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category audio_interface Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category miscellanea Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category music_service Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category plugins.json Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category system_controller Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category user_interface Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning into folder /data/plugins/ Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Scanning category music_service Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Plugin folders cleanup completed Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ----- Core plugins startup ---- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Loading plugins from folder /data/plugins/ Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Loading plugin "system"... Jan 28 11:19:55 volumio-livingroom volumio[15849]: info: Loading plugin "appearance"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "network"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Refreshing Cached IP Addresses Jan 28 11:19:56 volumio-livingroom sudo[15877]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:19:56 volumio-livingroom sudo[15877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:56 volumio-livingroom sudo[15877]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:56 volumio-livingroom sudo[15879]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:19:56 volumio-livingroom sudo[15879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:56 volumio-livingroom sudo[15879]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "services"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "alsa_controller"... Jan 28 11:19:56 volumio-livingroom sudo[15887]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:19:56 volumio-livingroom sudo[15887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "wizard"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "networkfs"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Starting Udev Watcher for removable devices Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Ignoring mount for partition: boot Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Ignoring mount for partition: volumio Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Ignoring mount for partition: volumio_data Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "upnp"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: [1769595596127] Starting Upmpd Daemon Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "my_music"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "mpd"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "upnp_browser"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Starting UPNP Browser Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "alarm-clock"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "airplay_emulation"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Starting Shairport Sync Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "last_100"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "webradio"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "i2s_dacs"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "volumiodiscovery"... Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** For more information see Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:56 volumio-livingroom volumio[15849]: *** WARNING *** For more information see Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** For more information see Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:19:56 volumio-livingroom node[15849]: *** WARNING *** For more information see Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Discovery: Started advertising with name: Volumio LivingRoom Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:19:56 volumio-livingroom volumio[15849]: info: Loading plugin "spop"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "ytcr"... Jan 28 11:19:57 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:19:57 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:57 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:57 volumio-livingroom go-librespot[15912]: go-librespot daemon starting... Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+01:00" level=debug msg="app state loaded" Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "ytmusic"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "outputs"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "albumart"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Plugin example_plugin is not enabled Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "inputs"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "updater_comm"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Plugin mpdemulation is not enabled Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "rest_api"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading plugin "websocket"... Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Loading i18n strings for locale en Jan 28 11:19:57 volumio-livingroom volumio[15849]: Updating browse sources language Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::initPlayerControls Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: Express server listening on port 3000 Jan 28 11:19:57 volumio-livingroom volumio[15849]: [Metrics] WebUI: 2s 336.94ms Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::resetVolumioState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::getcurrentVolume Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Volumio Network Manager: Network status updated: 2 Jan 28 11:19:57 volumio-livingroom volumio[15920]: Forking 3 albumart workers Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Reloading queue from file Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::pushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::updateTrackBlock Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrackBlock Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::pushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::setRandom null Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::pushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Setting Device type: Raspberry PI Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Completed loading Core Plugins Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Preparing to generate the ALSA configuration file Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: USB Boot Capable - System SBC Revision found in cpuinfo: e04171 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreStateMachine::pushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Output device has changed, restarting MPD Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+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]" Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+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]" Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+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]" Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Output device has changed, restarting Shairport Sync Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:57 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:57+01:00" level=info msg="zeroconf server listening on port 43903" Jan 28 11:19:57 volumio-livingroom sudo[15979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:57 volumio-livingroom sudo[15979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:57 volumio-livingroom sudo[15981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:57 volumio-livingroom sudo[15981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:57 volumio-livingroom sudo[15979]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: ___________ START PLUGINS ___________ Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:19:57 volumio-livingroom volumio[15849]: info: Creating MPD Configuration file Jan 28 11:19:57 volumio-livingroom systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:19:57 volumio-livingroom sudo[15990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:19:57 volumio-livingroom sudo[15990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: [1769595598002] CoreMusicLibrary::Adding element Media Servers Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:58 volumio-livingroom sudo[15990]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom sudo[15992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:19:58 volumio-livingroom sudo[15992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:19:58 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: UPNP Browser: Client initialized successfully Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:58 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:58 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:19:58 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:19:58 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:58 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: [1769595598063] CoreMusicLibrary::Adding element Last_100 Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:58 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: [1769595598072] CoreMusicLibrary::Adding element Webradio Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:58 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Initializing BBC Radios Jan 28 11:19:58 volumio-livingroom sudo[16006]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:19:58 volumio-livingroom sudo[16006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:19:58 volumio-livingroom sudo[16006]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Creating Spotify config file Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15936]: Starting albumart workers Jan 28 11:19:58 volumio-livingroom volumio[15939]: Starting albumart workers Jan 28 11:19:58 volumio-livingroom volumio[15938]: Starting albumart workers Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: [1769595598345] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:19:58 volumio-livingroom volumio[15849]: Cannot find translation for source YouTube Music Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Volumio Calling Home Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Discovery: adding 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Discovery: this is already registered, 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: MPD Permissions set Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: MPD Permissions set Jan 28 11:19:58 volumio-livingroom volumio[15849]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Spotify config file written Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom sudo[16039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:58 volumio-livingroom sudo[16039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom go-librespot[15913]: time="2026-01-28T11:19:58+01:00" level=debug msg="obtained new client token: AACwuaD3DWTiowjOyOTpsPeCp2WK5N5jI7htJ4CN6bfsIxo/HYuI7PiXoMimxoXyOSveQ0ve3zvFk2Kw+noTBt39i9Ns/rlW8ogOokUiCekG6NwinLp+r8TjGKLOJ9Sitg3Pc+Fyc4VDLr3KbNKWMeNmN5E1gGIHQdLZoXVEDjahgTeqrsQg6hAqIPeDR6lC0zZw6mbJOOO7isr72iaE/6GiExILpl/Qjs14RiBENmnMa8c4r/cb9RPw" Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:19:58 volumio-livingroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: No need to fix Spotify hosts Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Starting Shairport Sync Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Starting Shairport Sync Jan 28 11:19:58 volumio-livingroom sudo[16059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:58 volumio-livingroom sudo[16059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Starting Shairport Sync Jan 28 11:19:58 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:19:58 volumio-livingroom go-librespot[16057]: go-librespot daemon starting... Jan 28 11:19:58 volumio-livingroom sudo[16039]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom sudo[16065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:58 volumio-livingroom sudo[16065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom sudo[16062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:19:58 volumio-livingroom sudo[16062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:19:58 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:58+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:19:58 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:58+01:00" level=debug msg="app state loaded" Jan 28 11:19:58 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:19:58 volumio-livingroom systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:19:58 volumio-livingroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:58 volumio-livingroom systemd[1]: shairport-sync.service: Consumed 1.536s CPU time. Jan 28 11:19:58 volumio-livingroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:19:58 volumio-livingroom sudo[16065]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom sudo[16062]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom sudo[16059]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Volumio called home Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Shairport-Sync Started Jan 28 11:19:58 volumio-livingroom volumio[15849]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Shairport-Sync Started Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: Shairport-Sync Started Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:58 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:58 volumio-livingroom mpd[16019]: 2026-01-28T11:19:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:19:58 volumio-livingroom systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:19:58 volumio-livingroom sudo[15992]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:58 volumio-livingroom sudo[15981]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:59 volumio-livingroom volumio[15849]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:19:59 volumio-livingroom volumio[15849]: assert.ok(self.idling) Jan 28 11:19:59 volumio-livingroom volumio[15849]: error: The expression evaluated to a falsy value: Jan 28 11:19:59 volumio-livingroom volumio[15849]: assert.ok(self.idling) Jan 28 11:19:59 volumio-livingroom volumio[15849]: error: updateQueue error: null Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: MPD running with PID16019 Jan 28 11:19:59 volumio-livingroom volumio[15849]: ,establishing connection Jan 28 11:19:59 volumio-livingroom volumio[15849]: error: updateQueue error: null Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 11:19:59 volumio-livingroom sudo[15887]: pam_unix(sudo:session): session closed for user root Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19: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]" Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19: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]" Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19: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]" Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:59+01:00" level=info msg="zeroconf server listening on port 41105" Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:59+01:00" level=debug msg="obtained new client token: AABppb5Q8nquDD4lo1YfMVSWgH9UGM/CK/0sx6u9CP1JkfEN9enM+BdjIutM32cMpZ5g1wLLBBIoaN3vlFnIyJHd8TEoqE+HxHndxXHBl6EhIQHpZSOBDaWyMyK9ltKlD6QTFKKeeORNyavR/zOkfvTySLauVsJUMjpF58c92nyCPmw38RXKW5dx3na4o+yiGXW9dXg3qDxulNmObOu1y3I7DLsZ14bASFNKFNOl+CoFDv9gt6Fz4Wr/" Jan 28 11:19:59 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:59] [connect] Successful connection Jan 28 11:19:59 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:19:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769595599 101 Jan 28 11:19:59 volumio-livingroom volumio[15849]: 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 Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:19:59 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:19:59+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CoreStateMachine::pushState Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioPushState Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: Completed starting Core Plugins Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: ----- MyVolumio plugins startup ---- Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: ------------------------------------------- Jan 28 11:19:59 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:20:00 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:20:00 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:00+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:00 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:00+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:20:00 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:00+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:00 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:00+01:00" level=debug msg="completed challenge" Jan 28 11:20:01 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:01+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:01 volumio-livingroom volumio[15849]: info: go-librespot daemon successfully initialized Jan 28 11:20:01 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:01+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 11:20:01 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:01+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:01 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:01+01:00" level=debug msg="completed challenge" Jan 28 11:20:02 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:02+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:02 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:02+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 11:20:02 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:02+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:02 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:02+01:00" level=debug msg="completed challenge" Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:03+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:03+01:00" level=debug msg="completed challenge" Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20:03+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:03 volumio-livingroom go-librespot[16064]: time="2026-01-28T11:20: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 " Jan 28 11:20:03 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:20:03 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:20:03 volumio-livingroom volumio[15849]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:20:04 volumio-livingroom volumio[15849]: info: Initializing connection to go-librespot Websocket Jan 28 11:20:04 volumio-livingroom volumio[15849]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:20:06 volumio-livingroom sudo[16114]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:20:06 volumio-livingroom sudo[16114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:06 volumio-livingroom sudo[16116]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:20:06 volumio-livingroom sudo[16114]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:06 volumio-livingroom sudo[16116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:06 volumio-livingroom sudo[16116]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:06 volumio-livingroom sudo[16120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:20:06 volumio-livingroom sudo[16120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:06 volumio-livingroom sudo[16120]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:06 volumio-livingroom volumio[15849]: info: Upmpdcli Daemon Started Jan 28 11:20:06 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:20:06 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:06 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:06 volumio-livingroom go-librespot[16122]: go-librespot daemon starting... Jan 28 11:20:06 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:06+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:20:06 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:06+01:00" level=debug msg="app state loaded" Jan 28 11:20:06 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+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]" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+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]" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+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]" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=info msg="zeroconf server listening on port 39975" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=debug msg="obtained new client token: AAC1CWDMUU/TcFVJzi7Oe6VOaD4/o7lAZUJi5lscX6Aw0yRD0bsZecC8jDIvehpXK5faDTY2mZH7wMZ48c0jZiZIeVojOGY+uWdPQc2Pa92tSgo1xBmBhCU+D2zy3YHIH1qDs/6LEAu/C/IeePIkO8zmehPBEMhJjazxghqkNH8iL5G5bWEuCYRnfySH3OzxMErrMzzl//YxavghI0JgSW1Kx7FViPw2J7AjVCZ/nkqVKZWLHJwqGO+h" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=debug msg="completed challenge" Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:07 volumio-livingroom volumio[15849]: info: Initializing connection to go-librespot Websocket Jan 28 11:20:07 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:07+01:00" level=debug msg="new websocket client" Jan 28 11:20:07 volumio-livingroom volumio[15849]: info: Connection to go-librespot Websocket established Jan 28 11:20:08 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:20:08 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:08+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:08 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:08+01:00" level=debug msg="completed challenge" Jan 28 11:20:08 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:08+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: MyVolumio login type: Token Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Streaming services startup Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: Starting Streaming Daemon Jan 28 11:20:08 volumio-livingroom sudo[16133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:20:08 volumio-livingroom sudo[16133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:08 volumio-livingroom volumio[15849]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:20:08 volumio-livingroom sudo[16133]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:08 volumio-livingroom volumio[15849]: error: Cannot start Volumio Streaming Daemon Jan 28 11:20:08 volumio-livingroom volumio[15849]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:20:08 volumio-livingroom volumio[15849]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:20:09 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:09+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:20:09 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:09+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.134:50380->104.199.65.9:80: read: connection reset by peer" Jan 28 11:20:09 volumio-livingroom volumio[15849]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 11:20:09 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:09+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 11:20:09 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:09+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:09 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:09+01:00" level=debug msg="completed challenge" Jan 28 11:20:10 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: MyVolumio token set successfully Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: MYVOLUMIO: Adding device Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: MYVOLUMIO: Evaluating Server Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: MyVolumio status changed Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Streaming services startup Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Starting Streaming Daemon Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Removing audio output: Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Stoppping Tunnel 1 Jan 28 11:20:10 volumio-livingroom sudo[16162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:20:10 volumio-livingroom sudo[16162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:10 volumio-livingroom sudo[16164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 11:20:10 volumio-livingroom sudo[16164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom sudo[16162]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:10 volumio-livingroom volumio[15849]: error: Cannot start Volumio Streaming Daemon Jan 28 11:20:10 volumio-livingroom volumio[15849]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:20:10 volumio-livingroom volumio[15849]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom 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. Jan 28 11:20:10 volumio-livingroom sudo[16164]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Remote SSH Stopped Jan 28 11:20:10 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Setting Geolocation for MyVolumio to eu3 Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:10 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:10+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:10 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:10+01:00" level=debug msg="completed challenge" Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Getting Spotify volume Jan 28 11:20:10 volumio-livingroom volumio[15849]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:10 volumio-livingroom volumio[15849]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Jan 28 11:20:10 volumio-livingroom volumio[15849]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:20:10 volumio-livingroom volumio[15849]: SPOTIFY: VOLUMIO VOLUME 50 Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:10 volumio-livingroom volumio[15849]: info: Setting Spotify Volume from Volumio: 50 Jan 28 11:20:10 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:10+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:10 volumio-livingroom volumio[15849]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 11:20:11 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:11+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:20:11 volumio-livingroom volumio[15849]: info: Updating MyVolumio device info Jan 28 11:20:11 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:11 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:11 volumio-livingroom volumio[15849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:11 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:11+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:11 volumio-livingroom go-librespot[16123]: time="2026-01-28T11:20:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:11 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:20:11 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:20:11 volumio-livingroom volumio[15849]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:20:11 volumio-livingroom volumio[15849]: Error: socket hang up Jan 28 11:20:11 volumio-livingroom volumio[15849]: at connResetException (node:internal/errors:720:14) Jan 28 11:20:11 volumio-livingroom volumio[15849]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:20:11 volumio-livingroom volumio[15849]: at Socket.emit (node:events:526:35) Jan 28 11:20:11 volumio-livingroom volumio[15849]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:20:11 volumio-livingroom volumio[15849]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:20:11 volumio-livingroom volumio[15849]: code: 'ECONNRESET', Jan 28 11:20:11 volumio-livingroom volumio[15849]: response: undefined Jan 28 11:20:11 volumio-livingroom volumio[15849]: } Jan 28 11:20:11 volumio-livingroom volumio[15849]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:20:12 volumio-livingroom sudo[16181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:19' Jan 28 11:20:12 volumio-livingroom sudo[16181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:12 volumio-livingroom sudo[16181]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:12 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:20:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:20:12 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:20:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:20:12 volumio-livingroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:20:12 volumio-livingroom systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:20:12 volumio-livingroom systemd[1]: volumio.service: Consumed 9.375s CPU time. Jan 28 11:20:12 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:20:12 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:20:12 volumio-livingroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 47. Jan 28 11:20:12 volumio-livingroom systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:20:12 volumio-livingroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:20:12 volumio-livingroom systemd[1]: volumio.service: Consumed 9.375s CPU time. Jan 28 11:20:12 volumio-livingroom systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:20:12 volumio-livingroom systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ----- Volumio3 ---- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ----- System startup ---- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: MYVOLUMIO Environment detected Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Plugin folders cleanup Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category audio_interface Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category miscellanea Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category music_service Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category plugins.json Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category system_controller Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category user_interface Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning into folder /data/plugins/ Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Scanning category music_service Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Plugin folders cleanup completed Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ----- Core plugins startup ---- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugins from folder /data/plugins/ Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "system"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "appearance"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "network"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Refreshing Cached IP Addresses Jan 28 11:20:13 volumio-livingroom sudo[16223]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:20:13 volumio-livingroom sudo[16223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:13 volumio-livingroom sudo[16225]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:20:13 volumio-livingroom sudo[16225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:13 volumio-livingroom sudo[16223]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:13 volumio-livingroom sudo[16225]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "services"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "alsa_controller"... Jan 28 11:20:13 volumio-livingroom sudo[16234]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:20:13 volumio-livingroom sudo[16234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "wizard"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "networkfs"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Starting Udev Watcher for removable devices Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Ignoring mount for partition: boot Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Ignoring mount for partition: volumio Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Ignoring mount for partition: volumio_data Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "upnp"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: [1769595613645] Starting Upmpd Daemon Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "my_music"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "mpd"... Jan 28 11:20:13 volumio-livingroom volumio[16195]: info: Loading plugin "upnp_browser"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Starting UPNP Browser Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "alarm-clock"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "airplay_emulation"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Starting Shairport Sync Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "last_100"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "webradio"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "i2s_dacs"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "volumiodiscovery"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** For more information see Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** For more information see Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:20:14 volumio-livingroom volumio[16195]: *** WARNING *** For more information see Jan 28 11:20:14 volumio-livingroom node[16195]: *** WARNING *** For more information see Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Discovery: Started advertising with name: Volumio LivingRoom Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "spop"... Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "ytcr"... Jan 28 11:20:14 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:20:14 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:14 volumio-livingroom volumio[16195]: info: Loading plugin "ytmusic"... Jan 28 11:20:14 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:14 volumio-livingroom go-librespot[16258]: go-librespot daemon starting... Jan 28 11:20:14 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:14+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:20:14 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:14+01:00" level=debug msg="app state loaded" Jan 28 11:20:14 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "outputs"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "albumart"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Plugin example_plugin is not enabled Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "inputs"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "updater_comm"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Plugin mpdemulation is not enabled Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "rest_api"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading plugin "websocket"... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Loading i18n strings for locale en Jan 28 11:20:15 volumio-livingroom volumio[16195]: Updating browse sources language Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::initPlayerControls Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: Express server listening on port 3000 Jan 28 11:20:15 volumio-livingroom volumio[16195]: [Metrics] WebUI: 2s 344.62ms Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::resetVolumioState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::getcurrentVolume Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Volumio Network Manager: Network status updated: 2 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::pushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioPushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::updateTrackBlock Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrackBlock Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:20:15 volumio-livingroom volumio[16265]: Forking 3 albumart workers Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Reloading queue from file Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::pushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioPushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::setRandom null Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::pushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioPushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Setting Device type: Raspberry PI Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: USB Boot Capable - System SBC Revision found in cpuinfo: e04171 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Completed loading Core Plugins Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Preparing to generate the ALSA configuration file Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreStateMachine::pushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioPushState Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Output device has changed, restarting MPD Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Output device has changed, restarting Shairport Sync Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:15 volumio-livingroom sudo[16323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:20:15 volumio-livingroom sudo[16323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:15 volumio-livingroom sudo[16325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:20:15 volumio-livingroom sudo[16325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:15 volumio-livingroom sudo[16323]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: ___________ START PLUGINS ___________ Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Creating MPD Configuration file Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: [1769595615483] CoreMusicLibrary::Adding element Media Servers Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:20:15 volumio-livingroom sudo[16333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:20:15 volumio-livingroom sudo[16333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: UPNP Browser: Client initialized successfully Jan 28 11:20:15 volumio-livingroom systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:20:15 volumio-livingroom sudo[16333]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:15 volumio-livingroom sudo[16335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:20:15 volumio-livingroom sudo[16335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:15 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:20:15 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:20:15 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:20:15 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:20:15 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: [1769595615545] CoreMusicLibrary::Adding element Last_100 Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: [1769595615547] CoreMusicLibrary::Adding element Webradio Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Initializing BBC Radios Jan 28 11:20:15 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:20:15 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:20:15 volumio-livingroom systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:20:15 volumio-livingroom systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:20:15 volumio-livingroom systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:20:15 volumio-livingroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:20:15 volumio-livingroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:20:15 volumio-livingroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:20:15 volumio-livingroom systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Creating Spotify config file Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:15 volumio-livingroom sudo[16363]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:20:15 volumio-livingroom sudo[16363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:20:15 volumio-livingroom sudo[16363]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:15 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:15+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]" Jan 28 11:20:15 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:15+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]" Jan 28 11:20:15 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:15+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]" Jan 28 11:20:15 volumio-livingroom go-librespot[16259]: time="2026-01-28T11:20:15+01:00" level=info msg="zeroconf server listening on port 34443" Jan 28 11:20:15 volumio-livingroom volumio[16285]: Starting albumart workers Jan 28 11:20:15 volumio-livingroom volumio[16287]: Starting albumart workers Jan 28 11:20:15 volumio-livingroom volumio[16284]: Starting albumart workers Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: [1769595615902] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:20:15 volumio-livingroom volumio[16195]: Cannot find translation for source YouTube Music Jan 28 11:20:15 volumio-livingroom volumio[16195]: info: Volumio Calling Home Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Discovery: adding 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Discovery: this is already registered, 97edba0b-8e89-480f-81bd-1232387e69fa Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Discovery: Found device Volumio LivingRoom Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: MPD Permissions set Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: MPD Permissions set Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Spotify config file written Jan 28 11:20:16 volumio-livingroom sudo[16384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:20:16 volumio-livingroom sudo[16384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:16 volumio-livingroom volumio[16195]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:20:16 volumio-livingroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:20:16 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: No need to fix Spotify hosts Jan 28 11:20:16 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:16 volumio-livingroom go-librespot[16391]: go-librespot daemon starting... Jan 28 11:20:16 volumio-livingroom sudo[16384]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+01:00" level=debug msg="app state loaded" Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Starting Shairport Sync Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Starting Shairport Sync Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Starting Shairport Sync Jan 28 11:20:16 volumio-livingroom sudo[16411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:20:16 volumio-livingroom sudo[16412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:20:16 volumio-livingroom sudo[16412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:16 volumio-livingroom sudo[16411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:16 volumio-livingroom sudo[16414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:20:16 volumio-livingroom sudo[16414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:16 volumio-livingroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:20:16 volumio-livingroom systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:20:16 volumio-livingroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:20:16 volumio-livingroom systemd[1]: shairport-sync.service: Consumed 1.558s CPU time. Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:16 volumio-livingroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:20:16 volumio-livingroom sudo[16411]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom sudo[16414]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom sudo[16412]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Shairport-Sync Started Jan 28 11:20:16 volumio-livingroom volumio[16195]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Shairport-Sync Started Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Shairport-Sync Started Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: Volumio called home Jan 28 11:20:16 volumio-livingroom mpd[16365]: 2026-01-28T11:20:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:20:16 volumio-livingroom systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:20:16 volumio-livingroom sudo[16335]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom sudo[16325]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom volumio[16195]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:20:16 volumio-livingroom volumio[16195]: assert.ok(self.idling) Jan 28 11:20:16 volumio-livingroom volumio[16195]: error: The expression evaluated to a falsy value: Jan 28 11:20:16 volumio-livingroom volumio[16195]: assert.ok(self.idling) Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: MPD running with PID16365 Jan 28 11:20:16 volumio-livingroom volumio[16195]: ,establishing connection Jan 28 11:20:16 volumio-livingroom volumio[16195]: error: updateQueue error: null Jan 28 11:20:16 volumio-livingroom volumio[16195]: error: updateQueue error: null Jan 28 11:20:16 volumio-livingroom volumio[16195]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 11:20:16 volumio-livingroom sudo[16234]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+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]" Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+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]" Jan 28 11:20:16 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:16+01:00" level=info msg="zeroconf server listening on port 42409" Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=debug msg="obtained new client token: AACSX5/SHvSsI5E0gTy4XUdmYIwq1bviEgvBQ34m5EB4QLKkJwp/yOn5g08o1a0ong42pQeSrND2dRv3AIEY5Jj3pGQwoT6K+6ePP4bcXszsqvygfYx/QyRYFRwaFss0x4cJOAiJBLw3Hm9HQn5jdARGGpfmH0qUjjItsl6T49vfcBnik+R04Gjal2V2DxiCbYU9vBpqQfurCXzjxgrsh/14UvpVPwMtrhYaWA+wgBNaRfN6oJZ2gQ==" Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:20:17 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:20:17] [connect] Successful connection Jan 28 11:20:17 volumio-livingroom volumio-remote-updater[1001]: [2026-01-28 11:20:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769595617 101 Jan 28 11:20:17 volumio-livingroom volumio[16195]: 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 Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: VolumeController:: Volume=50 Mute =false Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioGetState Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CoreStateMachine::pushState Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CorePlayQueue::getTrack 0 Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: CoreCommandRouter::volumioPushState Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=debug msg="completed challenge" Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: Completed starting Core Plugins Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: ----- MyVolumio plugins startup ---- Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: ------------------------------------------- Jan 28 11:20:17 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+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" Jan 28 11:20:17 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=debug msg="completed challenge" Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:18 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:18+01:00" level=debug msg="completed challenge" Jan 28 11:20:19 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:19+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:19 volumio-livingroom volumio[16195]: info: go-librespot daemon successfully initialized Jan 28 11:20:19 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:19+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 11:20:19 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:19+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:19 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:19+01:00" level=debug msg="completed challenge" Jan 28 11:20:20 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:20+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:20 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:20+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:20:21 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:21+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:21 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:21+01:00" level=debug msg="completed challenge" Jan 28 11:20:21 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:21+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:21 volumio-livingroom volumio[16195]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:20:21 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:20:22 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:22+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:22 volumio-livingroom go-librespot[16397]: time="2026-01-28T11:20:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:22 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:20:22 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:20:22 volumio-livingroom volumio[16195]: info: Initializing connection to go-librespot Websocket Jan 28 11:20:22 volumio-livingroom volumio[16195]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:20:23 volumio-livingroom sudo[16459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:20:23 volumio-livingroom sudo[16459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:23 volumio-livingroom sudo[16459]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:23 volumio-livingroom sudo[16461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:20:23 volumio-livingroom sudo[16461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:23 volumio-livingroom sudo[16461]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:23 volumio-livingroom sudo[16464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:20:23 volumio-livingroom sudo[16464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:23 volumio-livingroom sudo[16464]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:23 volumio-livingroom volumio[16195]: info: Upmpdcli Daemon Started Jan 28 11:20:25 volumio-livingroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:20:25 volumio-livingroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Initializing connection to go-librespot Websocket Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:20:25 volumio-livingroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:20:25 volumio-livingroom go-librespot[16468]: go-librespot daemon starting... Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=debug msg="app state loaded" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+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]" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+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]" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+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]" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=info msg="zeroconf server listening on port 41479" Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=debug msg="obtained new client token: AADx9LE726nv/PyXjvvn5yoK1VTuSZABPRGnDf10xgLrC8SYC3ONM/UJNaOvrvNAghw0VtWegwJicWwKvy6Z4s9qfxRQdWCUZz/fJr5UBKKt2gZ+F5ADX7oUOtL75+4bGn6Eh2qcWlV0NgQIawO569kNFdx65VtHqnYcg2j8Lg9ssjJ2URhWD9EWqK29r7VG1vliI0zg4BC4q8ZdxgFTT2phVDsebViLZI8+IlK+gYeo4nmWIhYV4/G1" Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 28 11:20:25 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:25+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: MyVolumio login type: Token Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:20:25 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: Streaming services startup Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: Starting Streaming Daemon Jan 28 11:20:26 volumio-livingroom sudo[16479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:20:26 volumio-livingroom sudo[16479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:20:26 volumio-livingroom sudo[16479]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:26 volumio-livingroom volumio[16195]: error: Cannot start Volumio Streaming Daemon Jan 28 11:20:26 volumio-livingroom volumio[16195]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:20:26 volumio-livingroom volumio[16195]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:20:26 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:26+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 11:20:26 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:26+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 11:20:26 volumio-livingroom volumio[16195]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 11:20:27 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:27+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 11:20:27 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:27+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:27 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:27+01:00" level=debug msg="completed challenge" Jan 28 11:20:27 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:27+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: MyVolumio token set successfully Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: MYVOLUMIO: Adding device Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: MYVOLUMIO: Evaluating Server Jan 28 11:20:27 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:27+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: MyVolumio status changed Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Streaming services startup Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Starting Streaming Daemon Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Removing audio output: Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Stoppping Tunnel 1 Jan 28 11:20:27 volumio-livingroom sudo[16507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:20:27 volumio-livingroom sudo[16507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:27 volumio-livingroom sudo[16509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 11:20:27 volumio-livingroom sudo[16509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:20:27 volumio-livingroom sudo[16507]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:27 volumio-livingroom volumio[16195]: error: Cannot start Volumio Streaming Daemon Jan 28 11:20:27 volumio-livingroom volumio[16195]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:20:27 volumio-livingroom volumio[16195]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom 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. Jan 28 11:20:27 volumio-livingroom sudo[16509]: pam_unix(sudo:session): session closed for user root Jan 28 11:20:27 volumio-livingroom volumio[16195]: info: Remote SSH Stopped Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="completed challenge" Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: Initializing connection to go-librespot Websocket Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="new websocket client" Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: Connection to go-librespot Websocket established Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: Setting Geolocation for MyVolumio to eu3 Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:28 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:28 volumio-livingroom volumio[16195]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=debug msg="completed challenge" Jan 28 11:20:28 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:28+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:29 volumio-livingroom volumio[16195]: info: Updating MyVolumio device info Jan 28 11:20:29 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:29 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:29 volumio-livingroom volumio[16195]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:20:29 volumio-livingroom volumio[16195]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 28 11:20:29 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:29+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:20:29 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:29+01:00" level=debug msg="completed keyexchange" Jan 28 11:20:29 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:29+01:00" level=debug msg="completed challenge" Jan 28 11:20:30 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:30+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:20:30 volumio-livingroom go-librespot[16469]: time="2026-01-28T11:20:30+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 " Jan 28 11:20:30 volumio-livingroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:20:30 volumio-livingroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:20:30 volumio-livingroom volumio[16195]: info: Connection to go-librespot Websocket closed Jan 28 11:20:31 volumio-livingroom volumio[16195]: info: Getting Spotify volume Jan 28 11:20:31 volumio-livingroom volumio[16195]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:20:31 volumio-livingroom volumio[16195]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:20:31 volumio-livingroom volumio[16195]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:20:31 volumio-livingroom volumio[16195]: errno: -111, Jan 28 11:20:31 volumio-livingroom volumio[16195]: code: 'ECONNREFUSED', Jan 28 11:20:31 volumio-livingroom volumio[16195]: syscall: 'connect', Jan 28 11:20:31 volumio-livingroom volumio[16195]: address: '127.0.0.1', Jan 28 11:20:31 volumio-livingroom volumio[16195]: port: 9879, Jan 28 11:20:31 volumio-livingroom volumio[16195]: response: undefined Jan 28 11:20:31 volumio-livingroom volumio[16195]: } Jan 28 11:20:31 volumio-livingroom volumio[16195]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:20:31 volumio-livingroom sudo[16526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:19' Jan 28 11:20:31 volumio-livingroom sudo[16526]: 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"