Oct 15 10:03:49 volumio ntpd[1218]: CLOCK: time stepped by 16462400.261498 Oct 15 10:03:49 volumio ntpd[1218]: CLOCK: time changed from 2026-04-07 to 2026-10-15 Oct 15 10:03:49 volumio ntpd[1218]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 15 10:03:49 volumio sudo[2679]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 10:03:49 volumio sudo[2679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:03:49 volumio sudo[2681]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 10:03:49 volumio sudo[2681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:03:49 volumio sudo[2679]: pam_unix(sudo:session): session closed for user root Oct 15 10:03:49 volumio sudo[2681]: pam_unix(sudo:session): session closed for user root Oct 15 10:03:49 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Oct 15 10:03:49 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Oct 15 10:03:49 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Oct 15 10:03:49 volumio volumio[1434]: verbose: New Socket.io Connection to 192.168.4.64 from 192.168.4.52 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.261014.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 15 10:03:49 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Oct 15 10:03:49 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Oct 15 10:03:49 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Oct 15 10:03:49 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Oct 15 10:03:49 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Oct 15 10:03:49 volumio sudo[2710]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 10:03:49 volumio sudo[2710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:03:49 volumio sudo[2710]: pam_unix(sudo:session): session closed for user root Oct 15 10:03:49 volumio sudo[2712]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 10:03:49 volumio sudo[2712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:03:49 volumio sudo[2712]: pam_unix(sudo:session): session closed for user root Oct 15 10:03:49 volumio volumio[1434]: verbose: New Socket.io Connection to 192.168.4.64 from 192.168.4.52 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.106 Mobile Safari/537.36 VolumioApp/6.261014.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::volumioGetState Oct 15 10:03:49 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 15 10:03:49 volumio volumio[1434]: info: Listing playlists Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 15 10:03:49 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: A device disappeared from network Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: Device volumio disappeared from network Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: A device disappeared from network Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: adding 524397a4-fd01-4fb6-90a8-83060597f442 Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: Found device Volumio Oct 15 10:03:50 volumio volumio[1434]: info: CoreCommandRouter::volumioGetState Oct 15 10:03:50 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: this is already registered, 524397a4-fd01-4fb6-90a8-83060597f442 Oct 15 10:03:50 volumio volumio[1434]: info: Discovery: Found device Volumio Oct 15 10:03:50 volumio volumio[1434]: info: CoreCommandRouter::volumioGetState Oct 15 10:03:50 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:03:51 volumio volumio[1434]: info: Initializing connection to go-librespot Websocket Oct 15 10:03:51 volumio volumio[1434]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 15 10:03:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Oct 15 10:03:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:52 volumio go-librespot[2718]: go-librespot daemon starting... Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=info msg="running go-librespot 0.7.1" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="app state loaded" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=info msg="zeroconf server listening on port 44497" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="obtained new client token: AAFnbTV2QFxhJFHi4WJ3P9CRpOVC8k+wrvAR8RfRwYqL79vewMBfGVpKTLwv/zYzas0CnquBznJoxhSY//5Qgf8LqgeH+hf0Wneco+B3oNtjb7Ndh8Kl3QJAn0gu7ZINvWSD5UkR5NIy4oPj1gor8E2aMu3rv73tBd5+r1+p1xpr8W9AniZGQmMzTOW7lgGTeTU9QsFhVFQl/ASTXzrUIVuFAh8geONksJjxgL2I7RCR69mtxnXjggYd+g==" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="completed keyexchange" Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=debug msg="completed challenge" Oct 15 10:03:52 volumio upmpdcli[2728]: writing RSA key Oct 15 10:03:52 volumio go-librespot[2719]: time="2026-10-15T10:03:52-04:00" level=info msg="authenticated AP" username="ls******62" Oct 15 10:03:53 volumio go-librespot[2719]: time="2026-10-15T10:03:53-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 15 10:03:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 15 10:03:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033415] [Pandora] checkHTTP: Ping works but web requests are not working. Still waiting.... Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033580] [Pandora] checkHTTP: ***CRACK THE BEERS WE HAVE INTERNET*** Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033581] ControllerPandora::initializeMQTT Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033581] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033581] ControllerPandora::PandoraHandler::init Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033581] ControllerPandora::PandoraHandler::loadErrorCodes Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033649] ControllerPandora::validateAndSetAccountOptions Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033650] ControllerPandora::PandoraHandler::setAccountOptions Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033650] ControllerPandora::flushPandora Oct 15 10:03:53 volumio volumio[1434]: info: CorePlayQueue::getQueue Oct 15 10:03:53 volumio volumio[1434]: info: CorePlayQueue::clearAddPlayQueue Oct 15 10:03:53 volumio volumio[1434]: info: CorePlayQueue::saveQueue Oct 15 10:03:53 volumio volumio[1434]: info: CoreCommandRouter::serviceClearAddPlayTracks Oct 15 10:03:53 volumio volumio[1434]: error: WARNING: No clearAddPlayTracks method for service mpd Oct 15 10:03:53 volumio volumio[1434]: info: CoreCommandRouter::volumioPushQueue Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033679] [Pandora] PreventAuthTimeout::init: Timer loaded Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033679] [Pandora] PreventAuthTimeout::init: Interval set to 10800000 ms Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033679] [Pandora] PreventAuthTimeout::init: Starting delayed timer after next interval Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033679] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033989] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: [<=- Logged in to Pandora Servers -=>] Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033996] [Pandora] validateAndSetAccountOptions: ***DEBUG*** self.loggedIn: true Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033997] [Pandora] ExpireOldTracks::init: Timer loaded Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033997] [Pandora] ExpireOldTracks::init: Interval set to 300000 ms Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033997] [Pandora] ExpireOldTracks::init: Starting delayed timer after next interval Oct 15 10:03:53 volumio volumio[1434]: info: [1792073033997] ControllerPandora::PandoraHandler::fillStationData Oct 15 10:03:54 volumio volumio[1434]: info: Initializing connection to go-librespot Websocket Oct 15 10:03:54 volumio volumio[1434]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 15 10:03:54 volumio volumio[1434]: info: [1792073034366] [Pandora] PandoraHandler::setMaxStationTracks: 16 Oct 15 10:03:54 volumio volumio[1434]: info: [1792073034367] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Oct 15 10:03:54 volumio volumio[1434]: info: [1792073034367] ControllerPandora::flushPandora Oct 15 10:03:54 volumio volumio[1434]: info: CorePlayQueue::getQueue Oct 15 10:03:54 volumio volumio[1434]: info: CorePlayQueue::clearAddPlayQueue Oct 15 10:03:54 volumio volumio[1434]: info: CorePlayQueue::saveQueue Oct 15 10:03:54 volumio volumio[1434]: info: CoreCommandRouter::serviceClearAddPlayTracks Oct 15 10:03:54 volumio volumio[1434]: error: WARNING: No clearAddPlayTracks method for service mpd Oct 15 10:03:54 volumio volumio[1434]: info: CoreCommandRouter::volumioPushQueue Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin bluetooth to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin multiroom to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin metavolumio to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin cd_controller to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 15 10:03:55 volumio volumio[1434]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 15 10:03:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Oct 15 10:03:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:56 volumio go-librespot[2736]: go-librespot daemon starting... Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=info msg="running go-librespot 0.7.1" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="app state loaded" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 15 10:03:56 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:03:56 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:03:56 volumio volumio[1434]: info: Starting MyVolumio Remote Streaming Endpoints Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 15 10:03:56 volumio volumio[1434]: info: MyVolumio login type: Token Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=info msg="zeroconf server listening on port 41651" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="obtained new client token: AAEkxl4FxCf5wGyccYLeTI5fIrDtqcy/+7ebJvBmA9klt+qvdsxexljBWFmgHw5gJ1bZysTqHGkRmHynBmDUYyMxM9h1G9IOumttsHlh836hPd9DFgcixEjLn7WukyKekr1ppbQAT2YglYj6391sRqFVgBoJ3K4rQQP155AjjEG3/WMUDaAv1ASdO0UuH0oGQb6RKmDPCi+kUbN3yroB0wVpPuesuyNG8IIGiAMueCN2bRDuMkUMNrftGw==" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="completed keyexchange" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=debug msg="completed challenge" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=info msg="authenticated AP" username="ls******62" Oct 15 10:03:56 volumio go-librespot[2737]: time="2026-10-15T10:03:56-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 15 10:03:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 15 10:03:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 15 10:03:56 volumio volumio[1434]: info: Streaming services startup Oct 15 10:03:56 volumio volumio[1434]: info: Starting Streaming Daemon Oct 15 10:03:56 volumio sudo[2747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 15 10:03:56 volumio sudo[2747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:03:56 volumio volumio[1434]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 15 10:03:56 volumio sudo[2747]: pam_unix(sudo:session): session closed for user root Oct 15 10:03:56 volumio volumio[1434]: error: Cannot start Volumio Streaming Daemon Oct 15 10:03:56 volumio volumio[1434]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 15 10:03:56 volumio volumio[1434]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 15 10:03:57 volumio volumio[1434]: error: MyVolumio Custom Token format not valid, refreshing it Oct 15 10:03:57 volumio volumio[1434]: info: Initializing connection to go-librespot Websocket Oct 15 10:03:57 volumio volumio[1434]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 15 10:03:57 volumio volumio[1434]: info: MyVolumio login type: Token Oct 15 10:03:57 volumio volumio[1434]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 15 10:03:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Oct 15 10:03:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 15 10:03:59 volumio go-librespot[2772]: go-librespot daemon starting... Oct 15 10:03:59 volumio go-librespot[2773]: time="2026-10-15T10:03:59-04:00" level=info msg="running go-librespot 0.7.1" Oct 15 10:03:59 volumio go-librespot[2773]: time="2026-10-15T10:03:59-04:00" level=debug msg="app state loaded" Oct 15 10:03:59 volumio go-librespot[2773]: time="2026-10-15T10:03:59-04:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=info msg="zeroconf server listening on port 38517" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 15 10:04:00 volumio volumio[1434]: info: Initializing connection to go-librespot Websocket Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="new websocket client" Oct 15 10:04:00 volumio volumio[1434]: info: Connection to go-librespot Websocket established Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="obtained new client token: AAFF2y8ejXEsEwAGX2ieQvgL3GKYXaKI0Xnk/fpTDLONSiAfh2Tgboc16JotFWai+eql3Bmu7LCyyaZ4LmP6/17GTrZe44fRqeZW/nHTliGD+sOnsyx771HNshedMl+NbkWM+8YcUR7JvrUlJ98Orr0b6lAQXllGocCoTXkCS/AhXkTvnsgeu7aYQFpa0QZJ8zIpNm/zaBNQJV9be1oxIUKSE2LcmAXOE7rwcQB/KEgFJmGpzqHyTn8=" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Oct 15 10:04:00 volumio volumio[1434]: info: MyVolumio token set successfully Oct 15 10:04:00 volumio volumio[1434]: info: MYVOLUMIO: Adding device Oct 15 10:04:00 volumio volumio[1434]: info: MYVOLUMIO: Evaluating Server Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="completed keyexchange" Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=debug msg="completed challenge" Oct 15 10:04:00 volumio volumio[1434]: info: MyVolumio status changed Oct 15 10:04:00 volumio volumio[1434]: info: Streaming services startup Oct 15 10:04:00 volumio volumio[1434]: info: Starting Streaming Daemon Oct 15 10:04:00 volumio volumio[1434]: info: Removing browser output: myVolumio user plan is not superstar Oct 15 10:04:00 volumio volumio[1434]: info: Removing audio output: Oct 15 10:04:00 volumio volumio[1434]: info: Stoppping Tunnel 1 Oct 15 10:04:00 volumio sudo[2801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPlay Oct 15 10:04:00 volumio sudo[2801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::play index undefined Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::startPlaybackTimer Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::clearAddPlayTracks USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3 Oct 15 10:04:00 volumio sudo[2803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 15 10:04:00 volumio sudo[2803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand stop took 2 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand clear took 1 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand add "USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3" Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio volumio[1434]: error: updateQueue error: null Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 4ms Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand add "USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3" took 4 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 4ms Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand play Oct 15 10:04:00 volumio sudo[2801]: pam_unix(sudo:session): session closed for user root Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces system playlist update Oct 15 10:04:00 volumio volumio[1434]: info: Ignoring MPD Status Update Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 8ms Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 7ms Oct 15 10:04:00 volumio volumio[1434]: error: Cannot start Volumio Streaming Daemon Oct 15 10:04:00 volumio volumio[1434]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 15 10:04:00 volumio volumio[1434]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand play took 6 milliseconds Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 9ms Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 8ms Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 15 10:04:00 volumio sudo[2803]: pam_unix(sudo:session): session closed for user root Oct 15 10:04:00 volumio volumio[1434]: info: Remote SSH Stopped Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 16 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 17 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 17 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: info: Oct 15 10:04:00 volumio volumio[1434]: ---------------------------- MPD announces state update: player Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::getState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand status Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 3 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"32 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus stop Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"32 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus play Oct 15 10:04:00 volumio volumio[1434]: info: Received an update from plugin. extracting info from payload Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus play Oct 15 10:04:00 volumio volumio[1434]: info: Received an update from plugin. extracting info from payload Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 29ms Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 43ms Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 44ms Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 26 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand status took 25 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseState Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus play Oct 15 10:04:00 volumio volumio[1434]: info: Received an update from plugin. extracting info from payload Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 45ms Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 15 10:04:00 volumio volumio[1434]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: verbose: ControllerMpd::parseTrackInfo Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus play Oct 15 10:04:00 volumio volumio[1434]: info: Received an update from plugin. extracting info from payload Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: ControllerMpd::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::servicePushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":197,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Wonderland by Night (Wunderland bei Nacht)","artist":"Bert Kaempfert","album":"The Very Best of Bert Kaempfert","uri":"USB/nvme/familyplexmusic.mirror/Bert Kaempfert/1995 The Very Best of Bert Kaempfert/01 - Wonderland by Night (Wunderland bei Nacht).mp3","trackType":"mp3"} Oct 15 10:04:00 volumio volumio[1434]: verbose: CURRENT POSITION 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState stateService play Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::syncState currentStatus play Oct 15 10:04:00 volumio volumio[1434]: info: Received an update from plugin. extracting info from payload Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: CoreStateMachine::pushState Oct 15 10:04:00 volumio volumio[1434]: info: CorePlayQueue::getTrack 0 Oct 15 10:04:00 volumio volumio[1434]: info: CoreCommandRouter::volumioPushState Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 89ms Oct 15 10:04:00 volumio volumio[1434]: info: ------------------------------ 89ms Oct 15 10:04:00 volumio volumio[1434]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 15 10:04:00 volumio go-librespot[2773]: time="2026-10-15T10:04:00-04:00" level=info msg="authenticated AP" username="ls******62" Oct 15 10:04:01 volumio go-librespot[2773]: time="2026-10-15T10:04:01-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 15 10:04:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 15 10:04:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 15 10:04:01 volumio volumio[1434]: info: Connection to go-librespot Websocket closed Oct 15 10:04:01 volumio volumio[1434]: info: Setting Geolocation for MyVolumio to us1 Oct 15 10:04:01 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:01 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:01 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:02 volumio volumio[1434]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 15 10:04:02 volumio volumio[1434]: info: Updating MyVolumio device info Oct 15 10:04:02 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:02 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:02 volumio volumio[1434]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 10:04:02 volumio volumio[1434]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 15 10:04:03 volumio volumio[1434]: info: Getting Spotify volume Oct 15 10:04:03 volumio volumio[1434]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 10:04:03 volumio volumio[1434]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 15 10:04:03 volumio volumio[1434]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 15 10:04:03 volumio volumio[1434]: errno: -111, Oct 15 10:04:03 volumio volumio[1434]: code: 'ECONNREFUSED', Oct 15 10:04:03 volumio volumio[1434]: syscall: 'connect', Oct 15 10:04:03 volumio volumio[1434]: address: '127.0.0.1', Oct 15 10:04:03 volumio volumio[1434]: port: 9879, Oct 15 10:04:03 volumio volumio[1434]: response: undefined Oct 15 10:04:03 volumio volumio[1434]: } Oct 15 10:04:03 volumio volumio[1434]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 10:04:03 volumio sudo[2838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-15 10:03' Oct 15 10:04:03 volumio sudo[2838]: 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"