Mar 25 22:55:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:00 katarynka go-librespot[1275]: go-librespot daemon starting... Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=debug msg="app state loaded" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+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 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+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 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+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 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=info msg="zeroconf server listening on port 43995" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=debug msg="obtained new client token: AACi1wUKVLFRyetNx8yPgaBJUsZhcuPad4Fz10j5xdKp2j9VowmVwCQ8WW0ZjZ61k6R7jsGCEdGCdCosEpiiRFjDNi/ggxKtdFVptr7xr2dBB8xoNhgEDAMM9g1UrbuK9d4WO8q+h/Q+/g5hYhyyvCzeDBNI6Bjx6ySf+kVr3KzZ4m0FzmUbMwVza/uJH6G4RCninWnAFF1p+fvedZX2CMeVZpi2EgpdNcD2QjhugeTOcCvNmQsNOMoM5go=" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+01:00" level=debug msg="completed challenge" Mar 25 22:55:00 katarynka go-librespot[1276]: time="2026-03-25T22:55:00+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 25 22:55:00 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:00 katarynka volumio[1259]: info: ----- Volumio3 ---- Mar 25 22:55:00 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:00 katarynka volumio[1259]: info: ----- System startup ---- Mar 25 22:55:00 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:01 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:01] [connect] Successful connection Mar 25 22:55:02 katarynka volumio[1259]: info: MYVOLUMIO Environment detected Mar 25 22:55:02 katarynka volumio[1259]: info: Plugin folders cleanup Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning into folder /volumio/app/plugins/ Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category audio_interface Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category miscellanea Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category music_service Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category plugins.json Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category system_controller Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category user_interface Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning into folder /data/plugins/ Mar 25 22:55:02 katarynka volumio[1259]: info: Scanning category music_service Mar 25 22:55:02 katarynka volumio[1259]: info: Plugin folders cleanup completed Mar 25 22:55:02 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:02 katarynka volumio[1259]: info: ----- Core plugins startup ---- Mar 25 22:55:02 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:02 katarynka volumio[1259]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 22:55:02 katarynka volumio[1259]: info: Adding plugin upnp to MyMusic Plugins Mar 25 22:55:02 katarynka volumio[1259]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 22:55:02 katarynka volumio[1259]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 22:55:02 katarynka volumio[1259]: info: Loading plugins from folder /data/plugins/ Mar 25 22:55:02 katarynka volumio[1259]: info: Loading plugin "system"... Mar 25 22:55:02 katarynka volumio[1259]: info: Loading plugin "appearance"... Mar 25 22:55:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 22:55:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:04 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:04 katarynka go-librespot[1303]: go-librespot daemon starting... Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=debug msg="app state loaded" Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+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 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+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 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+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 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=info msg="zeroconf server listening on port 40879" Mar 25 22:55:04 katarynka volumio[1259]: info: Loading plugin "network"... Mar 25 22:55:04 katarynka volumio[1259]: info: Refreshing Cached IP Addresses Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=debug msg="obtained new client token: AADFRfqzCXyP0MeeLN5ywY8zmVFDJ65J6L3iyHf5qS930Ha96+FEROrhQiRyeGwBQAAakSP3+Afp/eoVp0C25KiKnuq1fNRcJS+3tnn8lgDvPLj+seKTHcM7wzmXt90Z1rDimIejWfzQ9UcArZvl2/PILW8bqvaRkrFOqluPEk/Q7LjvO6Xv3M3TRw9leOyMXv3FzVyV6fFWe4SemQcBmuuf+dbHinwOd76OZHpkaOUtzbUbc6LTNDGbY0M=" Mar 25 22:55:04 katarynka sudo[1314]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 22:55:04 katarynka sudo[1314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:04 katarynka sudo[1316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 22:55:04 katarynka sudo[1314]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:04 katarynka sudo[1316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:04 katarynka volumio[1259]: info: Loading plugin "services"... Mar 25 22:55:04 katarynka sudo[1316]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:04 katarynka volumio[1259]: info: Loading plugin "alsa_controller"... Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:04 katarynka go-librespot[1304]: time="2026-03-25T22:55:04+01:00" level=debug msg="completed challenge" Mar 25 22:55:04 katarynka sudo[1324]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 22:55:04 katarynka sudo[1324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:04 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:55:04 katarynka volumio[1259]: info: Loading plugin "wizard"... Mar 25 22:55:04 katarynka volumio[1259]: info: Loading plugin "networkfs"... Mar 25 22:55:05 katarynka volumio[1259]: info: Starting Udev Watcher for removable devices Mar 25 22:55:05 katarynka volumio[1259]: info: Ignoring mount for partition: boot Mar 25 22:55:05 katarynka volumio[1259]: info: Ignoring mount for partition: volumio Mar 25 22:55:05 katarynka volumio[1259]: info: Ignoring mount for partition: volumio_data Mar 25 22:55:05 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:05 katarynka volumio[1259]: info: Loading plugin "volumio_command_line_client"... Mar 25 22:55:05 katarynka go-librespot[1304]: time="2026-03-25T22:55:05+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 25 22:55:05 katarynka volumio[1259]: info: Loading plugin "upnp"... Mar 25 22:55:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:05 katarynka volumio[1259]: info: [1774475705108] Starting Upmpd Daemon Mar 25 22:55:05 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:05 katarynka volumio[1259]: info: Loading plugin "my_music"... Mar 25 22:55:05 katarynka volumio[1259]: info: Loading plugin "mpd"... Mar 25 22:55:05 katarynka sudo[1324]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:05 katarynka volumio[1259]: info: Loading plugin "upnp_browser"... Mar 25 22:55:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 22:55:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:08 katarynka go-librespot[1348]: go-librespot daemon starting... Mar 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+01:00" level=debug msg="app state loaded" Mar 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+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 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+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 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+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 25 22:55:08 katarynka volumio[1259]: info: Starting UPNP Browser Mar 25 22:55:08 katarynka volumio[1259]: info: Loading plugin "alarm-clock"... Mar 25 22:55:08 katarynka go-librespot[1349]: time="2026-03-25T22:55:08+01:00" level=info msg="zeroconf server listening on port 46651" Mar 25 22:55:09 katarynka go-librespot[1349]: time="2026-03-25T22:55:09+01:00" level=debug msg="obtained new client token: AAAoDJqDexgbl20a57FYkuV8CEVRMVidMLPnIzSL6T7JELIhoC5W210kJHeyiHR1sZ7EQIi3Jy62c2Rs2bLaWsZBl+GciDBeKDYoMVDDAhAKrD+QpS0VUADuLlHa+VKax9MPO4tfEpmTr6G2IA/bpdtD3DFD4xY1f0pLKte6v9YtYYmvfTnDOgV/TFIKBTwXmRRuLxyV9GfqpMlvGj/sHqPiY0NHOTy2wzQNy7BsZ2NfwHe94KdPyxF0" Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "airplay_emulation"... Mar 25 22:55:09 katarynka volumio[1259]: info: Starting Shairport Sync Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "last_100"... Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "webradio"... Mar 25 22:55:09 katarynka go-librespot[1349]: time="2026-03-25T22:55:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "i2s_dacs"... Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "volumiodiscovery"... Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** For more information see Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:09 katarynka volumio[1259]: *** WARNING *** For more information see Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** For more information see Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:09 katarynka node[1259]: *** WARNING *** For more information see Mar 25 22:55:09 katarynka volumio[1259]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 22:55:09 katarynka volumio[1259]: info: Discovery: Started advertising with name: katarynka Mar 25 22:55:09 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:09 katarynka volumio[1259]: info: Loading plugin "spop"... Mar 25 22:55:09 katarynka go-librespot[1349]: time="2026-03-25T22:55:09+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:09 katarynka go-librespot[1349]: time="2026-03-25T22:55:09+01:00" level=debug msg="completed challenge" Mar 25 22:55:09 katarynka go-librespot[1349]: time="2026-03-25T22:55:09+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 25 22:55:09 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:09 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "outputs"... Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "albumart"... Mar 25 22:55:11 katarynka volumio[1259]: info: Plugin example_plugin is not enabled Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "inputs"... Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "updater_comm"... Mar 25 22:55:11 katarynka volumio[1259]: info: Plugin mpdemulation is not enabled Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "rest_api"... Mar 25 22:55:11 katarynka volumio[1259]: info: Loading plugin "websocket"... Mar 25 22:55:12 katarynka volumio[1259]: info: Starting Socket.io Server version 1.7.4 Mar 25 22:55:12 katarynka volumio[1259]: info: Loading i18n strings for locale pl Mar 25 22:55:12 katarynka volumio[1259]: Updating browse sources language Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::initPlayerControls Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: Express server listening on port 3000 Mar 25 22:55:12 katarynka volumio[1259]: [Metrics] WebUI: 12s 578.92ms Mar 25 22:55:12 katarynka volumio[1259]: info: CoreStateMachine::resetVolumioState Mar 25 22:55:12 katarynka volumio[1259]: info: CoreStateMachine::getcurrentVolume Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 22:55:12 katarynka volumio[1259]: info: Cannot read play queue from file Mar 25 22:55:12 katarynka volumio[1259]: info: Volumio Network Manager: Network status updated: 2 Mar 25 22:55:12 katarynka volumio[1362]: Forking 3 albumart workers Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:12 katarynka volumio[1259]: info: VolumeController:: Volume=96 Mute =false Mar 25 22:55:12 katarynka volumio[1259]: info: CoreStateMachine::pushState Mar 25 22:55:12 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:12 katarynka volumio[1259]: info: CoreStateMachine::updateTrackBlock Mar 25 22:55:12 katarynka volumio[1259]: info: CorePlayQueue::getTrackBlock Mar 25 22:55:12 katarynka volumio[1259]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 22:55:12 katarynka volumio[1259]: info: Setting Device type: Raspberry PI Mar 25 22:55:12 katarynka volumio[1259]: info: CoreStateMachine::setRepeat null single undefined Mar 25 22:55:13 katarynka volumio[1259]: info: CoreStateMachine::pushState Mar 25 22:55:13 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:13 katarynka volumio[1259]: info: CoreStateMachine::setRandom null Mar 25 22:55:13 katarynka volumio[1259]: info: CoreStateMachine::pushState Mar 25 22:55:13 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:13 katarynka volumio[1259]: info: Completed loading Core Plugins Mar 25 22:55:13 katarynka volumio[1259]: info: Preparing to generate the ALSA configuration file Mar 25 22:55:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 22:55:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:13 katarynka go-librespot[1417]: go-librespot daemon starting... Mar 25 22:55:13 katarynka volumio[1259]: info: Asound.conf file unchanged, so no further update is needed Mar 25 22:55:13 katarynka volumio[1259]: info: Output device has changed, restarting MPD Mar 25 22:55:13 katarynka volumio[1259]: info: Output device has changed, restarting Shairport Sync Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:13 katarynka go-librespot[1418]: time="2026-03-25T22:55:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:13 katarynka go-librespot[1418]: time="2026-03-25T22:55:13+01:00" level=debug msg="app state loaded" Mar 25 22:55:13 katarynka go-librespot[1418]: time="2026-03-25T22:55:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:13 katarynka sudo[1420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 22:55:13 katarynka sudo[1420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:13 katarynka sudo[1420]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:13 katarynka volumio[1259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:55:13 katarynka volumio[1259]: info: ___________ START PLUGINS ___________ Mar 25 22:55:13 katarynka sudo[1428]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 22:55:13 katarynka sudo[1428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:13 katarynka volumio[1259]: info: ControllerMpd::onStart: Initializing MPD Mar 25 22:55:13 katarynka volumio[1259]: info: Creating MPD Configuration file Mar 25 22:55:13 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 22:55:13 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:55:13 katarynka volumio[1259]: info: [1774475713671] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:55:13 katarynka sudo[1438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 22:55:13 katarynka sudo[1438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:13 katarynka volumio[1259]: info: UPNP Browser: Client initialized successfully Mar 25 22:55:13 katarynka sudo[1436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 22:55:13 katarynka sudo[1436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:13 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 22:55:13 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 22:55:13 katarynka systemd[1]: mpd.service: Consumed 7.706s CPU time. Mar 25 22:55:13 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 22:55:13 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 22:55:13 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 22:55:13 katarynka sudo[1436]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:13 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 22:55:13 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 22:55:13 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 22:55:13 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 22:55:13 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 22:55:13 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 22:55:13 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 22:55:13 katarynka volumio[1259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:13 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:14 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55: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 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55: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 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55: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 25 22:55:14 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 22:55:14 katarynka volumio[1259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:55:14 katarynka volumio[1259]: info: [1774475714071] CoreMusicLibrary::Adding element Last_100 Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:55:14 katarynka volumio[1259]: info: [1774475714094] CoreMusicLibrary::Adding element Webradio Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55:14+01:00" level=info msg="zeroconf server listening on port 37733" Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:55:14 katarynka volumio[1259]: info: Initializing BBC Radios Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55:14+01:00" level=debug msg="obtained new client token: AACjjI0xQoJGIerchrDOqsuLjyNpVngw+k23CsxE++vhoj1FKg6HyXvMXKoDOMnAU2C3ZxXOkVqAyU3X/4wew6ookA6QPd4M97e9WbDlOrcxcrov7ayPrXqS5XMeXxdr7Z3xJ8Vkt1L83azpl1lz3Fh33YaGxf7pZcABrf06SZ0CDBq1615WkooMkZR2w5mSt/6yD2uYhVUEASNStqS+Uj7Ghhu9ixy0xSp/QlLFuxOkf9cbF2hvpiSk" Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:14 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:14] [connect] Successful connection Mar 25 22:55:14 katarynka volumio[1259]: info: Creating Spotify config file Mar 25 22:55:14 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55:14+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55:14+01:00" level=debug msg="completed challenge" Mar 25 22:55:14 katarynka go-librespot[1418]: time="2026-03-25T22:55: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 25 22:55:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:14 katarynka sudo[1452]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 22:55:14 katarynka sudo[1452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 22:55:14 katarynka sudo[1452]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:15 katarynka volumio[1259]: info: Volumio Calling Home Mar 25 22:55:16 katarynka volumio[1259]: info: VolumeController:: Volume=96 Mute =false Mar 25 22:55:16 katarynka volumio[1259]: info: CoreStateMachine::pushState Mar 25 22:55:16 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:16 katarynka volumio[1259]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:16 katarynka volumio[1259]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 22:55:16 katarynka volumio[1259]: info: Discovery: Found device katarynka Mar 25 22:55:16 katarynka volumio[1259]: info: CoreCommandRouter::volumioGetState Mar 25 22:55:16 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:16 katarynka volumio[1378]: Starting albumart workers Mar 25 22:55:16 katarynka volumio[1259]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 22:55:16 katarynka volumio[1259]: info: Discovery: Found device katarynka Mar 25 22:55:16 katarynka volumio[1259]: info: CoreCommandRouter::volumioGetState Mar 25 22:55:16 katarynka sudo[1494]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 22:55:16 katarynka sudo[1494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:16 katarynka sudo[1492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 22:55:16 katarynka sudo[1492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:16 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:16 katarynka sudo[1494]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:16 katarynka sudo[1492]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:16 katarynka volumio[1259]: info: MPD Permissions set Mar 25 22:55:16 katarynka volumio[1259]: info: MPD Permissions set Mar 25 22:55:16 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774475714 101 Mar 25 22:55:16 katarynka volumio[1259]: 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 25 22:55:16 katarynka volumio[1259]: info: Spotify config file written Mar 25 22:55:16 katarynka sudo[1498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 22:55:16 katarynka sudo[1498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:17 katarynka volumio[1381]: Starting albumart workers Mar 25 22:55:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:17 katarynka go-librespot[1500]: go-librespot daemon starting... Mar 25 22:55:17 katarynka sudo[1498]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+01:00" level=debug msg="app state loaded" Mar 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:17 katarynka volumio[1259]: 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 25 22:55:17 katarynka volumio[1259]: info: Volumio called home Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:17 katarynka volumio[1259]: info: No need to fix Spotify hosts Mar 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+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 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+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 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+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 25 22:55:17 katarynka go-librespot[1501]: time="2026-03-25T22:55:17+01:00" level=info msg="zeroconf server listening on port 45311" Mar 25 22:55:18 katarynka volumio[1380]: Starting albumart workers Mar 25 22:55:18 katarynka go-librespot[1501]: time="2026-03-25T22:55:18+01:00" level=debug msg="obtained new client token: AADtUhkV9lootDYKP0f82LXIKsPNHrYsofwiFjx2EsDCFPBJ4RY4Duif4BLGySIyWTn7A9aYWxBlC5/PqKs17KV7IsRg2Aw1jmBB4dczUuGlnLBTd8xBCKIMpziKQL4+WOyM6gDgvVKa2+hujgrlDsjLstWViuDPQqVBVxCd1u2jRPZCzreexXOqbVsZBdQ/SdSwXTjdS8f/HslQfxf4P+uQANOxCCewFdLq+oe7ofEOHedOkADcm89O" Mar 25 22:55:18 katarynka go-librespot[1501]: time="2026-03-25T22:55:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:18 katarynka go-librespot[1501]: time="2026-03-25T22:55:18+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:18 katarynka go-librespot[1501]: time="2026-03-25T22:55:18+01:00" level=debug msg="completed challenge" Mar 25 22:55:18 katarynka go-librespot[1501]: time="2026-03-25T22:55:18+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 25 22:55:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:18 katarynka volumio[1259]: info: Starting Shairport Sync Mar 25 22:55:18 katarynka volumio[1259]: info: Starting Shairport Sync Mar 25 22:55:18 katarynka volumio[1259]: info: Starting Shairport Sync Mar 25 22:55:18 katarynka sudo[1521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:55:18 katarynka sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:18 katarynka sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:55:18 katarynka sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:18 katarynka sudo[1530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:55:18 katarynka sudo[1532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 22:55:18 katarynka sudo[1532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:18 katarynka sudo[1530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:18 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 22:55:19 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 22:55:19 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:55:19 katarynka systemd[1]: shairport-sync.service: Consumed 2.457s CPU time. Mar 25 22:55:19 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:55:19 katarynka sudo[1525]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:19 katarynka sudo[1521]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:19 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 22:55:19 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 22:55:19 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:55:19 katarynka sudo[1532]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:19 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:55:19 katarynka sudo[1530]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:19 katarynka volumio[1259]: info: Shairport-Sync Started Mar 25 22:55:19 katarynka volumio[1259]: Error adding Membership: Error: addMembership EINVAL Mar 25 22:55:19 katarynka volumio[1259]: info: Shairport-Sync Started Mar 25 22:55:19 katarynka volumio[1259]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 22:55:19 katarynka volumio[1259]: info: Shairport-Sync Started Mar 25 22:55:19 katarynka volumio[1259]: info: Upmpdcli Daemon Started Mar 25 22:55:19 katarynka volumio[1259]: info: CoreCommandRouter::volumioGetState Mar 25 22:55:19 katarynka volumio[1259]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:19 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 22:55:19 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 22:55:19 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 22:55:21 katarynka volumio[1259]: info: go-librespot daemon successfully initialized Mar 25 22:55:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 22:55:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:21 katarynka go-librespot[1580]: go-librespot daemon starting... Mar 25 22:55:21 katarynka go-librespot[1581]: time="2026-03-25T22:55:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:21 katarynka go-librespot[1581]: time="2026-03-25T22:55:21+01:00" level=debug msg="app state loaded" Mar 25 22:55:21 katarynka go-librespot[1581]: time="2026-03-25T22:55:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+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 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+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 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+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 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+01:00" level=info msg="zeroconf server listening on port 38641" Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+01:00" level=debug msg="obtained new client token: AACfXJlEG167H5iv/vgWrn/GlED5Mmp5K4r1Kdd4ODuT93PgqpikHAQEvKUPhd9Q53CYeW4/00dvhKpgIsYe9JKVus3fDxy8FKy3W/3wzdUZEVuorVbrL14pyoaDp3T6qOoWc70hyjd+Qw98kqBrapuG4ch5Pb1uliEyXZo3L6AyvQntJNatbZWMEqPMC4D9NLyd8voyGC4IH/PAZoe7qMmW4pj6Foi7vfgNHDv0DbxORMHY3ErYQzcK" Mar 25 22:55:22 katarynka mpd[1467]: 2026-03-25T22:55:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 22:55:22 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:22 katarynka sudo[1428]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:22 katarynka sudo[1438]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:22 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 22:55:22 katarynka volumio[1259]: info: Completed starting Core Plugins Mar 25 22:55:22 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:22 katarynka volumio[1259]: info: ----- MyVolumio plugins startup ---- Mar 25 22:55:22 katarynka volumio[1259]: info: ------------------------------------------- Mar 25 22:55:22 katarynka volumio[1259]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+01:00" level=debug msg="completed challenge" Mar 25 22:55:22 katarynka go-librespot[1581]: time="2026-03-25T22:55:22+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 25 22:55:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:22 katarynka volumio[1259]: error: MPD error: The expression evaluated to a falsy value: Mar 25 22:55:22 katarynka volumio[1259]: assert.ok(self.idling) Mar 25 22:55:22 katarynka volumio[1259]: error: The expression evaluated to a falsy value: Mar 25 22:55:22 katarynka volumio[1259]: assert.ok(self.idling) Mar 25 22:55:22 katarynka volumio[1259]: info: MPD running with PID1467 Mar 25 22:55:22 katarynka volumio[1259]: ,establishing connection Mar 25 22:55:22 katarynka volumio[1259]: error: updateQueue error: null Mar 25 22:55:22 katarynka volumio[1259]: error: updateQueue error: null Mar 25 22:55:24 katarynka volumio[1259]: info: Initializing connection to go-librespot Websocket Mar 25 22:55:24 katarynka volumio[1259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:55:25 katarynka sudo[1612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 22:55:25 katarynka sudo[1612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:25 katarynka sudo[1614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 22:55:25 katarynka sudo[1614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:25 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 22:55:25 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:25 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:25 katarynka go-librespot[1617]: go-librespot daemon starting... Mar 25 22:55:25 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 22:55:25 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 22:55:25 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 22:55:25 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 22:55:25 katarynka sudo[1612]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:25 katarynka sudo[1614]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:25 katarynka volumio[1259]: info: Successfully started MPD Monitor Mar 25 22:55:25 katarynka go-librespot[1618]: time="2026-03-25T22:55:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:25 katarynka go-librespot[1618]: time="2026-03-25T22:55:25+01:00" level=debug msg="app state loaded" Mar 25 22:55:25 katarynka mpd_monitor.sh[1624]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 22:55:25 katarynka go-librespot[1618]: time="2026-03-25T22:55:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:25 katarynka volumio[1259]: info: Successfully started MPD Monitor Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+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 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+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 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+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 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+01:00" level=info msg="zeroconf server listening on port 32929" Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+01:00" level=debug msg="obtained new client token: AADtMVQneiK0I4ARgMsGwm7a9C4KtjI4ikM0lrnsB6sVkQVJ38KvHXigyxHnIGcs/1MesHVCXWqobV/RUjqzrCtkqW5hYJLv5AZXKFvaviYtEPNLoa+MzQXbE5fplfitggTMMLCPWgFXNOOWRE4yCO2rQQf822N13qzufbX7MXKGF61fG/fugOG/N9nIVu/dXBuyK93xmKkMqLfC4N0uqD7RFzYczmgHV4mb5hh6GLc9Vvmn5yRqVVbr" Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+01:00" level=debug msg="completed challenge" Mar 25 22:55:26 katarynka go-librespot[1618]: time="2026-03-25T22:55:26+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 25 22:55:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:27 katarynka volumio[1259]: info: Initializing connection to go-librespot Websocket Mar 25 22:55:27 katarynka volumio[1259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:55:27 katarynka volumio[1259]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 22:55:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 22:55:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:29 katarynka go-librespot[1629]: go-librespot daemon starting... Mar 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+01:00" level=debug msg="app state loaded" Mar 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+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 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+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 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+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 25 22:55:29 katarynka go-librespot[1630]: time="2026-03-25T22:55:29+01:00" level=info msg="zeroconf server listening on port 36457" Mar 25 22:55:30 katarynka go-librespot[1630]: time="2026-03-25T22:55:30+01:00" level=debug msg="obtained new client token: AAAaSnOSAD+MbQbZ9YDiJhP2bJ/1LiepGMncBtb2HbkI6IUJZ+BUDYW2qNPSVwh9LNJB8zr/9UyCeM7CJV5dIivIVA+PGqtCxiu35+vAmkcmIpLavX9hk6QhSWK+gI/65J9kertVVgOwd9QYWWIkzDRl8lIZQrZb7D8b785zs3viZNVsJ+sMxM8OTI3ldeKtJMnxDVFIz8hbxRdeopoo0RfrgX0LcuXeNUH4y5R9X0BfjDNBBjVenW62" Mar 25 22:55:30 katarynka go-librespot[1630]: time="2026-03-25T22:55:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:30 katarynka go-librespot[1630]: time="2026-03-25T22:55:30+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:30 katarynka go-librespot[1630]: time="2026-03-25T22:55:30+01:00" level=debug msg="completed challenge" Mar 25 22:55:30 katarynka go-librespot[1630]: time="2026-03-25T22:55:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 22:55:30 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:30 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:30 katarynka volumio[1259]: info: Initializing connection to go-librespot Websocket Mar 25 22:55:30 katarynka volumio[1259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 22:55:30 katarynka volumio[1259]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 22:55:32 katarynka volumio[1259]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 22:55:32 katarynka volumio[1259]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 22:55:32 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:32 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:32 katarynka volumio[1259]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 22:55:32 katarynka volumio[1259]: info: MyVolumio login type: Token Mar 25 22:55:32 katarynka volumio[1259]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 22:55:32 katarynka volumio[1259]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 22:55:33 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 22:55:33 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:33 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:33 katarynka go-librespot[1638]: go-librespot daemon starting... Mar 25 22:55:33 katarynka go-librespot[1639]: time="2026-03-25T22:55:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:33 katarynka go-librespot[1639]: time="2026-03-25T22:55:33+01:00" level=debug msg="app state loaded" Mar 25 22:55:33 katarynka go-librespot[1639]: time="2026-03-25T22:55:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+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 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+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 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+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 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+01:00" level=info msg="zeroconf server listening on port 45679" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+01:00" level=debug msg="obtained new client token: AAAttmzvkCbE6pDQsPc8Z5HxDW7d89WJzSdvzwUhxsztQmwaC+kKPiRtZK2teYKOh89gLmTSJ5Vv+OpKeIFFIv69zHL1sbunvUZLgzYjfXV3tFY8tPr7oZS+xiMsQyetEdHgBv8kCxWCE35eaOKRU7i6cypVzaXfkeu15daXOrgYlBySQ/I2zcoIHbv/tFKV6/enCG0ZOq6EjvlfVj17eNyHdBzcBXnomm9v+2EJslU/74LdazN9rIVK" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+01:00" level=debug msg="completed challenge" Mar 25 22:55:34 katarynka go-librespot[1639]: time="2026-03-25T22:55:34+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 25 22:55:34 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:34 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:34 katarynka volumio[1259]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 22:55:34 katarynka volumio[1259]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 22:55:34 katarynka volumio[1259]: info: Streaming services startup Mar 25 22:55:34 katarynka volumio[1259]: info: Starting Streaming Daemon Mar 25 22:55:34 katarynka sudo[1647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 22:55:34 katarynka sudo[1647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:34 katarynka volumio[1259]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 22:55:34 katarynka sudo[1647]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:34 katarynka volumio[1259]: info: Initializing connection to go-librespot Websocket Mar 25 22:55:34 katarynka volumio[1259]: error: Cannot start Volumio Streaming Daemon Mar 25 22:55:34 katarynka volumio[1259]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 22:55:34 katarynka volumio[1259]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 22:55:34 katarynka volumio[1259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:55:35 katarynka volumio[1259]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 22:55:36 katarynka volumio[1259]: info: MyVolumio token set successfully Mar 25 22:55:36 katarynka volumio[1259]: info: MYVOLUMIO: Adding device Mar 25 22:55:36 katarynka volumio[1259]: info: MYVOLUMIO: Evaluating Server Mar 25 22:55:36 katarynka volumio[1259]: info: MyVolumio status changed Mar 25 22:55:36 katarynka volumio[1259]: info: Streaming services startup Mar 25 22:55:36 katarynka volumio[1259]: info: Starting Streaming Daemon Mar 25 22:55:36 katarynka volumio[1259]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 22:55:36 katarynka volumio[1259]: info: Removing audio output: Mar 25 22:55:36 katarynka volumio[1259]: info: Stoppping Tunnel 1 Mar 25 22:55:36 katarynka sudo[1690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 22:55:36 katarynka sudo[1690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:36 katarynka sudo[1692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 22:55:36 katarynka sudo[1692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:36 katarynka sudo[1690]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:36 katarynka volumio[1259]: error: Cannot start Volumio Streaming Daemon Mar 25 22:55:36 katarynka volumio[1259]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 22:55:36 katarynka volumio[1259]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 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 25 22:55:36 katarynka sudo[1692]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:36 katarynka volumio[1259]: info: Remote SSH Stopped Mar 25 22:55:37 katarynka volumio[1259]: info: Setting Geolocation for MyVolumio to eu7 Mar 25 22:55:37 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:37 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:37 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:37 katarynka volumio[1259]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 22:55:37 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 22:55:37 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:37 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:37 katarynka go-librespot[1695]: go-librespot daemon starting... Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=debug msg="app state loaded" Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:37 katarynka volumio[1259]: info: Initializing connection to go-librespot Websocket Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=debug msg="new websocket client" Mar 25 22:55:37 katarynka volumio[1259]: info: Connection to go-librespot Websocket established Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+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 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+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 25 22:55:37 katarynka go-librespot[1696]: time="2026-03-25T22:55:37+01:00" level=info msg="zeroconf server listening on port 33671" Mar 25 22:55:38 katarynka volumio[1259]: info: Updating MyVolumio device info Mar 25 22:55:38 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:38 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:38 katarynka volumio[1259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:38 katarynka go-librespot[1696]: time="2026-03-25T22:55:38+01:00" level=debug msg="obtained new client token: AACMpOGKLvbcGeulAfx7KyVGHyxEQSJTIiuCatNANz2xC9jEygOoWB5g1rqldHKU57n1DJcrfVDOkVSSnQZfrTRcGhkaLswBVwJC+XCwX/vVx6dBYO8GeWZmp3uMotmbrWrco9v6xyupozpGOA7V4kz3Ur8hRSh9wqWyF6Akpu5DtUf/oGUrxFLb97jENqyDYa9PX000QsP+VWAJobv5+B0f5m1y37eALY1FuTkEes7Kme3uw2UXoAsD" Mar 25 22:55:38 katarynka go-librespot[1696]: time="2026-03-25T22:55:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:38 katarynka go-librespot[1696]: time="2026-03-25T22:55:38+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:38 katarynka go-librespot[1696]: time="2026-03-25T22:55:38+01:00" level=debug msg="completed challenge" Mar 25 22:55:38 katarynka go-librespot[1696]: time="2026-03-25T22:55:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 22:55:38 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:38 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:38 katarynka volumio[1259]: info: Connection to go-librespot Websocket closed Mar 25 22:55:38 katarynka volumio[1259]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 25 22:55:40 katarynka volumio[1259]: info: Getting Spotify volume Mar 25 22:55:40 katarynka volumio[1259]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 22:55:41 katarynka volumio[1259]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:55:41 katarynka volumio[1259]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 22:55:41 katarynka volumio[1259]: errno: -111, Mar 25 22:55:41 katarynka volumio[1259]: code: 'ECONNREFUSED', Mar 25 22:55:41 katarynka volumio[1259]: syscall: 'connect', Mar 25 22:55:41 katarynka volumio[1259]: address: '127.0.0.1', Mar 25 22:55:41 katarynka volumio[1259]: port: 9879, Mar 25 22:55:41 katarynka volumio[1259]: response: undefined Mar 25 22:55:41 katarynka volumio[1259]: } Mar 25 22:55:41 katarynka volumio[1259]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 22:55:41 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 22:55:41 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:41 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:41 katarynka go-librespot[1716]: go-librespot daemon starting... Mar 25 22:55:41 katarynka go-librespot[1717]: time="2026-03-25T22:55:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:41 katarynka go-librespot[1717]: time="2026-03-25T22:55:41+01:00" level=debug msg="app state loaded" Mar 25 22:55:41 katarynka go-librespot[1717]: time="2026-03-25T22:55:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+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 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+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 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+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 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+01:00" level=info msg="zeroconf server listening on port 41927" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+01:00" level=debug msg="obtained new client token: AAD1Uus/y8/z21DOwtsfsENEocoSj3GEBqVYQc+V0fAm+z+hSbFSNIfy35MXMozSKdHbGIJL9hv9rdh8xfuluQ/LowkL7pUfEM9xMIi9k29ii08SVfi+CWfnuEYzo308M4Bj8zye++zXhKfWOJ8nwPFed8reU1C/781KT68X0rz/+9h3TuIVfdKPPaFW40MXanoxm+R7nxPVbf0OeGytyOVJQ0qRWVsNqxBoxNVoAq5lCQFa2S21ksUb" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+01:00" level=debug msg="completed challenge" Mar 25 22:55:42 katarynka go-librespot[1717]: time="2026-03-25T22:55:42+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 25 22:55:42 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:42 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:42 katarynka sudo[1727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 22:54' Mar 25 22:55:42 katarynka sudo[1727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:42 katarynka sudo[1727]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:43 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:43] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Mar 25 22:55:43 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:43] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Mar 25 22:55:43 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:43 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 22:55:43 katarynka systemd[1]: volumio.service: Consumed 50.613s CPU time. Mar 25 22:55:43 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 22:55:43 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 22:55:43 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 358. Mar 25 22:55:43 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 22:55:43 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 22:55:43 katarynka systemd[1]: volumio.service: Consumed 50.613s CPU time. Mar 25 22:55:43 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 22:55:43 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 22:55:45 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 22:55:45 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:45 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:45 katarynka go-librespot[1754]: go-librespot daemon starting... Mar 25 22:55:45 katarynka go-librespot[1755]: time="2026-03-25T22:55:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:45 katarynka go-librespot[1755]: time="2026-03-25T22:55:45+01:00" level=debug msg="app state loaded" Mar 25 22:55:45 katarynka go-librespot[1755]: time="2026-03-25T22:55:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+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 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+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 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+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 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+01:00" level=info msg="zeroconf server listening on port 45113" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+01:00" level=debug msg="obtained new client token: AACwm4Hc40IuwIi+YPCjNSYN3yoD2g+BQQ4bIuXC0WAFc7dPORl2uLg7TxfP5rpvQKvrguULRk0iu4kQZUxMOniA1hWiSEMOBZ7t6XcUm+lG3g8bIZoDR10/9RTZuK8ZJ+cd7mmUpV1yaqNLakQxyRyPyQLQWusKULUIfJqDyCQlgoUkJNhYurev36AdHp5iwD/aFR7aLZ4GyIdMTwRdXaEIzWrJLjVqDNxoJNM74zp5VImN7qQ5im8a" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+01:00" level=debug msg="completed challenge" Mar 25 22:55:46 katarynka go-librespot[1755]: time="2026-03-25T22:55:46+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 25 22:55:46 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:46 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:47 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:55:47 katarynka volumio[1739]: info: ----- Volumio3 ---- Mar 25 22:55:47 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:55:47 katarynka volumio[1739]: info: ----- System startup ---- Mar 25 22:55:47 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:55:48 katarynka volumio-remote-updater[686]: [2026-03-25 22:55:48] [connect] Successful connection Mar 25 22:55:48 katarynka volumio[1739]: info: MYVOLUMIO Environment detected Mar 25 22:55:48 katarynka volumio[1739]: info: Plugin folders cleanup Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning into folder /volumio/app/plugins/ Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category audio_interface Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category miscellanea Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category music_service Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category plugins.json Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category system_controller Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category user_interface Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning into folder /data/plugins/ Mar 25 22:55:48 katarynka volumio[1739]: info: Scanning category music_service Mar 25 22:55:48 katarynka volumio[1739]: info: Plugin folders cleanup completed Mar 25 22:55:48 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:55:48 katarynka volumio[1739]: info: ----- Core plugins startup ---- Mar 25 22:55:48 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:55:48 katarynka volumio[1739]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 22:55:48 katarynka volumio[1739]: info: Adding plugin upnp to MyMusic Plugins Mar 25 22:55:48 katarynka volumio[1739]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 22:55:48 katarynka volumio[1739]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 22:55:48 katarynka volumio[1739]: info: Loading plugins from folder /data/plugins/ Mar 25 22:55:48 katarynka volumio[1739]: info: Loading plugin "system"... Mar 25 22:55:48 katarynka volumio[1739]: info: Loading plugin "appearance"... Mar 25 22:55:49 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 22:55:49 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:49 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:49 katarynka go-librespot[1778]: go-librespot daemon starting... Mar 25 22:55:49 katarynka go-librespot[1779]: time="2026-03-25T22:55:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:49 katarynka go-librespot[1779]: time="2026-03-25T22:55:49+01:00" level=debug msg="app state loaded" Mar 25 22:55:49 katarynka go-librespot[1779]: time="2026-03-25T22:55:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+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 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+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 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+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 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+01:00" level=info msg="zeroconf server listening on port 36533" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+01:00" level=debug msg="obtained new client token: AAAwTdjcxohB+Ei1cV2WUaPaQB+poJVzUMRxQVhHhTmk1BHMTMJtvK6mrEiSiLjfsG2M/gOI9e8l81hNUFdey8KRyMjZJVGCLwJWTTXSB/rZGueLXzuPYEPmHq/Eg3agIEIVvOn4zd3Tt5VCPHkESwKyKrTq3rYEjjb9Jr5le+mL4rKJeU8cWacbgtUKwgo5jBN02IOcn8aVOqTZbEL5RpLn7jNKRln90a0sY073yKtsaLoFJuMU/lgB" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+01:00" level=debug msg="completed challenge" Mar 25 22:55:50 katarynka go-librespot[1779]: time="2026-03-25T22:55:50+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 25 22:55:50 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:50 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "network"... Mar 25 22:55:51 katarynka volumio[1739]: info: Refreshing Cached IP Addresses Mar 25 22:55:51 katarynka sudo[1788]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 22:55:51 katarynka sudo[1788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:51 katarynka sudo[1790]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "services"... Mar 25 22:55:51 katarynka sudo[1790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "alsa_controller"... Mar 25 22:55:51 katarynka sudo[1788]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:51 katarynka sudo[1790]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:51 katarynka sudo[1797]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 22:55:51 katarynka sudo[1797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:51 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "wizard"... Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "networkfs"... Mar 25 22:55:51 katarynka volumio[1739]: info: Starting Udev Watcher for removable devices Mar 25 22:55:51 katarynka volumio[1739]: info: Ignoring mount for partition: boot Mar 25 22:55:51 katarynka volumio[1739]: info: Ignoring mount for partition: volumio Mar 25 22:55:51 katarynka volumio[1739]: info: Ignoring mount for partition: volumio_data Mar 25 22:55:51 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "volumio_command_line_client"... Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "upnp"... Mar 25 22:55:51 katarynka volumio[1739]: info: [1774475751466] Starting Upmpd Daemon Mar 25 22:55:51 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "my_music"... Mar 25 22:55:51 katarynka volumio[1739]: info: Loading plugin "mpd"... Mar 25 22:55:52 katarynka sudo[1797]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:52 katarynka volumio[1739]: info: Loading plugin "upnp_browser"... Mar 25 22:55:53 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 22:55:53 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:53 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:53 katarynka go-librespot[1822]: go-librespot daemon starting... Mar 25 22:55:53 katarynka go-librespot[1823]: time="2026-03-25T22:55:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:53 katarynka go-librespot[1823]: time="2026-03-25T22:55:53+01:00" level=debug msg="app state loaded" Mar 25 22:55:53 katarynka go-librespot[1823]: time="2026-03-25T22:55:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+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 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+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 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+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 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+01:00" level=info msg="zeroconf server listening on port 45501" Mar 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+01:00" level=debug msg="obtained new client token: AAAPrYgDwLLGAuuHveVhJM1iMoTXxqjdohpRMQcnGmsDsfRyNr6N+cZf1NjUIlx/2bBse6uQ58QhVhMJFHGtSdyLLFBp489RgBhEEsgoomv7xw1qmg/6HYD1OqToqlELganeGonXXIg4uu76f4I3saus07SmuHn6kc3TIyPMM25bRsPo2vEwoKbt8nowpvI1NejSKY9shFXccQ2ccUQYeb/7ig7FbUwgag3Dwx2gzeDrUoFYYEMvT/EmHc4=" Mar 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+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 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:54 katarynka go-librespot[1823]: time="2026-03-25T22:55:54+01:00" level=debug msg="completed challenge" Mar 25 22:55:55 katarynka go-librespot[1823]: time="2026-03-25T22:55:55+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 25 22:55:55 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:55 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:55 katarynka volumio[1739]: info: Starting UPNP Browser Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "alarm-clock"... Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "airplay_emulation"... Mar 25 22:55:55 katarynka volumio[1739]: info: Starting Shairport Sync Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "last_100"... Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "webradio"... Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "i2s_dacs"... Mar 25 22:55:55 katarynka volumio[1739]: info: Loading plugin "volumiodiscovery"... Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** For more information see Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:55 katarynka volumio[1739]: *** WARNING *** For more information see Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** For more information see Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 22:55:55 katarynka node[1739]: *** WARNING *** For more information see Mar 25 22:55:55 katarynka volumio[1739]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 22:55:55 katarynka volumio[1739]: info: Discovery: Started advertising with name: katarynka Mar 25 22:55:56 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 22:55:56 katarynka volumio[1739]: info: Loading plugin "spop"... Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "outputs"... Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "albumart"... Mar 25 22:55:58 katarynka volumio[1739]: info: Plugin example_plugin is not enabled Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "inputs"... Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "updater_comm"... Mar 25 22:55:58 katarynka volumio[1739]: info: Plugin mpdemulation is not enabled Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "rest_api"... Mar 25 22:55:58 katarynka volumio[1739]: info: Loading plugin "websocket"... Mar 25 22:55:58 katarynka volumio[1739]: info: Starting Socket.io Server version 1.7.4 Mar 25 22:55:58 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 25 22:55:58 katarynka volumio[1739]: info: Loading i18n strings for locale pl Mar 25 22:55:58 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:58 katarynka volumio[1739]: Updating browse sources language Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:55:58 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:55:58 katarynka go-librespot[1844]: go-librespot daemon starting... Mar 25 22:55:58 katarynka go-librespot[1845]: time="2026-03-25T22:55:58+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:55:58 katarynka go-librespot[1845]: time="2026-03-25T22:55:58+01:00" level=debug msg="app state loaded" Mar 25 22:55:58 katarynka go-librespot[1845]: time="2026-03-25T22:55:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::initPlayerControls Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:55:58 katarynka volumio[1739]: Express server listening on port 3000 Mar 25 22:55:58 katarynka volumio[1739]: [Metrics] WebUI: 12s 665.49ms Mar 25 22:55:58 katarynka volumio[1739]: info: CoreStateMachine::resetVolumioState Mar 25 22:55:58 katarynka volumio[1739]: info: CoreStateMachine::getcurrentVolume Mar 25 22:55:58 katarynka volumio[1739]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 22:55:58 katarynka volumio[1739]: info: Cannot read play queue from file Mar 25 22:55:59 katarynka volumio[1739]: info: Volumio Network Manager: Network status updated: 2 Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+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 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+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 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+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 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+01:00" level=info msg="zeroconf server listening on port 33915" Mar 25 22:55:59 katarynka volumio[1834]: Forking 3 albumart workers Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+01:00" level=debug msg="obtained new client token: AADdY6+Q2C5xhSjSSYmd/ukZRR3quvXCFA0u/S/gKj19dCkbI6sEp585xilGMrrCcx8nxzhYVcfVCoWUkvS9U4HKmD0ws34xDFYWPMfr7gnx0M2vjvNY4N7jHdJDXFTCcxk3a9e+MvISFLnN2kaNJMRpG2hDhG8Y6AaWGpwUyucG5XjPxdgCNduEcbQPE66TeFEwItWlkPrEjiaSTeWJOet7iQIWRKFUJ1J0bsI3nLimQNsGFY2sJG7Q" Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::setRepeat null single undefined Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+01:00" level=debug msg="completed keyexchange" Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+01:00" level=debug msg="completed challenge" Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::pushState Mar 25 22:55:59 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::setRandom null Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::pushState Mar 25 22:55:59 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:59 katarynka go-librespot[1845]: time="2026-03-25T22:55:59+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 25 22:55:59 katarynka volumio[1739]: info: Setting Device type: Raspberry PI Mar 25 22:55:59 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:55:59 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:55:59 katarynka volumio[1739]: info: VolumeController:: Volume=96 Mute =false Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::pushState Mar 25 22:55:59 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::volumioPushState Mar 25 22:55:59 katarynka volumio[1739]: info: CoreStateMachine::updateTrackBlock Mar 25 22:55:59 katarynka volumio[1739]: info: CorePlayQueue::getTrackBlock Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 22:55:59 katarynka volumio[1739]: info: Completed loading Core Plugins Mar 25 22:55:59 katarynka volumio[1739]: info: Preparing to generate the ALSA configuration file Mar 25 22:55:59 katarynka volumio[1739]: info: Asound.conf file unchanged, so no further update is needed Mar 25 22:55:59 katarynka volumio[1739]: info: Output device has changed, restarting MPD Mar 25 22:55:59 katarynka volumio[1739]: info: Output device has changed, restarting Shairport Sync Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:55:59 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:55:59 katarynka sudo[1897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 22:55:59 katarynka sudo[1897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:59 katarynka sudo[1897]: pam_unix(sudo:session): session closed for user root Mar 25 22:55:59 katarynka volumio[1739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:55:59 katarynka volumio[1739]: info: ___________ START PLUGINS ___________ Mar 25 22:55:59 katarynka sudo[1899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 22:55:59 katarynka sudo[1899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:55:59 katarynka volumio[1739]: info: ControllerMpd::onStart: Initializing MPD Mar 25 22:55:59 katarynka volumio[1739]: info: Creating MPD Configuration file Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:56:00 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 22:56:00 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 22:56:00 katarynka sudo[1907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 22:56:00 katarynka volumio[1739]: info: [1774475760105] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:56:00 katarynka sudo[1907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:00 katarynka sudo[1909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 22:56:00 katarynka sudo[1907]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:00 katarynka volumio[1739]: info: UPNP Browser: Client initialized successfully Mar 25 22:56:00 katarynka sudo[1909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:00 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 22:56:00 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 22:56:00 katarynka systemd[1]: mpd.service: Consumed 7.782s CPU time. Mar 25 22:56:00 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 22:56:00 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 22:56:00 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 22:56:00 katarynka volumio[1739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:00 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 22:56:00 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 22:56:00 katarynka volumio[1739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:56:00 katarynka volumio[1739]: info: [1774475760385] CoreMusicLibrary::Adding element Last_100 Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 22:56:00 katarynka volumio[1739]: info: [1774475760409] CoreMusicLibrary::Adding element Webradio Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 22:56:00 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 22:56:00 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:56:00 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 22:56:00 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 22:56:00 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 22:56:00 katarynka volumio[1739]: info: Initializing BBC Radios Mar 25 22:56:00 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 22:56:00 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 22:56:00 katarynka volumio-remote-updater[686]: [2026-03-25 22:56:00] [connect] Successful connection Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:00 katarynka volumio[1739]: info: Creating Spotify config file Mar 25 22:56:00 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:01 katarynka sudo[1924]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 22:56:01 katarynka sudo[1924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 22:56:01 katarynka sudo[1924]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:01 katarynka volumio[1739]: info: Volumio Calling Home Mar 25 22:56:02 katarynka volumio[1858]: Starting albumart workers Mar 25 22:56:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 25 22:56:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:02 katarynka go-librespot[1956]: go-librespot daemon starting... Mar 25 22:56:02 katarynka sudo[1958]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 22:56:02 katarynka sudo[1958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:02 katarynka go-librespot[1961]: time="2026-03-25T22:56:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:02 katarynka go-librespot[1961]: time="2026-03-25T22:56:02+01:00" level=debug msg="app state loaded" Mar 25 22:56:02 katarynka go-librespot[1961]: time="2026-03-25T22:56:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:02 katarynka sudo[1958]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:02 katarynka volumio[1739]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 22:56:02 katarynka volumio[1739]: info: Discovery: Found device katarynka Mar 25 22:56:02 katarynka sudo[1960]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 22:56:02 katarynka volumio[1739]: info: CoreCommandRouter::volumioGetState Mar 25 22:56:02 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:02 katarynka sudo[1960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:02 katarynka sudo[1960]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:03 katarynka volumio[1739]: info: MPD Permissions set Mar 25 22:56:03 katarynka volumio[1739]: info: MPD Permissions set Mar 25 22:56:03 katarynka volumio[1739]: info: VolumeController:: Volume=96 Mute =false Mar 25 22:56:03 katarynka volumio[1739]: info: CoreStateMachine::pushState Mar 25 22:56:03 katarynka volumio[1859]: Starting albumart workers Mar 25 22:56:03 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:03 katarynka volumio[1739]: info: CoreCommandRouter::volumioPushState Mar 25 22:56:03 katarynka volumio-remote-updater[686]: [2026-03-25 22:56:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774475760 101 Mar 25 22:56:03 katarynka volumio[1739]: 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 25 22:56:03 katarynka volumio[1739]: info: Volumio called home Mar 25 22:56:03 katarynka volumio[1739]: info: Spotify config file written Mar 25 22:56:03 katarynka volumio[1739]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 22:56:03 katarynka volumio[1739]: info: Discovery: Found device katarynka Mar 25 22:56:03 katarynka volumio[1739]: info: CoreCommandRouter::volumioGetState Mar 25 22:56:03 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56: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 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56: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 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56: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 25 22:56:03 katarynka sudo[1971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56:03+01:00" level=info msg="zeroconf server listening on port 37119" Mar 25 22:56:03 katarynka sudo[1971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:03 katarynka volumio[1857]: Starting albumart workers Mar 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56:03+01:00" level=debug msg="obtained new client token: AAD+FLBid5Bf7BN/k7+3XF6tdUBnVSViwzqb8AxYnqf7AAjc7hBW9jEwzRWyfnwZ2PpKML3w4LLHuXBo7tXnFjLDw3sXrcyyngtFK6jVNYU0fjC5nuVCBQQE/fIm2KCwrZqLnxYhN17Qh4kdnldZY7fz9SUQkGEMQxgspXwH4gTUcVYMQ0yCIAXBa6xN0eA9LC0kGOLN5l1BpRjEsalrIhHDydrY8OHOm6+/s/2+4oo1lAlrd2VYK/ZwFrY=" Mar 25 22:56:03 katarynka systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 25 22:56:03 katarynka go-librespot[1961]: time="2026-03-25T22:56: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 25 22:56:03 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 22:56:03 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 22:56:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:03 katarynka go-librespot[1977]: go-librespot daemon starting... Mar 25 22:56:03 katarynka sudo[1971]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+01:00" level=debug msg="app state loaded" Mar 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:04 katarynka volumio[1739]: 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 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 22:56:04 katarynka volumio[1739]: info: No need to fix Spotify hosts Mar 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+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 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+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 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+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 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+01:00" level=info msg="zeroconf server listening on port 38247" Mar 25 22:56:04 katarynka go-librespot[1979]: time="2026-03-25T22:56:04+01:00" level=debug msg="obtained new client token: AAA+iuA27/MY3MD8Som+ny2rkvsEBo1PWfbckacqE3zovjn63AfNzOJQZW+AsXISQxUSsG7dyoobgcml8c+X2TJkPYaRcd5K2ZQvsK2GMeH9Kdh7YSHsWr7lQGtRTDELJa+PaitNEDuytU/1VGwApNwGp5mXJlCJWkOx4bclKSUri12BKe28fFxk2nM1tspGdzy8SJ0pJ7JlseYTKVYkTYTIfLe8sFTbnFMdUffooRJs9zBjMi8jVLRJois=" Mar 25 22:56:05 katarynka go-librespot[1979]: time="2026-03-25T22:56:05+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 25 22:56:05 katarynka go-librespot[1979]: time="2026-03-25T22:56:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 22:56:05 katarynka go-librespot[1979]: time="2026-03-25T22:56:05+01:00" level=debug msg="completed keyexchange" Mar 25 22:56:05 katarynka go-librespot[1979]: time="2026-03-25T22:56:05+01:00" level=debug msg="completed challenge" Mar 25 22:56:05 katarynka go-librespot[1979]: time="2026-03-25T22:56:05+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 25 22:56:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:56:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:56:05 katarynka volumio[1739]: info: Starting Shairport Sync Mar 25 22:56:05 katarynka volumio[1739]: info: Starting Shairport Sync Mar 25 22:56:05 katarynka volumio[1739]: info: Starting Shairport Sync Mar 25 22:56:05 katarynka sudo[2009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:56:05 katarynka sudo[2009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:05 katarynka sudo[2019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 22:56:05 katarynka sudo[2013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:56:05 katarynka sudo[2013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:05 katarynka sudo[2019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:05 katarynka sudo[2020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 22:56:06 katarynka sudo[2020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:06 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 22:56:06 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 22:56:06 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 22:56:06 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 22:56:06 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 22:56:06 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:56:06 katarynka systemd[1]: shairport-sync.service: Consumed 2.451s CPU time. Mar 25 22:56:06 katarynka sudo[2019]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:06 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:56:06 katarynka sudo[2009]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:06 katarynka sudo[2020]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:06 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 22:56:06 katarynka volumio[1739]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 22:56:06 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 22:56:06 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:56:06 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 22:56:06 katarynka sudo[2013]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:06 katarynka volumio[1739]: info: Upmpdcli Daemon Started Mar 25 22:56:06 katarynka volumio[1739]: info: Shairport-Sync Started Mar 25 22:56:06 katarynka volumio[1739]: Error adding Membership: Error: addMembership EINVAL Mar 25 22:56:06 katarynka volumio[1739]: info: Shairport-Sync Started Mar 25 22:56:06 katarynka volumio[1739]: info: Shairport-Sync Started Mar 25 22:56:06 katarynka volumio[1739]: info: CoreCommandRouter::volumioGetState Mar 25 22:56:06 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:06 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 25 22:56:06 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 25 22:56:06 katarynka systemd[1]: setdatetime-helper.service: Consumed 2.353s CPU time. Mar 25 22:56:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 22:56:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:08 katarynka go-librespot[2067]: go-librespot daemon starting... Mar 25 22:56:08 katarynka volumio[1739]: info: go-librespot daemon successfully initialized Mar 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+01:00" level=debug msg="app state loaded" Mar 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+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 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+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 25 22:56:08 katarynka go-librespot[2068]: time="2026-03-25T22:56:08+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 25 22:56:09 katarynka go-librespot[2068]: time="2026-03-25T22:56:09+01:00" level=info msg="zeroconf server listening on port 45315" Mar 25 22:56:09 katarynka go-librespot[2068]: time="2026-03-25T22:56:09+01:00" level=debug msg="obtained new client token: AAC03skGt57IS2fYSmyQ9Sv4LBX/wCRG8C8kf5FaNgWWcflJLGllG4lNzsCGHCHQeY5NEJl6k1jqS1m+KwxXv7q/6m7HRAcEgee3PDOTDeUQNwXwNoYaGXc3nIkHLpDcrNRTWX1hrNkTdnr9wH2uLLgXHciHSWRIMudBPF0L2SVZl43fJyTPYZiYEFWPmSrCIFQ0KKM7bDvfqrjO0GMn88Cj7D7l5H7Dk1x+RltzP0IzUARwHNYXztpm" Mar 25 22:56:09 katarynka mpd[1938]: 2026-03-25T22:56:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 22:56:09 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 22:56:09 katarynka sudo[1899]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:09 katarynka sudo[1909]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:09 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 22:56:09 katarynka volumio[1739]: info: Completed starting Core Plugins Mar 25 22:56:09 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:56:09 katarynka volumio[1739]: info: ----- MyVolumio plugins startup ---- Mar 25 22:56:09 katarynka volumio[1739]: info: ------------------------------------------- Mar 25 22:56:09 katarynka volumio[1739]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 22:56:09 katarynka go-librespot[2068]: time="2026-03-25T22:56:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:56:09 katarynka volumio[1739]: error: MPD error: The expression evaluated to a falsy value: Mar 25 22:56:09 katarynka volumio[1739]: assert.ok(self.idling) Mar 25 22:56:09 katarynka volumio[1739]: error: The expression evaluated to a falsy value: Mar 25 22:56:09 katarynka volumio[1739]: assert.ok(self.idling) Mar 25 22:56:09 katarynka volumio[1739]: error: updateQueue error: null Mar 25 22:56:09 katarynka volumio[1739]: info: MPD running with PID1938 Mar 25 22:56:09 katarynka volumio[1739]: ,establishing connection Mar 25 22:56:09 katarynka volumio[1739]: error: updateQueue error: null Mar 25 22:56:09 katarynka go-librespot[2068]: time="2026-03-25T22:56:09+01:00" level=debug msg="completed keyexchange" Mar 25 22:56:09 katarynka go-librespot[2068]: time="2026-03-25T22:56:09+01:00" level=debug msg="completed challenge" Mar 25 22:56:10 katarynka go-librespot[2068]: time="2026-03-25T22:56: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 25 22:56:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:56:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:56:11 katarynka volumio[1739]: info: Initializing connection to go-librespot Websocket Mar 25 22:56:11 katarynka volumio[1739]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:56:12 katarynka sudo[2097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 22:56:12 katarynka sudo[2097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:12 katarynka sudo[2099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 22:56:12 katarynka sudo[2099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:12 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 22:56:12 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 22:56:12 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 22:56:12 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 22:56:12 katarynka sudo[2099]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:12 katarynka sudo[2097]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:12 katarynka mpd_monitor.sh[2102]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 22:56:12 katarynka volumio[1739]: info: Successfully started MPD Monitor Mar 25 22:56:12 katarynka volumio[1739]: info: Successfully started MPD Monitor Mar 25 22:56:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 22:56:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:13 katarynka go-librespot[2106]: go-librespot daemon starting... Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=debug msg="app state loaded" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+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 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+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 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+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 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=info msg="zeroconf server listening on port 41711" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=debug msg="obtained new client token: AACkTD3BIJtDIeOTltfYk8LxRV+1K+neGAqSRfYyH7WKki3mveX+TRuautWdhDsk+uingbFQP2SqqqQ6OQujQpIB7NmOyQRK443ritRCDt7I/W2KuLUevkS0pUlwTiemY/F0+UrQJDnGFgPRu9Nh8Ka+eDJ/L0yyV7AOiVLFoBPsa+eJ8Tzt0aQjylgta8ASiNS+9BlrCyqvd0Dn+AaKyTqiFkT/CbIomiR5peCapguZbOmPg3UJrSOhSvI=" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=debug msg="completed keyexchange" Mar 25 22:56:13 katarynka go-librespot[2107]: time="2026-03-25T22:56:13+01:00" level=debug msg="completed challenge" Mar 25 22:56:14 katarynka go-librespot[2107]: time="2026-03-25T22:56: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 25 22:56:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:56:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:56:14 katarynka volumio[1739]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 22:56:14 katarynka volumio[1739]: info: Initializing connection to go-librespot Websocket Mar 25 22:56:14 katarynka volumio[1739]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 22:56:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 22:56:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:17 katarynka go-librespot[2114]: go-librespot daemon starting... Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=debug msg="app state loaded" Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:17 katarynka volumio[1739]: info: Initializing connection to go-librespot Websocket Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=debug msg="new websocket client" Mar 25 22:56:17 katarynka volumio[1739]: info: Connection to go-librespot Websocket established Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+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 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+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 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+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 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=info msg="zeroconf server listening on port 40141" Mar 25 22:56:17 katarynka go-librespot[2115]: time="2026-03-25T22:56:17+01:00" level=debug msg="obtained new client token: AACmeMNKplIny2QNFmpjPtmHvH0iqCBrDrLMhG/RGOhKYvgikDow8EgmT+gmGPD2BrJNKKYUSKOU4QYhY2Wra8IvYtfNLARXJ8Ypq+YIDlRXJSxFyGC+I/86xO3DJVwAqwk9iMF/vj8r4aLUq8aDkBtuwkd153974ZTwyEi+tDPoQyCcxZV5wYd90DkCMWmKwPOsStI5oz8hdXizgBh/K59TT7UhXmNu2F09NUxiJwLqjJeC+Kq6facH91Y=" Mar 25 22:56:17 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 22:56:17 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 22:56:18 katarynka volumio[1739]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 22:56:18 katarynka go-librespot[2115]: time="2026-03-25T22:56:18+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 25 22:56:18 katarynka go-librespot[2115]: time="2026-03-25T22:56:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 22:56:18 katarynka go-librespot[2115]: time="2026-03-25T22:56:18+01:00" level=debug msg="completed keyexchange" Mar 25 22:56:18 katarynka go-librespot[2115]: time="2026-03-25T22:56:18+01:00" level=debug msg="completed challenge" Mar 25 22:56:18 katarynka go-librespot[2115]: time="2026-03-25T22:56:18+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 25 22:56:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:56:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:56:19 katarynka volumio[1739]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 22:56:19 katarynka volumio[1739]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 22:56:19 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:19 katarynka volumio[1739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 22:56:20 katarynka volumio[1739]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 22:56:20 katarynka volumio[1739]: info: MyVolumio login type: Token Mar 25 22:56:20 katarynka volumio[1739]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 22:56:20 katarynka volumio[1739]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 22:56:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 22:56:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 22:56:21 katarynka go-librespot[2126]: go-librespot daemon starting... Mar 25 22:56:21 katarynka go-librespot[2136]: time="2026-03-25T22:56:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 22:56:21 katarynka go-librespot[2136]: time="2026-03-25T22:56:21+01:00" level=debug msg="app state loaded" Mar 25 22:56:21 katarynka go-librespot[2136]: time="2026-03-25T22:56:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 22:56:21 katarynka volumio[1739]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 22:56:22 katarynka volumio[1739]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 22:56:22 katarynka volumio[1739]: info: Streaming services startup Mar 25 22:56:22 katarynka volumio[1739]: info: Starting Streaming Daemon Mar 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+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 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+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 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+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 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+01:00" level=info msg="zeroconf server listening on port 35949" Mar 25 22:56:22 katarynka sudo[2146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 22:56:22 katarynka sudo[2146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 22:56:22 katarynka volumio[1739]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 22:56:22 katarynka sudo[2146]: pam_unix(sudo:session): session closed for user root Mar 25 22:56:22 katarynka volumio[1739]: info: Getting Spotify volume Mar 25 22:56:22 katarynka volumio[1739]: info: Connection to go-librespot Websocket closed Mar 25 22:56:22 katarynka volumio[1739]: error: Cannot start Volumio Streaming Daemon Mar 25 22:56:22 katarynka volumio[1739]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 22:56:22 katarynka volumio[1739]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 22:56:22 katarynka volumio[1739]: 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 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+01:00" level=debug msg="obtained new client token: AACvjIrnHN127tr2HC7VXzZVJQ6kS1nvA9eqcQRnXGJjEIn/QiR1Qbxgu4cpYZXMEsXIcAdGWCu0Xgg1W29OZEtcCcwOePkapDVhWO5726odYCFIBn1umtF23CDBimK4HaVWZauZ2yAWNOE/agdIgYL/AisVntDx/kL4yAzj+8vTU23BtEXSuW/n9PMChWJtyOzxIsRHQNtolhvOJE37FsnJ598h+gayYSH0zY1zP2D890NSCvI3+fNzJRk=" Mar 25 22:56:22 katarynka volumio[1739]: info: CoreCommandRouter::volumioGetState Mar 25 22:56:22 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:22 katarynka volumio[1739]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 25 22:56:22 katarynka volumio[1739]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 22:56:22 katarynka volumio[1739]: SPOTIFY: VOLUMIO VOLUME 96 Mar 25 22:56:22 katarynka volumio[1739]: info: Aligning Spotify Volume to Volumio Volume Mar 25 22:56:22 katarynka volumio[1739]: info: CoreCommandRouter::volumioGetState Mar 25 22:56:22 katarynka volumio[1739]: info: CorePlayQueue::getTrack 0 Mar 25 22:56:22 katarynka volumio[1739]: info: Setting Spotify Volume from Volumio: 96 Mar 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+01:00" level=debug msg="completed keyexchange" Mar 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+01:00" level=debug msg="completed challenge" Mar 25 22:56:22 katarynka go-librespot[2136]: time="2026-03-25T22:56:22+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 25 22:56:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 22:56:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 22:56:22 katarynka volumio[1739]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 22:56:22 katarynka volumio[1739]: Error: socket hang up Mar 25 22:56:22 katarynka volumio[1739]: at connResetException (node:internal/errors:720:14) Mar 25 22:56:22 katarynka volumio[1739]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 22:56:22 katarynka volumio[1739]: at Socket.emit (node:events:526:35) Mar 25 22:56:22 katarynka volumio[1739]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 22:56:22 katarynka volumio[1739]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 22:56:22 katarynka volumio[1739]: code: 'ECONNRESET', Mar 25 22:56:22 katarynka volumio[1739]: response: undefined Mar 25 22:56:22 katarynka volumio[1739]: } Mar 25 22:56:22 katarynka volumio[1739]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 22:56:24 katarynka sudo[2170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 22:55' Mar 25 22:56:24 katarynka sudo[2170]: 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"