Mar 24 20:08:00 katarynka volumio[19089]: info: Starting UPNP Browser
Mar 24 20:08:00 katarynka volumio[19089]: info: Loading plugin "alarm-clock"...
Mar 24 20:08:00 katarynka volumio[19089]: info: Loading plugin "airplay_emulation"...
Mar 24 20:08:00 katarynka volumio[19089]: info: Starting Shairport Sync
Mar 24 20:08:00 katarynka volumio[19089]: info: Loading plugin "last_100"...
Mar 24 20:08:00 katarynka volumio[19089]: info: Loading plugin "webradio"...
Mar 24 20:08:01 katarynka volumio[19089]: info: Loading plugin "i2s_dacs"...
Mar 24 20:08:01 katarynka volumio[19089]: info: Loading plugin "volumiodiscovery"...
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** For more information see 
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:01 katarynka volumio[19089]: *** WARNING *** For more information see 
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** For more information see 
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:01 katarynka node[19089]: *** WARNING *** For more information see 
Mar 24 20:08:01 katarynka volumio[19089]: info: Applying required configuration parameters for plugin volumiodiscovery
Mar 24 20:08:01 katarynka volumio[19089]: info: Discovery: Started advertising with name: katarynka
Mar 24 20:08:01 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 24 20:08:01 katarynka volumio[19089]: info: Loading plugin "spop"...
Mar 24 20:08:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Mar 24 20:08:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:02 katarynka go-librespot[19179]: go-librespot daemon starting...
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=debug msg="app state loaded"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "outputs"...
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "albumart"...
Mar 24 20:08:03 katarynka volumio[19089]: info: Plugin example_plugin is not enabled
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "inputs"...
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "updater_comm"...
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=info msg="zeroconf server listening on port 45067"
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=debug msg="obtained new client token: AADsQkG3X3D9kPyPuXcDrlhVqfARXka8kgJRFE4UadQrFjRJ/xM3Lv6R5ZhZZAxo9DFj6RZkBmfLOBw9vmelHmvcGrHIVr1mMOIoqtzA0byjcVAmA7Z9mbtUAzLO+PD31stKGoWO9A2zb6gqn6EVKjP47kEbshRWTmbpoz3aWGA4t0Le/e3nHjixnEmVkF7WUy11rxeDXFsDRjdni6jQmC9nABrgEEbk5YrJomaR/tlNHuqwUzE3Pr+XRWo="
Mar 24 20:08:03 katarynka volumio[19089]: info: Plugin mpdemulation is not enabled
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "rest_api"...
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading plugin "websocket"...
Mar 24 20:08:03 katarynka go-librespot[19180]: time="2026-03-24T20:08:03+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Mar 24 20:08:03 katarynka volumio[19089]: info: Starting Socket.io Server version 1.7.4
Mar 24 20:08:03 katarynka volumio[19089]: info: Loading i18n strings for locale pl
Mar 24 20:08:03 katarynka volumio[19089]: Updating browse sources language
Mar 24 20:08:03 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused"
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused"
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::initPlayerControls
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: Express server listening on port 3000
Mar 24 20:08:04 katarynka volumio[19089]:  [Metrics]  WebUI:  12s 542.15ms 
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::resetVolumioState
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::getcurrentVolume
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::volumioRetrievevolume
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+01:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Mar 24 20:08:04 katarynka volumio[19089]: info: Cannot read play queue from file
Mar 24 20:08:04 katarynka volumio[19089]: info: Volumio Network Manager: Network status updated: 2
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+01:00" level=debug msg="completed challenge"
Mar 24 20:08:04 katarynka go-librespot[19180]: time="2026-03-24T20:08:04+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 "
Mar 24 20:08:04 katarynka volumio[19188]: Forking 3 albumart workers
Mar 24 20:08:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:04 katarynka volumio[19089]: info: VolumeController:: Volume=96 Mute =false
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::pushState
Mar 24 20:08:04 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::updateTrackBlock
Mar 24 20:08:04 katarynka volumio[19089]: info: CorePlayQueue::getTrackBlock
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::volumioRetrievevolume
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::setRepeat null single undefined
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::pushState
Mar 24 20:08:04 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::setRandom null
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreStateMachine::pushState
Mar 24 20:08:04 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:04 katarynka volumio[19089]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:04 katarynka volumio[19089]: info: Setting Device type: Raspberry PI
Mar 24 20:08:04 katarynka volumio[19089]: info: Completed loading Core Plugins
Mar 24 20:08:04 katarynka volumio[19089]: info: Preparing to generate the ALSA configuration file
Mar 24 20:08:05 katarynka volumio[19089]: info: Asound.conf file unchanged, so no further update is needed
Mar 24 20:08:05 katarynka volumio[19089]: info: Output device has changed, restarting MPD
Mar 24 20:08:05 katarynka volumio[19089]: info: Output device has changed, restarting Shairport Sync
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:05 katarynka sudo[19242]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 24 20:08:05 katarynka sudo[19242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:05 katarynka sudo[19242]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:05 katarynka sudo[19244]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 24 20:08:05 katarynka sudo[19244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:05 katarynka volumio[19089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:05 katarynka volumio[19089]: info: ___________ START PLUGINS ___________
Mar 24 20:08:05 katarynka volumio[19089]: info: ControllerMpd::onStart: Initializing MPD
Mar 24 20:08:05 katarynka volumio[19089]: info: Creating MPD Configuration file
Mar 24 20:08:05 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon...
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:05 katarynka volumio[19089]: info: [1774379285392] CoreMusicLibrary::Adding element Serwery Mediów
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:05 katarynka sudo[19252]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 24 20:08:05 katarynka sudo[19252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:05 katarynka volumio[19089]: info: UPNP Browser: Client initialized successfully
Mar 24 20:08:05 katarynka sudo[19252]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:05 katarynka systemd[1]: mpd.service: Deactivated successfully.
Mar 24 20:08:05 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 24 20:08:05 katarynka systemd[1]: mpd.service: Consumed 7.895s CPU time.
Mar 24 20:08:05 katarynka systemd[1]: mpd.socket: Deactivated successfully.
Mar 24 20:08:05 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:05 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 24 20:08:05 katarynka sudo[19254]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 24 20:08:05 katarynka sudo[19254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:05 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:05 katarynka systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 24 20:08:05 katarynka volumio[19089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:05 katarynka systemd[1]: mpd.service: Deactivated successfully.
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:05 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 24 20:08:05 katarynka systemd[1]: mpd.socket: Deactivated successfully.
Mar 24 20:08:05 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:05 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 24 20:08:05 katarynka volumio[19089]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:05 katarynka volumio[19089]: info: [1774379285773] CoreMusicLibrary::Adding element Last_100
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:05 katarynka volumio[19089]: info: [1774379285785] CoreMusicLibrary::Adding element Webradio
Mar 24 20:08:05 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:05 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:05 katarynka systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 24 20:08:05 katarynka volumio[19089]: info: Initializing BBC Radios
Mar 24 20:08:06 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:06 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:06 katarynka volumio[19089]: info: Creating Spotify config file
Mar 24 20:08:06 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:06 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:06] [connect] Successful connection
Mar 24 20:08:06 katarynka sudo[19269]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 24 20:08:06 katarynka sudo[19269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 24 20:08:06 katarynka sudo[19269]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:07 katarynka volumio[19089]: info: Volumio Calling Home
Mar 24 20:08:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Mar 24 20:08:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:07 katarynka go-librespot[19302]: go-librespot daemon starting...
Mar 24 20:08:07 katarynka go-librespot[19304]: time="2026-03-24T20:08:07+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:08 katarynka volumio[19204]: Starting albumart workers
Mar 24 20:08:08 katarynka volumio[19207]: Starting albumart workers
Mar 24 20:08:08 katarynka go-librespot[19304]: time="2026-03-24T20:08:08+01:00" level=info msg="zeroconf server listening on port 39429"
Mar 24 20:08:08 katarynka sudo[19312]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 24 20:08:08 katarynka sudo[19312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:08 katarynka sudo[19312]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:08 katarynka volumio[19089]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51
Mar 24 20:08:08 katarynka volumio[19089]: info: Discovery: Found device katarynka
Mar 24 20:08:08 katarynka volumio[19089]: info: CoreCommandRouter::volumioGetState
Mar 24 20:08:08 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:08 katarynka volumio[19209]: Starting albumart workers
Mar 24 20:08:08 katarynka sudo[19314]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 24 20:08:08 katarynka sudo[19314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:08 katarynka volumio[19089]: info: MPD Permissions set
Mar 24 20:08:08 katarynka volumio[19089]: info: MPD Permissions set
Mar 24 20:08:08 katarynka volumio[19089]: info: VolumeController:: Volume=96 Mute =false
Mar 24 20:08:08 katarynka volumio[19089]: info: CoreStateMachine::pushState
Mar 24 20:08:08 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:08 katarynka volumio[19089]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:08 katarynka sudo[19314]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:08 katarynka volumio[19089]: info: Discovery: this is already registered,  4d616d77-6a8c-4da2-85a4-840d70f98e51
Mar 24 20:08:08 katarynka volumio[19089]: info: Discovery: Found device katarynka
Mar 24 20:08:08 katarynka volumio[19089]: info: CoreCommandRouter::volumioGetState
Mar 24 20:08:08 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:09 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774379286 101
Mar 24 20:08:09 katarynka volumio[19089]: 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: 1
Mar 24 20:08:09 katarynka volumio[19089]: info: Volumio called home
Mar 24 20:08:09 katarynka volumio[19089]: info: Spotify config file written
Mar 24 20:08:09 katarynka sudo[19318]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Mar 24 20:08:09 katarynka sudo[19318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:09 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Mar 24 20:08:09 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Mar 24 20:08:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:09 katarynka go-librespot[19320]: go-librespot daemon starting...
Mar 24 20:08:09 katarynka sudo[19318]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:09 katarynka go-librespot[19321]: time="2026-03-24T20:08:09+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:09 katarynka go-librespot[19321]: time="2026-03-24T20:08:09+01:00" level=debug msg="app state loaded"
Mar 24 20:08:09 katarynka go-librespot[19321]: time="2026-03-24T20:08:09+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:09 katarynka volumio[19089]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:09 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:10 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:10 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:10 katarynka volumio[19089]: info: No need to fix Spotify hosts
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=info msg="zeroconf server listening on port 37589"
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="obtained new client token: AADs8XqSQuffXf3+nUn9erpX587qha+LmcvulIX0+pTCoLvwuOyyIZP7fFPdXMZKOK/FSMIim8mTZUyR5PL88MMwfYmHCXrL1srXWPvXogwpJvfK+DLo61rO00b/bQmvp7dUTzb0z8MUeCqC7qCoO8DymkExBfFzC2On/K2j3kINq+QQLWZ2sXBOwtQsdOXqe1pqR/1G+6lflC6FecrAUyn+Qh2jYtH6pqESVqw7wKNB945tCIu7T8ahl9M="
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Mar 24 20:08:10 katarynka volumio[19089]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Mar 24 20:08:10 katarynka volumio[19089]: info: Starting Shairport Sync
Mar 24 20:08:10 katarynka volumio[19089]: info: Starting Shairport Sync
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+01:00" level=debug msg="completed challenge"
Mar 24 20:08:10 katarynka sudo[19352]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:08:10 katarynka sudo[19352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:10 katarynka volumio[19089]: info: Starting Shairport Sync
Mar 24 20:08:10 katarynka go-librespot[19321]: time="2026-03-24T20:08:10+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 "
Mar 24 20:08:10 katarynka sudo[19354]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:08:10 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 24 20:08:10 katarynka sudo[19357]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:08:10 katarynka sudo[19357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:10 katarynka sudo[19354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:11 katarynka systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 24 20:08:11 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:08:11 katarynka systemd[1]: shairport-sync.service: Consumed 2.250s CPU time.
Mar 24 20:08:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:11 katarynka sudo[19359]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Mar 24 20:08:11 katarynka sudo[19359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:11 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:08:11 katarynka sudo[19352]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:11 katarynka volumio[19089]: info: Shairport-Sync Started
Mar 24 20:08:11 katarynka volumio[19089]: Error adding Membership: Error: addMembership EINVAL
Mar 24 20:08:11 katarynka volumio[19089]: info: CoreCommandRouter::volumioGetState
Mar 24 20:08:11 katarynka volumio[19089]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:11 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 24 20:08:11 katarynka sudo[19359]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:11 katarynka volumio[19089]: info: Upmpdcli Daemon Started
Mar 24 20:08:11 katarynka systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 24 20:08:11 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:08:11 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:08:11 katarynka sudo[19357]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:11 katarynka sudo[19354]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:11 katarynka volumio[19089]: info: Shairport-Sync Started
Mar 24 20:08:11 katarynka volumio[19089]: info: Shairport-Sync Started
Mar 24 20:08:13 katarynka volumio[19089]: info: go-librespot daemon successfully initialized
Mar 24 20:08:14 katarynka mpd[19284]: 2026-03-24T20:08:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 24 20:08:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Mar 24 20:08:14 katarynka systemd[1]: Started mpd.service - Music Player Daemon.
Mar 24 20:08:14 katarynka sudo[19244]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:14 katarynka sudo[19254]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:14 katarynka volumio[19089]: info: Completed starting Core Plugins
Mar 24 20:08:14 katarynka volumio[19089]: info: -------------------------------------------
Mar 24 20:08:14 katarynka volumio[19089]: info: -----    MyVolumio plugins startup     ----
Mar 24 20:08:14 katarynka volumio[19089]: info: -------------------------------------------
Mar 24 20:08:14 katarynka volumio[19089]: info: [MyVolumio PluginManager] Fetching plans data....
Mar 24 20:08:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:14 katarynka go-librespot[19400]: go-librespot daemon starting...
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="app state loaded"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:14 katarynka volumio[19089]: error: MPD error: The expression evaluated to a falsy value:
Mar 24 20:08:14 katarynka volumio[19089]:   assert.ok(self.idling)
Mar 24 20:08:14 katarynka volumio[19089]: error: The expression evaluated to a falsy value:
Mar 24 20:08:14 katarynka volumio[19089]:   assert.ok(self.idling)
Mar 24 20:08:14 katarynka volumio[19089]: info: MPD running with PID19284
Mar 24 20:08:14 katarynka volumio[19089]:  ,establishing connection
Mar 24 20:08:14 katarynka volumio[19089]: error: updateQueue error: null
Mar 24 20:08:14 katarynka volumio[19089]: error: updateQueue error: null
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=info msg="zeroconf server listening on port 34529"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="obtained new client token: AACCWllYFouX9j8aDj0I6RwlR5uykRnX0JZ5E5bGuCaxzeP/xOsom8/t2WFQMkwH6AY+h1xCWxw/qaETMIkH2QrEVnMY2hON5liOcvz04+B/MFWXaqSze5U+hmIwoSkLElfUQmcqJ9t63PQP5grR+QFedmZywnVUIbNawJtA9lPKc96fVBc3/G/vtzjg5l7/UYX7/tsvuZcRHk9ZHbcW5zuWWmzAnC7+DqdHXbAsIBcbsabWgTlnwb7OqDs="
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+01:00" level=debug msg="completed challenge"
Mar 24 20:08:14 katarynka go-librespot[19403]: time="2026-03-24T20:08:14+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 "
Mar 24 20:08:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:16 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:16 katarynka volumio[19089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:17 katarynka sudo[19426]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 24 20:08:17 katarynka sudo[19426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:17 katarynka sudo[19428]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 24 20:08:17 katarynka sudo[19428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:17 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Mar 24 20:08:17 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully.
Mar 24 20:08:17 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Mar 24 20:08:17 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Mar 24 20:08:17 katarynka mpd_monitor.sh[19431]: MPD Monitor Service: Starting MPD Monitor Service
Mar 24 20:08:17 katarynka sudo[19426]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:17 katarynka sudo[19428]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:17 katarynka volumio[19089]: info: Successfully started MPD Monitor
Mar 24 20:08:17 katarynka volumio[19089]: info: Successfully started MPD Monitor
Mar 24 20:08:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Mar 24 20:08:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:18 katarynka go-librespot[19435]: go-librespot daemon starting...
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=debug msg="app state loaded"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=info msg="zeroconf server listening on port 39873"
Mar 24 20:08:18 katarynka go-librespot[19436]: time="2026-03-24T20:08:18+01:00" level=debug msg="obtained new client token: AACBy0JINS6NTIylZHjdj2GuDrUZMjv+9ppBRod0kknThJuFDHc6LmhixSQdIh5ddfRwxSnD7TazZJSG+30wtC5z9Frzi2wWEkiXx3YmkKz7JwZVGH5HuAh0XEmk7HyXhizklgiWwsiIhTriT+Cg2l/GJ3M+Y5rhRcLIWxZwaYU74/U1qTPVHv+woPBCOKNhNSe1QDFhPbs7wMlev46Xr1NPtbInDKMPHuDzKP13sCGlEy2bNlSmQpZI6Iw="
Mar 24 20:08:19 katarynka go-librespot[19436]: time="2026-03-24T20:08:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:19 katarynka volumio[19089]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Mar 24 20:08:19 katarynka go-librespot[19436]: time="2026-03-24T20:08:19+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:19 katarynka go-librespot[19436]: time="2026-03-24T20:08:19+01:00" level=debug msg="completed challenge"
Mar 24 20:08:19 katarynka go-librespot[19436]: time="2026-03-24T20:08:19+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 "
Mar 24 20:08:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:19 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:19 katarynka volumio[19089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin bluetooth to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin multiroom to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin metavolumio to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin cd_controller to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin qobuzconnect to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin smart_inputs to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: Adding plugin tidalconnect to MyMusic Plugins
Mar 24 20:08:22 katarynka volumio[19089]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Mar 24 20:08:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Mar 24 20:08:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:22 katarynka go-librespot[19443]: go-librespot daemon starting...
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="app state loaded"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=info msg="zeroconf server listening on port 33463"
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="obtained new client token: AAATIxH/8UdXo4xDJ1UMhaP31Ba5swdq0Qz1w7L5sZ5qONZBZdvUVKt58wcDkgyPNaE++izNhK7j5QO1J7Y/LfFORhTMjVpO75znF1XTC4ZKvgq0Oq+zn+Jd+wc7U4GP8zTXuQvkh7nho3+MghazqLSxARkqGmRmi/Wnq15fgU/yLvnqQ9NufcJYxnwn5Wf5CxM31z1OxpOVgCf33ChzPwKKHc0WMCAc1pK8SNMtfN4+Gz6NkavK63uVOxI="
Mar 24 20:08:23 katarynka go-librespot[19444]: time="2026-03-24T20:08:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:24 katarynka go-librespot[19444]: time="2026-03-24T20:08:24+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:24 katarynka go-librespot[19444]: time="2026-03-24T20:08:24+01:00" level=debug msg="completed challenge"
Mar 24 20:08:24 katarynka go-librespot[19444]: time="2026-03-24T20:08:24+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 "
Mar 24 20:08:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:24 katarynka volumio[19089]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Mar 24 20:08:24 katarynka volumio[19089]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Mar 24 20:08:24 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:24 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:24 katarynka volumio[19089]: info: Starting MyVolumio Remote Streaming Endpoints
Mar 24 20:08:24 katarynka volumio[19089]: info: MyVolumio login type: Token
Mar 24 20:08:24 katarynka volumio[19089]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Mar 24 20:08:24 katarynka volumio[19089]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Mar 24 20:08:26 katarynka volumio[19089]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Mar 24 20:08:26 katarynka volumio[19089]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Mar 24 20:08:26 katarynka volumio[19089]: info: Streaming services startup
Mar 24 20:08:26 katarynka volumio[19089]: info: Starting Streaming Daemon
Mar 24 20:08:26 katarynka sudo[19452]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Mar 24 20:08:26 katarynka sudo[19452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:26 katarynka volumio[19089]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Mar 24 20:08:26 katarynka sudo[19452]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:26 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:26 katarynka volumio[19089]: error: Cannot start Volumio Streaming Daemon
Mar 24 20:08:26 katarynka volumio[19089]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Mar 24 20:08:26 katarynka volumio[19089]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Mar 24 20:08:26 katarynka volumio[19089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:27 katarynka volumio[19089]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Mar 24 20:08:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Mar 24 20:08:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:27 katarynka go-librespot[19472]: go-librespot daemon starting...
Mar 24 20:08:27 katarynka go-librespot[19473]: time="2026-03-24T20:08:27+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:27 katarynka go-librespot[19473]: time="2026-03-24T20:08:27+01:00" level=debug msg="app state loaded"
Mar 24 20:08:27 katarynka go-librespot[19473]: time="2026-03-24T20:08:27+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:28 katarynka volumio[19089]: info: MyVolumio token set successfully
Mar 24 20:08:28 katarynka volumio[19089]: info: MYVOLUMIO: Adding device
Mar 24 20:08:28 katarynka volumio[19089]: info: MYVOLUMIO: Evaluating Server
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=info msg="zeroconf server listening on port 44391"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="obtained new client token: AAB+9SI7f9oynlpZjcaCBSOzIIhenMfPEf2Uy6CGtTYtTP/mcvBgFKFq0KrQFOrMpZC4hZvpyGoqNs7g877vyXOaQ6HpKA+EOrLOHAFgybTUuAx58kufcW4DvUQPOPpfnEm4XO6Knnol0TXsh78AzXtibA/xDwbqseZfieHay5/Qp0UTqDD7FIcAd9fPQR5VzuxQjvfYcfa2Q4VK7D3FMXlzP0lPs+zHtZSqGQJw1kMx+iJdu8snRZaWo7E="
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=debug msg="completed challenge"
Mar 24 20:08:28 katarynka go-librespot[19473]: time="2026-03-24T20:08:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Mar 24 20:08:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:28 katarynka volumio[19089]: info: MyVolumio status changed
Mar 24 20:08:28 katarynka volumio[19089]: info: Streaming services startup
Mar 24 20:08:28 katarynka volumio[19089]: info: Starting Streaming Daemon
Mar 24 20:08:28 katarynka volumio[19089]: info: Removing browser output: myVolumio user plan is not superstar
Mar 24 20:08:28 katarynka volumio[19089]: info: Removing audio output:
Mar 24 20:08:28 katarynka volumio[19089]: info: Stoppping Tunnel 1
Mar 24 20:08:28 katarynka sudo[19502]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Mar 24 20:08:28 katarynka sudo[19502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:28 katarynka sudo[19504]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Mar 24 20:08:28 katarynka sudo[19504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:28 katarynka sudo[19502]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:28 katarynka volumio[19089]: error: Cannot start Volumio Streaming Daemon
Mar 24 20:08:28 katarynka volumio[19089]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Mar 24 20:08:28 katarynka volumio[19089]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka 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.
Mar 24 20:08:28 katarynka sudo[19504]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:28 katarynka volumio[19089]: info: Remote SSH Stopped
Mar 24 20:08:28 katarynka volumio[19089]: info: Setting Geolocation for MyVolumio to eu4
Mar 24 20:08:28 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:28 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:28 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:29 katarynka volumio[19089]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Mar 24 20:08:29 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:29 katarynka volumio[19089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:29 katarynka volumio[19089]: info: Updating MyVolumio device info
Mar 24 20:08:29 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:29 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:29 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:30 katarynka volumio[19089]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Mar 24 20:08:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Mar 24 20:08:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:31 katarynka go-librespot[19507]: go-librespot daemon starting...
Mar 24 20:08:31 katarynka go-librespot[19508]: time="2026-03-24T20:08:31+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:31 katarynka go-librespot[19508]: time="2026-03-24T20:08:31+01:00" level=debug msg="app state loaded"
Mar 24 20:08:31 katarynka go-librespot[19508]: time="2026-03-24T20:08:31+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=info msg="zeroconf server listening on port 42541"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="obtained new client token: AACPDLye8IP2KVKIKpVv64UDRViQX+Du+sPuW/+RvWM/mozV/ZvX8ZoEp0L8xBMOnGacl+Cc1gj70uBoxUYbvd5k/flsXMYXNU2FjOKcWV5xkwNtb6TLwbSCzwEYJwFJNcGarh6uPQe3sNjRYY+oxT3LgR5Tg/MH6aIO8ZTh/zA2hDhTIaCdfkkyTZk3RYTDXaR+EP4Rn0OzcBD6XJ9+BwkDzYh7Oql6bEeVAHg6b+PsW8xBhKkotAADPt0="
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+01:00" level=debug msg="completed challenge"
Mar 24 20:08:32 katarynka go-librespot[19508]: time="2026-03-24T20:08:32+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 "
Mar 24 20:08:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:32 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:32 katarynka volumio[19089]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:33 katarynka volumio[19089]: info: MYVOLUMIO: Adding device
Mar 24 20:08:33 katarynka volumio[19089]: info: MYVOLUMIO: Evaluating Server
Mar 24 20:08:34 katarynka volumio[19089]: info: Setting Geolocation for MyVolumio to eu11
Mar 24 20:08:34 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:34 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:34 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:34 katarynka volumio[19089]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Mar 24 20:08:35 katarynka volumio[19089]: info: Updating MyVolumio device info
Mar 24 20:08:35 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:35 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:35 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Mar 24 20:08:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:35 katarynka go-librespot[19533]: go-librespot daemon starting...
Mar 24 20:08:35 katarynka go-librespot[19534]: time="2026-03-24T20:08:35+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:35 katarynka go-librespot[19534]: time="2026-03-24T20:08:35+01:00" level=debug msg="app state loaded"
Mar 24 20:08:35 katarynka go-librespot[19534]: time="2026-03-24T20:08:35+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:35 katarynka volumio[19089]: info: Initializing connection to go-librespot Websocket
Mar 24 20:08:35 katarynka go-librespot[19534]: time="2026-03-24T20:08:35+01:00" level=debug msg="new websocket client"
Mar 24 20:08:35 katarynka volumio[19089]: info: Connection to go-librespot Websocket established
Mar 24 20:08:35 katarynka volumio[19089]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=info msg="zeroconf server listening on port 40453"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="obtained new client token: AACPLFifuKEnPnws35kb/YSoEqp2SZJp82p+f8PTJPj0ImII9AmG+o9DaCp/NXMpcBGsljT2z8yyiJ1kEeV5kqkSXZnChU9WEcQbmynYl39wg87OgPabUW9NAUCgTMLjLZQrtieTsPqpcS66St6udToG19uRBwIjjRiAVE6H0fao2h/tGpcMb3yY5CFAFJLhTSCVLj5RFRTVQ3NgMAwVEqXqwF58o0QMunjAULeBH43UIAoXkxAuRxdirrk="
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08:36+01:00" level=debug msg="completed challenge"
Mar 24 20:08:36 katarynka go-librespot[19534]: time="2026-03-24T20:08: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 "
Mar 24 20:08:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:36 katarynka volumio[19089]: info: Connection to go-librespot Websocket closed
Mar 24 20:08:37 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:37 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:37 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Mar 24 20:08:37 katarynka volumio-remote-updater[622]: Test mode disabled
Mar 24 20:08:37 katarynka volumio-remote-updater[622]: Alpha mode disabled
Mar 24 20:08:37 katarynka volumio-remote-updater[622]: Alpha legacy test mode disabled
Mar 24 20:08:37 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Mar 24 20:08:37 katarynka volumio[19089]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for BLE notification issues
\nFix for mDNS/BCT
\nFix wireless init on Pi
\nFix raspi-config abuse on Pi
\n
\nNEW ADDITIONS
\n\nBluetooth party mode
\nUpdate Tidal SDK
\nUpdate Qobuz Connect SDK
\n\n","title":"Update v4.103","updateavailable":true}
Mar 24 20:08:37 katarynka volumio[19089]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 24 20:08:38 katarynka volumio[19089]: info: Getting Spotify volume
Mar 24 20:08:38 katarynka volumio[19089]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 24 20:08:38 katarynka volumio[19089]: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:08:38 katarynka volumio[19089]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Mar 24 20:08:38 katarynka volumio[19089]:   errno: -111,
Mar 24 20:08:38 katarynka volumio[19089]:   code: 'ECONNREFUSED',
Mar 24 20:08:38 katarynka volumio[19089]:   syscall: 'connect',
Mar 24 20:08:38 katarynka volumio[19089]:   address: '127.0.0.1',
Mar 24 20:08:38 katarynka volumio[19089]:   port: 9879,
Mar 24 20:08:38 katarynka volumio[19089]:   response: undefined
Mar 24 20:08:38 katarynka volumio[19089]: }
Mar 24 20:08:38 katarynka volumio[19089]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 24 20:08:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Mar 24 20:08:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:39 katarynka go-librespot[19574]: go-librespot daemon starting...
Mar 24 20:08:39 katarynka go-librespot[19575]: time="2026-03-24T20:08:39+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:39 katarynka go-librespot[19575]: time="2026-03-24T20:08:39+01:00" level=debug msg="app state loaded"
Mar 24 20:08:39 katarynka go-librespot[19575]: time="2026-03-24T20:08:39+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=info msg="zeroconf server listening on port 38701"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="obtained new client token: AAACdHzRUnl/Oe+S/w9VplK8HEp0qO38aNpchMnu/2ecN4G6lAwz0ztgRECvBFSPXE0ApIWbrwysASvLn4ISw0/+qqD5E6yQv4VGdPW7qlRmJZp26Gf9Ta5RBp3B3yED8RlMURgKBywFxoG+LLuneJg8NBGcsRpv+J9ghQNETajkMP57lRBnS6+948y6BEVu+nSZ1B8SU/bp8DAZmKFZYJn9Ztmq4ewUMXizZArnCwu45ri/61yhlHEeY8Q="
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:40 katarynka sudo[19584]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 20:07'
Mar 24 20:08:40 katarynka sudo[19584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+01:00" level=debug msg="completed challenge"
Mar 24 20:08:40 katarynka go-librespot[19575]: time="2026-03-24T20:08:40+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 "
Mar 24 20:08:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:40 katarynka sudo[19584]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:40 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:40] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Mar 24 20:08:40 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:40] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Mar 24 20:08:40 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:41 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'.
Mar 24 20:08:41 katarynka systemd[1]: volumio.service: Consumed 51.713s CPU time.
Mar 24 20:08:41 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service.
Mar 24 20:08:41 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25337.
Mar 24 20:08:41 katarynka systemd[1]: dynamicswap.service: Deactivated successfully.
Mar 24 20:08:41 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module.
Mar 24 20:08:41 katarynka systemd[1]: volumio.service: Consumed 51.713s CPU time.
Mar 24 20:08:41 katarynka systemd[1]: Started volumio.service - Volumio Backend Module.
Mar 24 20:08:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Mar 24 20:08:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:43 katarynka go-librespot[19605]: go-librespot daemon starting...
Mar 24 20:08:43 katarynka go-librespot[19606]: time="2026-03-24T20:08:43+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:43 katarynka go-librespot[19606]: time="2026-03-24T20:08:43+01:00" level=debug msg="app state loaded"
Mar 24 20:08:43 katarynka go-librespot[19606]: time="2026-03-24T20:08:43+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=info msg="zeroconf server listening on port 43689"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="obtained new client token: AAB0Zy3ePz+4hWPUfST95xhul7Az0xV0xdeGFXnLvZ4uF0wScijgP9PZFNnHYiHRYrVIUw3LeOM+EEdz48Wst4D+lJyD2vWWpUezgC1P/NEpK6aXn1UD50fjxRs53/DZSXkuUPifM2v0HN19AidbKJrdlLmWMFbBQ3vuSwPTl75kXXqXymucr6GpMTnxVKmsh2WrgRtLH4FTfCkg6lK+wmprlVhEivhC3RQP1/GITY7xGqxB/eeGs0BUk/A="
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:44 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:08:44 katarynka volumio[19595]: info: -----            Volumio3              ----
Mar 24 20:08:44 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:44 katarynka go-librespot[19606]: time="2026-03-24T20:08:44+01:00" level=debug msg="completed challenge"
Mar 24 20:08:44 katarynka volumio[19595]: info: -----          System startup          ----
Mar 24 20:08:44 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:08:45 katarynka go-librespot[19606]: time="2026-03-24T20:08:45+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 "
Mar 24 20:08:45 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:45 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:45 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:45] [connect] Successful connection
Mar 24 20:08:46 katarynka volumio[19595]: info: MYVOLUMIO Environment detected
Mar 24 20:08:46 katarynka volumio[19595]: info: Plugin folders cleanup
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning into folder /volumio/app/plugins/
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category audio_interface
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category miscellanea
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category music_service
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category plugins.json
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category system_controller
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category user_interface
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning into folder /data/plugins/
Mar 24 20:08:46 katarynka volumio[19595]: info: Scanning category music_service
Mar 24 20:08:46 katarynka volumio[19595]: info: Plugin folders cleanup completed
Mar 24 20:08:46 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:08:46 katarynka volumio[19595]: info: -----      Core plugins startup        ----
Mar 24 20:08:46 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:08:46 katarynka volumio[19595]: info: Loading plugins from folder /volumio/app/plugins/
Mar 24 20:08:46 katarynka volumio[19595]: info: Adding plugin upnp to MyMusic Plugins
Mar 24 20:08:46 katarynka volumio[19595]: info: Adding plugin airplay_emulation to MyMusic Plugins
Mar 24 20:08:46 katarynka volumio[19595]: info: Adding plugin upnp_browser to MyMusic Plugins
Mar 24 20:08:46 katarynka volumio[19595]: info: Loading plugins from folder /data/plugins/
Mar 24 20:08:46 katarynka volumio[19595]: info: Loading plugin "system"...
Mar 24 20:08:46 katarynka volumio[19595]: info: Loading plugin "appearance"...
Mar 24 20:08:48 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Mar 24 20:08:48 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:48 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:48 katarynka go-librespot[19627]: go-librespot daemon starting...
Mar 24 20:08:48 katarynka go-librespot[19628]: time="2026-03-24T20:08:48+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:48 katarynka go-librespot[19628]: time="2026-03-24T20:08:48+01:00" level=debug msg="app state loaded"
Mar 24 20:08:48 katarynka go-librespot[19628]: time="2026-03-24T20:08:48+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:48 katarynka volumio[19595]: info: Loading plugin "network"...
Mar 24 20:08:48 katarynka volumio[19595]: info: Refreshing Cached IP Addresses
Mar 24 20:08:48 katarynka sudo[19635]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 24 20:08:48 katarynka sudo[19635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:48 katarynka sudo[19635]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:48 katarynka sudo[19637]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 24 20:08:48 katarynka sudo[19637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:48 katarynka volumio[19595]: info: Loading plugin "services"...
Mar 24 20:08:48 katarynka sudo[19637]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:48 katarynka volumio[19595]: info: Loading plugin "alsa_controller"...
Mar 24 20:08:48 katarynka sudo[19646]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Mar 24 20:08:48 katarynka sudo[19646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:48 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:48 katarynka volumio[19595]: info: Loading plugin "wizard"...
Mar 24 20:08:48 katarynka volumio[19595]: info: Loading plugin "networkfs"...
Mar 24 20:08:49 katarynka volumio[19595]: info: Starting Udev Watcher for removable devices
Mar 24 20:08:49 katarynka volumio[19595]: info: Ignoring mount for partition: boot
Mar 24 20:08:49 katarynka volumio[19595]: info: Ignoring mount for partition: volumio
Mar 24 20:08:49 katarynka volumio[19595]: info: Ignoring mount for partition: volumio_data
Mar 24 20:08:49 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 24 20:08:49 katarynka volumio[19595]: info: Loading plugin "volumio_command_line_client"...
Mar 24 20:08:49 katarynka volumio[19595]: info: Loading plugin "upnp"...
Mar 24 20:08:49 katarynka volumio[19595]: info: [1774379329133] Starting Upmpd Daemon
Mar 24 20:08:49 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 24 20:08:49 katarynka volumio[19595]: info: Loading plugin "my_music"...
Mar 24 20:08:49 katarynka volumio[19595]: info: Loading plugin "mpd"...
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=info msg="zeroconf server listening on port 36491"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="obtained new client token: AABZuYziaW9nQiONaWQIffa3W/iitOheq5F3TF5NBN+M+HwYpVbvaBq322GxaO1bG5pjuoDz43fZuiVrlfm68ANYVmNb0UggWWNzGJ367zcGp2HabBX93S232N8rIzind34R4olE0qE7Jlia6sX4GfaeOQFEzIrs5ShKiMqlWz2h3qsJVi9RTk66jD3kMN9vdAHkJBw28TfbbKsQJ/Pgm2O8xi3BSCyaliC3CA37L75cnnMYfn4y/QittLc="
Mar 24 20:08:49 katarynka sudo[19646]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+01:00" level=debug msg="completed challenge"
Mar 24 20:08:49 katarynka volumio[19595]: info: Loading plugin "upnp_browser"...
Mar 24 20:08:49 katarynka go-librespot[19628]: time="2026-03-24T20:08:49+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 "
Mar 24 20:08:49 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:49 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:51 katarynka wpa_supplicant[1161]: wlan0: WPA: Group rekeying completed with 84:a9:c4:23:8a:fc [GTK=TKIP]
Mar 24 20:08:52 katarynka volumio[19595]: info: Starting UPNP Browser
Mar 24 20:08:52 katarynka volumio[19595]: info: Loading plugin "alarm-clock"...
Mar 24 20:08:52 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Mar 24 20:08:52 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:52 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:52 katarynka go-librespot[19670]: go-librespot daemon starting...
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="app state loaded"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "airplay_emulation"...
Mar 24 20:08:53 katarynka volumio[19595]: info: Starting Shairport Sync
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "last_100"...
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "webradio"...
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "i2s_dacs"...
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "volumiodiscovery"...
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=info msg="zeroconf server listening on port 45163"
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** For more information see 
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:53 katarynka volumio[19595]: *** WARNING *** For more information see 
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** For more information see 
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 24 20:08:53 katarynka volumio[19595]: info: Applying required configuration parameters for plugin volumiodiscovery
Mar 24 20:08:53 katarynka node[19595]: *** WARNING *** For more information see 
Mar 24 20:08:53 katarynka volumio[19595]: info: Discovery: Started advertising with name: katarynka
Mar 24 20:08:53 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 24 20:08:53 katarynka volumio[19595]: info: Loading plugin "spop"...
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="obtained new client token: AABCxP/c/8Zda7xbB/TNEoXBqEShkbOwWfTdWK24oqCBQzyeoLfrLLsJQHl2nDx51wlRNPKnK5TG34pn4ykkTT73N/TQiRW6JdBdz1ovPdnSB6bMK7qQJT1pJAj4tQVzhZvrU+81ROsqV1cyjLMivv6NhXSbXBFf0Cjvn8x1M15nJCtVNKpm4pdeAESw+1l++9vdjQnA/swDYLg0MU/MZuerSH+A00krGyYedPuqbC+YW++4NtFVhXfyvEw="
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+01:00" level=debug msg="completed challenge"
Mar 24 20:08:53 katarynka go-librespot[19671]: time="2026-03-24T20:08:53+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 "
Mar 24 20:08:53 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:53 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "outputs"...
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "albumart"...
Mar 24 20:08:55 katarynka volumio[19595]: info: Plugin example_plugin is not enabled
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "inputs"...
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "updater_comm"...
Mar 24 20:08:55 katarynka volumio[19595]: info: Plugin mpdemulation is not enabled
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "rest_api"...
Mar 24 20:08:55 katarynka volumio[19595]: info: Loading plugin "websocket"...
Mar 24 20:08:56 katarynka volumio[19595]: info: Starting Socket.io Server version 1.7.4
Mar 24 20:08:56 katarynka volumio[19595]: info: Loading i18n strings for locale pl
Mar 24 20:08:56 katarynka volumio[19595]: Updating browse sources language
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::initPlayerControls
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: Express server listening on port 3000
Mar 24 20:08:56 katarynka volumio[19595]:  [Metrics]  WebUI:  12s 423.56ms 
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::resetVolumioState
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::getcurrentVolume
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::volumioRetrievevolume
Mar 24 20:08:56 katarynka volumio[19595]: info: Cannot read play queue from file
Mar 24 20:08:56 katarynka volumio[19595]: info: Volumio Network Manager: Network status updated: 2
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::setRepeat null single undefined
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::pushState
Mar 24 20:08:56 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 24 20:08:56 katarynka volumio[19681]: Forking 3 albumart workers
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::setRandom null
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::pushState
Mar 24 20:08:56 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:56 katarynka volumio[19595]: info: Setting Device type: Raspberry PI
Mar 24 20:08:56 katarynka volumio[19595]: info: Completed loading Core Plugins
Mar 24 20:08:56 katarynka volumio[19595]: info: Preparing to generate the ALSA configuration file
Mar 24 20:08:56 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Mar 24 20:08:56 katarynka volumio[19595]: info: VolumeController:: Volume=96 Mute =false
Mar 24 20:08:56 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::pushState
Mar 24 20:08:56 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::volumioPushState
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreStateMachine::updateTrackBlock
Mar 24 20:08:56 katarynka volumio[19595]: info: CorePlayQueue::getTrackBlock
Mar 24 20:08:56 katarynka volumio[19595]: info: CoreCommandRouter::volumioRetrievevolume
Mar 24 20:08:56 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:08:56 katarynka go-librespot[19711]: go-librespot daemon starting...
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=debug msg="app state loaded"
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:08:57 katarynka volumio[19595]: info: Asound.conf file unchanged, so no further update is needed
Mar 24 20:08:57 katarynka volumio[19595]: info: Output device has changed, restarting MPD
Mar 24 20:08:57 katarynka sudo[19741]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 24 20:08:57 katarynka sudo[19741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:57 katarynka volumio[19595]: info: Output device has changed, restarting Shairport Sync
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:57 katarynka sudo[19741]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:57 katarynka sudo[19745]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 24 20:08:57 katarynka sudo[19745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:57 katarynka volumio[19595]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:57 katarynka volumio[19595]: info: ___________ START PLUGINS ___________
Mar 24 20:08:57 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon...
Mar 24 20:08:57 katarynka volumio[19595]: info: ControllerMpd::onStart: Initializing MPD
Mar 24 20:08:57 katarynka volumio[19595]: info: Creating MPD Configuration file
Mar 24 20:08:57 katarynka systemd[1]: mpd.service: Deactivated successfully.
Mar 24 20:08:57 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 24 20:08:57 katarynka systemd[1]: mpd.service: Consumed 7.809s CPU time.
Mar 24 20:08:57 katarynka systemd[1]: mpd.socket: Deactivated successfully.
Mar 24 20:08:57 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:57 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:57 katarynka sudo[19756]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 24 20:08:57 katarynka sudo[19756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:57 katarynka sudo[19756]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:57 katarynka sudo[19758]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 24 20:08:57 katarynka sudo[19758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:08:57 katarynka volumio[19595]: info: [1774379337717] CoreMusicLibrary::Adding element Serwery Mediów
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=info msg="zeroconf server listening on port 41217"
Mar 24 20:08:57 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:57 katarynka systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 24 20:08:57 katarynka volumio[19595]: info: UPNP Browser: Client initialized successfully
Mar 24 20:08:57 katarynka systemd[1]: mpd.service: Deactivated successfully.
Mar 24 20:08:57 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 24 20:08:57 katarynka systemd[1]: mpd.socket: Deactivated successfully.
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:57 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:57 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:57 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 24 20:08:57 katarynka go-librespot[19724]: time="2026-03-24T20:08:57+01:00" level=debug msg="obtained new client token: AAD/NvMStKDfi7cJ2XPSnWp8oL3WwU/LADqVBQCMv6curjRcf73HAU09D+D0czY9PvslKevaTENmN4Nkzaxq8TALPlzECBvmbutzstlSqN955kiXmvloSJfZO676lU2nln6yxYcgqInjK5k8fvBer4yHpOP0JiGZHn2/ZmDWVJPK2wtDfvk5ls7Z9QKSrVixqkgWlkH4bx1W1bOyu8RcCk94crtGR8pPZ59gSu5sbbtGHSc1Dk0J3JELMyM="
Mar 24 20:08:57 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 24 20:08:58 katarynka volumio[19595]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:58 katarynka systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 24 20:08:58 katarynka go-librespot[19724]: time="2026-03-24T20:08:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:08:58 katarynka go-librespot[19724]: time="2026-03-24T20:08:58+01:00" level=debug msg="completed keyexchange"
Mar 24 20:08:58 katarynka go-librespot[19724]: time="2026-03-24T20:08:58+01:00" level=debug msg="completed challenge"
Mar 24 20:08:58 katarynka volumio[19595]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:58 katarynka volumio[19595]: info: [1774379338134] CoreMusicLibrary::Adding element Last_100
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 24 20:08:58 katarynka volumio[19595]: info: [1774379338147] CoreMusicLibrary::Adding element Webradio
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:58 katarynka go-librespot[19724]: time="2026-03-24T20:08:58+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 "
Mar 24 20:08:58 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:08:58 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:08:58 katarynka volumio[19595]: info: Initializing BBC Radios
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:08:58 katarynka volumio[19595]: info: Creating Spotify config file
Mar 24 20:08:58 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:08:58 katarynka volumio-remote-updater[622]: [2026-03-24 20:08:58] [connect] Successful connection
Mar 24 20:08:58 katarynka sudo[19768]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 24 20:08:58 katarynka sudo[19768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 24 20:08:58 katarynka sudo[19768]: pam_unix(sudo:session): session closed for user root
Mar 24 20:08:59 katarynka volumio[19595]: info: Volumio Calling Home
Mar 24 20:09:00 katarynka sudo[19808]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 24 20:09:00 katarynka sudo[19808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:00 katarynka sudo[19808]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:00 katarynka sudo[19806]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 24 20:09:00 katarynka sudo[19806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:00 katarynka sudo[19806]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:00 katarynka volumio[19595]: info: MPD Permissions set
Mar 24 20:09:00 katarynka volumio[19595]: info: MPD Permissions set
Mar 24 20:09:00 katarynka volumio[19595]: info: VolumeController:: Volume=96 Mute =false
Mar 24 20:09:00 katarynka volumio[19595]: info: CoreStateMachine::pushState
Mar 24 20:09:00 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:00 katarynka volumio[19595]: info: CoreCommandRouter::volumioPushState
Mar 24 20:09:00 katarynka volumio[19595]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51
Mar 24 20:09:00 katarynka volumio[19595]: info: Discovery: Found device katarynka
Mar 24 20:09:00 katarynka volumio[19595]: info: CoreCommandRouter::volumioGetState
Mar 24 20:09:00 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:00 katarynka volumio-remote-updater[622]: [2026-03-24 20:09:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774379338 101
Mar 24 20:09:00 katarynka volumio[19595]: 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: 1
Mar 24 20:09:00 katarynka volumio[19595]: info: Volumio called home
Mar 24 20:09:00 katarynka volumio[19595]: info: Spotify config file written
Mar 24 20:09:00 katarynka volumio[19595]: info: Discovery: this is already registered,  4d616d77-6a8c-4da2-85a4-840d70f98e51
Mar 24 20:09:00 katarynka volumio[19595]: info: Discovery: Found device katarynka
Mar 24 20:09:00 katarynka volumio[19595]: info: CoreCommandRouter::volumioGetState
Mar 24 20:09:00 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:00 katarynka volumio[19702]: Starting albumart workers
Mar 24 20:09:01 katarynka sudo[19812]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Mar 24 20:09:01 katarynka sudo[19812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:01 katarynka volumio[19701]: Starting albumart workers
Mar 24 20:09:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:01 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:01 katarynka go-librespot[19814]: go-librespot daemon starting...
Mar 24 20:09:01 katarynka sudo[19812]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:01 katarynka volumio[19700]: Starting albumart workers
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=debug msg="app state loaded"
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:09:01 katarynka volumio[19595]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 24 20:09:01 katarynka volumio[19595]: info: No need to fix Spotify hosts
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:09:01 katarynka go-librespot[19815]: time="2026-03-24T20:09:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+01:00" level=info msg="zeroconf server listening on port 39103"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+01:00" level=debug msg="obtained new client token: AAArC9QnUEpwRH0rB6aNReJeNuEPeKRLHMdcSnBEaS4fcO2h91AwyrcHsaZ8PT3QwA+0UqwHKCbR0Qbci+qdL66bubmfrtdjRcSJt5vO7bBu8MR2y2RfM/8N/eXBfcAlx1k076tmT4C6QRhEYps4PKMLnh9f6sLS46q4kY3lxnMiCaBEX/c3euW2m6oTVEf1vURsFCPn6QLl2g1+9OlCRLat4mBUvWm0G0CBktT3TCwsdZenYdIbsKYB"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+01:00" level=debug msg="completed keyexchange"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+01:00" level=debug msg="completed challenge"
Mar 24 20:09:02 katarynka go-librespot[19815]: time="2026-03-24T20:09:02+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 "
Mar 24 20:09:02 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:09:02 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:09:02 katarynka volumio[19595]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Mar 24 20:09:02 katarynka volumio[19595]: info: Starting Shairport Sync
Mar 24 20:09:02 katarynka volumio[19595]: info: Starting Shairport Sync
Mar 24 20:09:02 katarynka volumio[19595]: info: Starting Shairport Sync
Mar 24 20:09:02 katarynka sudo[19835]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:09:02 katarynka sudo[19837]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:09:02 katarynka sudo[19835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:02 katarynka sudo[19837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:02 katarynka sudo[19839]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 24 20:09:02 katarynka sudo[19839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:02 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 24 20:09:02 katarynka sudo[19841]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Mar 24 20:09:02 katarynka sudo[19841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:02 katarynka systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 24 20:09:02 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:09:02 katarynka systemd[1]: shairport-sync.service: Consumed 2.519s CPU time.
Mar 24 20:09:03 katarynka volumio[19595]: info: CoreCommandRouter::volumioGetState
Mar 24 20:09:03 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:03 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:09:03 katarynka sudo[19835]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:03 katarynka volumio[19595]: info: Shairport-Sync Started
Mar 24 20:09:03 katarynka volumio[19595]: Error adding Membership: Error: addMembership EINVAL
Mar 24 20:09:03 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 24 20:09:03 katarynka systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 24 20:09:03 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:09:03 katarynka sudo[19841]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:03 katarynka volumio[19595]: info: Upmpdcli Daemon Started
Mar 24 20:09:03 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 24 20:09:03 katarynka sudo[19839]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:03 katarynka volumio[19595]: info: Shairport-Sync Started
Mar 24 20:09:03 katarynka sudo[19837]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:03 katarynka volumio[19595]: info: Shairport-Sync Started
Mar 24 20:09:05 katarynka volumio[19595]: info: go-librespot daemon successfully initialized
Mar 24 20:09:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Mar 24 20:09:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:05 katarynka go-librespot[19880]: go-librespot daemon starting...
Mar 24 20:09:05 katarynka go-librespot[19881]: time="2026-03-24T20:09:05+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:09:05 katarynka go-librespot[19881]: time="2026-03-24T20:09:05+01:00" level=debug msg="app state loaded"
Mar 24 20:09:05 katarynka go-librespot[19881]: time="2026-03-24T20:09:05+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:09:06 katarynka mpd[19787]: 2026-03-24T20:09:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 24 20:09:06 katarynka systemd[1]: Started mpd.service - Music Player Daemon.
Mar 24 20:09:06 katarynka sudo[19758]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:06 katarynka sudo[19745]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:09:06 katarynka volumio[19595]: info: Completed starting Core Plugins
Mar 24 20:09:06 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:09:06 katarynka volumio[19595]: info: -----    MyVolumio plugins startup     ----
Mar 24 20:09:06 katarynka volumio[19595]: info: -------------------------------------------
Mar 24 20:09:06 katarynka volumio[19595]: info: [MyVolumio PluginManager] Fetching plans data....
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=info msg="zeroconf server listening on port 40149"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="obtained new client token: AAD41+cX+MjaBrWoPbdUDeuaNFleYNOPo61A2fDPt9LQZoJVAvOXzojXR9jh8poDoRl/fN3iJCXaQhvPLGvLC6BlTi41jw4PMYFAJnZuLCfhnBXjOJ+voUp4XtNyHPFCiJ/wJUX/Um5UisS9MFlfJwr1etJ1DUz/kUUjMfH5Www/L1UVKJR4FWmHogCfNWdcKV/mKlTAl7xiHMxwjt9GmVZKMjtjP9EU+eTRDIuVg6k04UF73BuDJGbXG+g="
Mar 24 20:09:06 katarynka volumio[19595]: error: MPD error: The expression evaluated to a falsy value:
Mar 24 20:09:06 katarynka volumio[19595]:   assert.ok(self.idling)
Mar 24 20:09:06 katarynka volumio[19595]: error: The expression evaluated to a falsy value:
Mar 24 20:09:06 katarynka volumio[19595]:   assert.ok(self.idling)
Mar 24 20:09:06 katarynka volumio[19595]: info: MPD running with PID19787
Mar 24 20:09:06 katarynka volumio[19595]:  ,establishing connection
Mar 24 20:09:06 katarynka volumio[19595]: error: updateQueue error: null
Mar 24 20:09:06 katarynka volumio[19595]: error: updateQueue error: null
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="completed keyexchange"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+01:00" level=debug msg="completed challenge"
Mar 24 20:09:06 katarynka go-librespot[19881]: time="2026-03-24T20:09:06+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 "
Mar 24 20:09:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:09:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:09:08 katarynka volumio[19595]: info: Initializing connection to go-librespot Websocket
Mar 24 20:09:08 katarynka volumio[19595]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:09:09 katarynka sudo[19908]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 24 20:09:09 katarynka sudo[19908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:09 katarynka sudo[19910]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 24 20:09:09 katarynka sudo[19910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:09 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Mar 24 20:09:09 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully.
Mar 24 20:09:09 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Mar 24 20:09:09 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Mar 24 20:09:09 katarynka sudo[19910]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:09 katarynka sudo[19908]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:09 katarynka mpd_monitor.sh[19913]: MPD Monitor Service: Starting MPD Monitor Service
Mar 24 20:09:09 katarynka volumio[19595]: info: Successfully started MPD Monitor
Mar 24 20:09:09 katarynka volumio[19595]: info: Successfully started MPD Monitor
Mar 24 20:09:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Mar 24 20:09:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:09 katarynka go-librespot[19917]: go-librespot daemon starting...
Mar 24 20:09:09 katarynka go-librespot[19918]: time="2026-03-24T20:09:09+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:09:09 katarynka go-librespot[19918]: time="2026-03-24T20:09:09+01:00" level=debug msg="app state loaded"
Mar 24 20:09:09 katarynka go-librespot[19918]: time="2026-03-24T20:09:09+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=info msg="zeroconf server listening on port 37121"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="obtained new client token: AADAbBY+iNUg9lYsbmYd6fDRpXV1/OaiMqunYfEiDqRFjEgj0AuPk27/YZUUClO6Vh/+USQxm2CdhETQYZ8+x9lltppG10+30nyVg3GZca+2yuy5g1vOJd2hanKxPgt4rcNkSF8OvVsAgEdusgpjVIpYP85Ya1VPOtz6cPfsmSldME/uHCklBkKpPIqYgAPBlLDXW84Wfm10UbZJEgSraUdhn//66Z+GCiNiKgB/NfBzTF99T40xMBRxaHs="
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="completed keyexchange"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+01:00" level=debug msg="completed challenge"
Mar 24 20:09:10 katarynka go-librespot[19918]: time="2026-03-24T20:09:10+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 "
Mar 24 20:09:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:09:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:09:11 katarynka volumio[19595]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Mar 24 20:09:11 katarynka volumio[19595]: info: Initializing connection to go-librespot Websocket
Mar 24 20:09:11 katarynka volumio[19595]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 24 20:09:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Mar 24 20:09:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:13 katarynka go-librespot[19925]: go-librespot daemon starting...
Mar 24 20:09:13 katarynka go-librespot[19926]: time="2026-03-24T20:09:13+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:09:13 katarynka go-librespot[19926]: time="2026-03-24T20:09:13+01:00" level=debug msg="app state loaded"
Mar 24 20:09:13 katarynka go-librespot[19926]: time="2026-03-24T20:09:13+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=info msg="zeroconf server listening on port 41883"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="obtained new client token: AACEneOBeOeg6mTD3tG/lQXbbwhFOIwBGFEiOHaXbDM6P0V+lYg5rKZ1ns8pdnqWmSPJek5GmRyGk7oTbq38Ml3P2nGcWRdcX1VIkhfHRr/CyxbOu5ORlRL4NwFg+ZocGsA8Pff9NcsXYRusxYOZ8ldhgm8TtFzdLN7uPJZh7NPJD+XdbGWpXqXik2Ct0SGjWgFhbANqRIvkMJRSePYxBYcNv5FZSbmpZqM0HpiMAKCbdRx5IICCXqOwM64="
Mar 24 20:09:14 katarynka volumio[19595]: info: Initializing connection to go-librespot Websocket
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="new websocket client"
Mar 24 20:09:14 katarynka volumio[19595]: info: Connection to go-librespot Websocket established
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin bluetooth to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin multiroom to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin metavolumio to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin cd_controller to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin qobuzconnect to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin smart_inputs to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: Adding plugin tidalconnect to MyMusic Plugins
Mar 24 20:09:14 katarynka volumio[19595]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="completed keyexchange"
Mar 24 20:09:14 katarynka go-librespot[19926]: time="2026-03-24T20:09:14+01:00" level=debug msg="completed challenge"
Mar 24 20:09:15 katarynka go-librespot[19926]: time="2026-03-24T20:09:15+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 "
Mar 24 20:09:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:09:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:09:16 katarynka volumio[19595]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Mar 24 20:09:16 katarynka volumio[19595]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Mar 24 20:09:16 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:09:16 katarynka volumio[19595]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 24 20:09:16 katarynka volumio[19595]: info: Starting MyVolumio Remote Streaming Endpoints
Mar 24 20:09:16 katarynka volumio[19595]: info: MyVolumio login type: Token
Mar 24 20:09:16 katarynka volumio[19595]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Mar 24 20:09:16 katarynka volumio[19595]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Mar 24 20:09:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Mar 24 20:09:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 24 20:09:18 katarynka go-librespot[19933]: go-librespot daemon starting...
Mar 24 20:09:18 katarynka go-librespot[19934]: time="2026-03-24T20:09:18+01:00" level=info msg="running go-librespot 0.4.0"
Mar 24 20:09:18 katarynka go-librespot[19934]: time="2026-03-24T20:09:18+01:00" level=debug msg="app state loaded"
Mar 24 20:09:18 katarynka go-librespot[19934]: time="2026-03-24T20:09:18+01:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 24 20:09:18 katarynka volumio[19595]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Mar 24 20:09:18 katarynka volumio[19595]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Mar 24 20:09:18 katarynka volumio[19595]: info: Streaming services startup
Mar 24 20:09:18 katarynka volumio[19595]: info: Starting Streaming Daemon
Mar 24 20:09:18 katarynka sudo[19942]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Mar 24 20:09:18 katarynka sudo[19942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 24 20:09:18 katarynka volumio[19595]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Mar 24 20:09:18 katarynka sudo[19942]: pam_unix(sudo:session): session closed for user root
Mar 24 20:09:18 katarynka volumio[19595]: info: Getting Spotify volume
Mar 24 20:09:18 katarynka volumio[19595]: info: Connection to go-librespot Websocket closed
Mar 24 20:09:18 katarynka volumio[19595]: error: Cannot start Volumio Streaming Daemon
Mar 24 20:09:18 katarynka volumio[19595]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Mar 24 20:09:18 katarynka volumio[19595]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Mar 24 20:09:18 katarynka volumio[19595]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=info msg="zeroconf server listening on port 37733"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="obtained new client token: AAAYo74TdCXCADeV0rh7gkLmnsInR9TLdGzoCM3kQNdLOq+uBtyUxCdUOPdAh0JyvsTgdPaepLzyl+R9AdATFjQnJjmmYEYFySb6GJhNZcoQnVeq0CIT3FvwFGUfBXqez7PaLF+1ZX4phpIZw7AcLEKqWF04MW9koEyZB/zXPV1QPvULuDeUqKHMakHnVDGcinKjXj0gNpB8RG28QvDxz/vt8Zk1jN90eBALyOs6KyAEoYE4QOA9acuP"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Mar 24 20:09:19 katarynka volumio[19595]: info: CoreCommandRouter::volumioGetState
Mar 24 20:09:19 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="completed keyexchange"
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+01:00" level=debug msg="completed challenge"
Mar 24 20:09:19 katarynka volumio[19595]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96
Mar 24 20:09:19 katarynka volumio[19595]: SPOTIFY: SPOTIFY VOLUME undefined
Mar 24 20:09:19 katarynka volumio[19595]: SPOTIFY: VOLUMIO VOLUME 96
Mar 24 20:09:19 katarynka volumio[19595]: info: Aligning Spotify Volume to Volumio Volume
Mar 24 20:09:19 katarynka volumio[19595]: info: CoreCommandRouter::volumioGetState
Mar 24 20:09:19 katarynka volumio[19595]: info: CorePlayQueue::getTrack 0
Mar 24 20:09:19 katarynka volumio[19595]: info: Setting Spotify Volume from Volumio: 96
Mar 24 20:09:19 katarynka go-librespot[19934]: time="2026-03-24T20:09:19+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 "
Mar 24 20:09:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 24 20:09:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 24 20:09:19 katarynka volumio[19595]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 24 20:09:19 katarynka volumio[19595]: Error: socket hang up
Mar 24 20:09:19 katarynka volumio[19595]:     at connResetException (node:internal/errors:720:14)
Mar 24 20:09:19 katarynka volumio[19595]:     at Socket.socketOnEnd (node:_http_client:519:23)
Mar 24 20:09:19 katarynka volumio[19595]:     at Socket.emit (node:events:526:35)
Mar 24 20:09:19 katarynka volumio[19595]:     at endReadableNT (node:internal/streams/readable:1376:12)
Mar 24 20:09:19 katarynka volumio[19595]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Mar 24 20:09:19 katarynka volumio[19595]:   code: 'ECONNRESET',
Mar 24 20:09:19 katarynka volumio[19595]:   response: undefined
Mar 24 20:09:19 katarynka volumio[19595]: }
Mar 24 20:09:19 katarynka volumio[19595]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 24 20:09:20 katarynka sudo[19977]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 20:08'
Mar 24 20:09:20 katarynka sudo[19977]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Dec  5 20:42:14 UTC 2025"
VOLUMIO_VERSION="4.073"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"