Mar 04 09:49:00 volumio go-librespot[8866]: time="2026-03-04T09:49:00-06:00" level=debug msg="obtained new client token: AAB0BOai5xkchxzaa1FufJ079ubSEayVPgnRyARx5zDajZRdQ5T/a8mDBtDugjWNAkmEA5RrHD7dg3XuDcmNqu4ZWcgk2rcOIr0GUkn0ZG5dHSzt7LRNGk6c6QoN3nAORQRu/u7+/85l7RjoK3kc666y3Wd4ZB9MdD58602t/Ww08Wy+iGx3DyOT//p0gz9xYKODMhQrLF+BoPLx+3hW5gCdGQXljVg1/q6w6edS9BIw+6O8OnCG9Io="
Mar 04 09:49:00 volumio go-librespot[8866]: time="2026-03-04T09:49:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:00 volumio go-librespot[8866]: time="2026-03-04T09:49:00-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:00 volumio go-librespot[8866]: time="2026-03-04T09:49:00-06:00" level=debug msg="completed challenge"
Mar 04 09:49:00 volumio go-librespot[8866]: time="2026-03-04T09:49:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:01 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:01 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26.
Mar 04 09:49:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:03 volumio go-librespot[8873]: go-librespot daemon starting...
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="app state loaded"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=info msg="zeroconf server listening on port 40617"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="obtained new client token: AABJA0FSeWqFiQYraQWpOUDcifITLh/k4ZTNXkIo5dPNz7mEbTnLedhNmiPt/O9VoTNFOZ2jH7b+3ZZeczSzH/KvNfyoiUnPZ1Ze/LXDPhJmtup+ORQXr3DYz+pCCeFE/wFmZe7gmwIsrHspZV8UiJ2CzjGSJN6Xj+gzycFyxR8LECrytqUSrrbPodBgTIwrNLwmhTDkEMKyVfDvSWtl5rZnDlnfzuuKUJVK8GJPd+7ryzNo6vgQG28oEg=="
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=debug msg="completed challenge"
Mar 04 09:49:03 volumio go-librespot[8874]: time="2026-03-04T09:49:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:04 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:04 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27.
Mar 04 09:49:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:07 volumio go-librespot[8895]: go-librespot daemon starting...
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="app state loaded"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=info msg="zeroconf server listening on port 46649"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="obtained new client token: AAAwU3hZsUDxshlJQRgUsUBYGtPguRL7EM1kyljaEIMvHBEZ+dibf793wqWYgzGmBLj2u07pyBVze0zEVoaKHNu9E9cg9HZ4SIDnJEa+KEQqfxX9chN1Grw8Al+YpRxLP6kMqyMBUOWMle3hcbfSXkXu5/jQXy7J7/6E00vfwl4sLYE2KYrOJXakIO60T1lEZvNQ2gSPKlnRk2xMGOhR4qJ4mFXYnqWX0m3onSi2yhGDgGDNgLa73nOqJg=="
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=debug msg="completed challenge"
Mar 04 09:49:07 volumio go-librespot[8896]: time="2026-03-04T09:49:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:07 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:07 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:10 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:49:10 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:10 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Mar 04 09:49:10 volumio volumio-remote-updater[13697]: Test mode disabled
Mar 04 09:49:10 volumio volumio-remote-updater[13697]: Alpha mode disabled
Mar 04 09:49:10 volumio volumio-remote-updater[13697]: Alpha legacy test mode disabled
Mar 04 09:49:10 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Mar 04 09:49:10 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:10 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28.
Mar 04 09:49:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:10 volumio go-librespot[8912]: go-librespot daemon starting...
Mar 04 09:49:10 volumio go-librespot[8913]: time="2026-03-04T09:49:10-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:10 volumio go-librespot[8913]: time="2026-03-04T09:49:10-06:00" level=debug msg="app state loaded"
Mar 04 09:49:10 volumio go-librespot[8913]: time="2026-03-04T09:49:10-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:10 volumio go-librespot[8913]: time="2026-03-04T09:49:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:11 volumio volumio[8360]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\n- Fix for CPU utilization spike
\n- Fix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\n- Add BLE onboarding plugin
\n- Enable vc4-kms-v3d for all compatible RPi models
\n- Update Tidal SDK
\n
\n","title":"Update v4.096","updateavailable":true}
Mar 04 09:49:11 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=info msg="zeroconf server listening on port 40599"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="obtained new client token: AABzfZKeaUiNBP/dXM5Ls2JE+XtCZYUJxVAcmqj7uz9+up/LDavL/viyHgHLkgGNhTBCPspZVACdaZkeFnYYHvye2EMkGCVUj76+SfNzoW4atPy6KjZgjra6aUPOOGqFiiOFeu9/hIyoHH05bsT0TWMhV+xSR0X+wyk+sVnTsxGjt8NWybg5KOOYl8FRFD5m8AM1IdCNFpWI1nZ8556LYXPdStE2qllNZpEGsHFa/dEH7UW7ol+AJtmDMA=="
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=debug msg="completed challenge"
Mar 04 09:49:11 volumio go-librespot[8913]: time="2026-03-04T09:49:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:12 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 04 09:49:12 volumio volumio[8360]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Mar 04 09:49:12 volumio volumio[8360]: info: CoreCommandRouter::volumioGetState
Mar 04 09:49:12 volumio volumio[8360]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:13 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:13 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Mar 04 09:49:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:14 volumio go-librespot[8920]: go-librespot daemon starting...
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=debug msg="app state loaded"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:14 volumio go-librespot[8921]: time="2026-03-04T09:49:14-06:00" level=info msg="zeroconf server listening on port 38329"
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=debug msg="obtained new client token: AAAj5cr/pCULMUBMSVEEqyW6v02q6EPv7+LBhRXYjiKgTIUIMZmPEu67VIITnmQDcDwthILlmge7lT5czPzwh+J1FX6eyhiLCiAf1gb5/G76ixoeGxSe+YHqClgIgouV1Wq0w5AzHyf2Lsgrim9EiKosy0haum0GvZlmav300TT6sxdrB20rFCwFTtSMqmn46+bS36hc3Gh6KYeQDCWrK66eNxaYqsv/7pCb/hmjnae+vczi3DEhRUU="
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=debug msg="completed challenge"
Mar 04 09:49:15 volumio go-librespot[8921]: time="2026-03-04T09:49:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:16 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:16 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::volumioGetBrowseSources
Mar 04 09:49:17 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Mar 04 09:49:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:18 volumio go-librespot[8942]: go-librespot daemon starting...
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="app state loaded"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=info msg="zeroconf server listening on port 46291"
Mar 04 09:49:18 volumio volumio[8360]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Mar 04 09:49:18 volumio volumio[8360]: info: Completed starting MyVolumio Plugin
Mar 04 09:49:18 volumio volumio[8360]: [Metrics] CommandRouter: 55s 405.86ms
Mar 04 09:49:18 volumio volumio[8360]: info: CoreCommandRouter::volumiosetStartupVolume
Mar 04 09:49:18 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:18 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:18 volumio volumio[8360]: info: CoreCommandRouter::Close All Modals sent
Mar 04 09:49:18 volumio volumio[8360]: info: CoreCommandRouter::Close All Modals sent
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="obtained new client token: AAAQpGyEgvuNOKCIjEuJMTkuH9D4KhgeiXzxlRdZkq6ls9ghnQajGUft2Hdkv7vGdU3gSh/V/1aZruAtfpSnFsvFfnvtr+xA1b5WxQvp4vNqOE8VcE5AIlUmJDgafg+o8Oyp8E2VMyJXZjrpjPTnKxJ1Y89tb810x3tWdxfozN6DImAMheoSBSao2TWahAEP8U1psvbG7KRN5+wAaHTjs2M2awD9Z9lLZPa/1zNGvQI/GlZWoNmn1/COBA=="
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=debug msg="completed challenge"
Mar 04 09:49:18 volumio go-librespot[8943]: time="2026-03-04T09:49:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:19 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Mar 04 09:49:19 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Mar 04 09:49:19 volumio volumio[8360]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Mar 04 09:49:19 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:19 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Mar 04 09:49:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:22 volumio go-librespot[8957]: go-librespot daemon starting...
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="app state loaded"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=info msg="zeroconf server listening on port 46703"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="obtained new client token: AAAZQKRbj0HemwYZLAe/KTmSXArQZEx6Y0tPUElfmE7PMreoAgCVAMD5jNq1yPhTQvZPNJwPscZnafBVOpjjrsXG+SM1Rg+mu7I7ySAonoAkzW5l8gloWiR91zgbL86M7v9NqsZ02a7CC0DwUvMOC9Dzj68r1wU/bSsRHQThWulPpz3rIUJVJ11XjpLpi/WhdUkWBe5s6k4x7DZxv0SLmnqqWPddPWJPrGlr+FJ1H33Y8fm2eme0kV8J+Q=="
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=debug msg="completed challenge"
Mar 04 09:49:22 volumio go-librespot[8958]: time="2026-03-04T09:49:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:22 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:22 volumio volumio[8360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:25 volumio volumio[8360]: info: BOOT COMPLETED
Mar 04 09:49:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Mar 04 09:49:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:25 volumio go-librespot[8979]: go-librespot daemon starting...
Mar 04 09:49:25 volumio go-librespot[8980]: time="2026-03-04T09:49:25-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:25 volumio go-librespot[8980]: time="2026-03-04T09:49:25-06:00" level=debug msg="app state loaded"
Mar 04 09:49:25 volumio go-librespot[8980]: time="2026-03-04T09:49:25-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:25 volumio go-librespot[8980]: time="2026-03-04T09:49:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:25 volumio volumio[8360]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:25 volumio go-librespot[8980]: time="2026-03-04T09:49:25-06:00" level=debug msg="new websocket client"
Mar 04 09:49:25 volumio volumio[8360]: info: Connection to go-librespot Websocket established
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=info msg="zeroconf server listening on port 43295"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="obtained new client token: AAA2nIiaA2eM3dYEWVvot3shoAPfsk/cbsIYDZo1+cm+GkXWbacJIlBtXMJN9dYs5ePL9VsD5059bDQmO1nCjcTS3RZEEy2EzVPMxaUZ7F0Yy1tSWZtI0cximdkLUdpmAvlzEib3agKZNtYoJUUQotQ/Txj1QpULIQ/7AiDeY0rClYXzuUym3EJHpm/zphbTUh53pR6lWIZiaD8wgA0IhGxQUeBD7eWP33ran5mZuuj1ud85SGqlO0U="
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp 104.154.127.247:443: connect: connection refused"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:80"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=debug msg="completed challenge"
Mar 04 09:49:26 volumio go-librespot[8980]: time="2026-03-04T09:49:26-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:26 volumio volumio[8360]: info: Connection to go-librespot Websocket closed
Mar 04 09:49:29 volumio volumio[8360]: info: Getting Spotify volume
Mar 04 09:49:29 volumio volumio[8360]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:49:29 volumio volumio[8360]: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:29 volumio volumio[8360]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Mar 04 09:49:29 volumio volumio[8360]: errno: -111,
Mar 04 09:49:29 volumio volumio[8360]: code: 'ECONNREFUSED',
Mar 04 09:49:29 volumio volumio[8360]: syscall: 'connect',
Mar 04 09:49:29 volumio volumio[8360]: address: '127.0.0.1',
Mar 04 09:49:29 volumio volumio[8360]: port: 9879,
Mar 04 09:49:29 volumio volumio[8360]: response: undefined
Mar 04 09:49:29 volumio volumio[8360]: }
Mar 04 09:49:29 volumio volumio[8360]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:49:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Mar 04 09:49:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:29 volumio go-librespot[9003]: go-librespot daemon starting...
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=debug msg="app state loaded"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:29 volumio sudo[9012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 09:48'
Mar 04 09:49:29 volumio sudo[9012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:29 volumio go-librespot[9004]: time="2026-03-04T09:49:29-06:00" level=info msg="zeroconf server listening on port 33091"
Mar 04 09:49:30 volumio sudo[9012]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=debug msg="obtained new client token: AACFDDPzohzdYmk/bBvoldBsvGNJGPxQWiEgC2yCFkjlBUJkXVmfo3HcsQ21rCux1PkAtd1zSpowZy7xD+qPalepvhGTTm0DxHem4DVco+/YC//ehTKvD6Sq29tm07IMYuLYcUBlYN8XWPk0jvvc4MgHY3jeoQIR/QJRs5j8lV5JgRQpivl3toUqHS8qsr7UITzRR2PZmsHL3iAcXn9MhZ46vnFQGy9XPbh7Zd3G2aTklM9Hk+B1lwY="
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:49:30 volumio volumio-remote-updater[13697]: [2026-03-04 09:49:30] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Mar 04 09:49:30 volumio volumio-remote-updater[13697]: [2026-03-04 09:49:30] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Mar 04 09:49:30 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:49:30 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Mar 04 09:49:30 volumio systemd[1]: volumio.service: Consumed 48.263s CPU time.
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=debug msg="completed challenge"
Mar 04 09:49:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Mar 04 09:49:30 volumio go-librespot[9004]: time="2026-03-04T09:49:30-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Mar 04 09:49:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:30 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12158.
Mar 04 09:49:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Mar 04 09:49:30 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Mar 04 09:49:30 volumio systemd[1]: volumio.service: Consumed 48.263s CPU time.
Mar 04 09:49:30 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Mar 04 09:49:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Mar 04 09:49:32 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:32 volumio volumio[9034]: info: ----- Volumio3 ----
Mar 04 09:49:32 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:32 volumio volumio[9034]: info: ----- System startup ----
Mar 04 09:49:32 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:33 volumio volumio[9034]: info: MYVOLUMIO Environment detected
Mar 04 09:49:33 volumio volumio[9034]: info: Plugin folders cleanup
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning into folder /volumio/app/plugins/
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category audio_interface
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category miscellanea
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category music_service
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category plugins.json
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category system_controller
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category user_interface
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning into folder /data/plugins/
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category audio_interface
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category music_service
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category system_controller
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category system_hardware
Mar 04 09:49:33 volumio volumio[9034]: info: Scanning category user_interface
Mar 04 09:49:33 volumio volumio[9034]: info: Plugin folders cleanup completed
Mar 04 09:49:33 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:33 volumio volumio[9034]: info: ----- Core plugins startup ----
Mar 04 09:49:33 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:33 volumio volumio[9034]: info: Loading plugins from folder /volumio/app/plugins/
Mar 04 09:49:33 volumio volumio[9034]: info: Adding plugin upnp to MyMusic Plugins
Mar 04 09:49:33 volumio volumio[9034]: info: Adding plugin airplay_emulation to MyMusic Plugins
Mar 04 09:49:33 volumio volumio[9034]: info: Adding plugin upnp_browser to MyMusic Plugins
Mar 04 09:49:33 volumio volumio[9034]: info: Loading plugins from folder /data/plugins/
Mar 04 09:49:33 volumio volumio[9034]: info: Loading plugin "system"...
Mar 04 09:49:33 volumio volumio[9034]: info: Loading plugin "appearance"...
Mar 04 09:49:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Mar 04 09:49:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:33 volumio go-librespot[9061]: go-librespot daemon starting...
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="app state loaded"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=info msg="zeroconf server listening on port 46231"
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="obtained new client token: AAC4X9Vge+rc7B9nTHnxzSFYFGY+jZ5uX9Gxx2Yp/QjNb8g72GBJjQNTcxNDGWkyZS6zpg9YZTzQK07LS6Eop+casudXdghftRbq+ZU/KOXaBn+lC4ex7ANhmgzUgASzGBE0MlXOKow2K9990wjoK6nfGTyjKo1PEd0K2H5nMRuAuK42ZVRAfy7OchMEWMTe6x7dNdTNe0Fuh6UGkprIifPPAfQptVx1RoxZpSxFn1hXnrPHhOy8JD3qCg=="
Mar 04 09:49:33 volumio go-librespot[9062]: time="2026-03-04T09:49:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "network"...
Mar 04 09:49:34 volumio volumio[9034]: info: Refreshing Cached IP Addresses
Mar 04 09:49:34 volumio sudo[9070]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 04 09:49:34 volumio sudo[9070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:34 volumio sudo[9070]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:34 volumio sudo[9072]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 04 09:49:34 volumio sudo[9072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "services"...
Mar 04 09:49:34 volumio sudo[9072]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "alsa_controller"...
Mar 04 09:49:34 volumio sudo[9080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Mar 04 09:49:34 volumio sudo[9080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:34 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "wizard"...
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "networkfs"...
Mar 04 09:49:34 volumio volumio[9034]: info: Starting Udev Watcher for removable devices
Mar 04 09:49:34 volumio volumio[9034]: info: Ignoring mount for partition: boot
Mar 04 09:49:34 volumio volumio[9034]: info: Ignoring mount for partition: volumio
Mar 04 09:49:34 volumio volumio[9034]: info: Ignoring mount for partition: volumio_data
Mar 04 09:49:34 volumio volumio[9034]: info: Mounting Device Wikipedia
Mar 04 09:49:34 volumio sudo[9109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Mar 04 09:49:34 volumio sudo[9109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:34 volumio sudo[9109]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:34 volumio volumio[9034]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Mar 04 09:49:34 volumio volumio[9034]: dmesg(1) may have more information after failed mount system call.
Mar 04 09:49:34 volumio volumio[9034]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Mar 04 09:49:34 volumio volumio[9034]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Mar 04 09:49:34 volumio volumio[9034]: dmesg(1) may have more information after failed mount system call.
Mar 04 09:49:34 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "volumio_command_line_client"...
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "upnp"...
Mar 04 09:49:34 volumio volumio[9034]: info: [1772639374661] Starting Upmpd Daemon
Mar 04 09:49:34 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "my_music"...
Mar 04 09:49:34 volumio volumio[9034]: info: Loading plugin "mpd"...
Mar 04 09:49:34 volumio sudo[9080]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:35 volumio go-librespot[9062]: time="2026-03-04T09:49:35-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:35 volumio go-librespot[9062]: time="2026-03-04T09:49:35-06:00" level=debug msg="completed challenge"
Mar 04 09:49:35 volumio go-librespot[9062]: time="2026-03-04T09:49:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:35 volumio kernel: hwmon hwmon1: Undervoltage detected!
Mar 04 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:35 volumio volumio-remote-updater[13697]: [2026-03-04 09:49:35] [connect] Successful connection
Mar 04 09:49:35 volumio volumio[9034]: info: Loading plugin "upnp_browser"...
Mar 04 09:49:37 volumio volumio[9034]: info: Loading plugin "alarm-clock"...
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "airplay_emulation"...
Mar 04 09:49:38 volumio volumio[9034]: info: Starting Shairport Sync
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "last_100"...
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "webradio"...
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "i2s_dacs"...
Mar 04 09:49:38 volumio volumio[9034]: info: I2S DAC not set, start Auto-detection
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "volumiodiscovery"...
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** For more information see
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:49:38 volumio volumio[9034]: *** WARNING *** For more information see
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** For more information see
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:49:38 volumio node[9034]: *** WARNING *** For more information see
Mar 04 09:49:38 volumio volumio[9034]: info: Applying required configuration parameters for plugin volumiodiscovery
Mar 04 09:49:38 volumio volumio[9034]: info: Discovery: Started advertising with name: Volumio
Mar 04 09:49:38 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:49:38 volumio volumio[9034]: info: Loading plugin "bandcamp"...
Mar 04 09:49:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Mar 04 09:49:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:38 volumio go-librespot[9114]: go-librespot daemon starting...
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="app state loaded"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=info msg="zeroconf server listening on port 40545"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="obtained new client token: AABgQdaO7Nlw6etuXHXLdHgt74hIkeVeal7G7L3bts1fo8Mz/EyZs0KClamKVaYau5ASCkzbIQbiXfFz4Zycvhd7PJ8g2+uyzZeXozxQwLHmmUaC6jQ4XR4ZrI2dnDCtD9LcOz3oab+atdSzUzboxnCXb6Y2bpwy16CwzQnOEL6/KOR8r4e+i8v65PoV+vpqVb0UGb6yzaOmYscbFgL5hAu6ov6RfSME84hqJnqgtWW9hBhU/mDEw6H8fg=="
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:38 volumio go-librespot[9115]: time="2026-03-04T09:49:38-06:00" level=debug msg="completed challenge"
Mar 04 09:49:39 volumio go-librespot[9115]: time="2026-03-04T09:49:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:39 volumio volumio[9034]: info: Plugin calmradio is not enabled
Mar 04 09:49:39 volumio volumio[9034]: info: Loading plugin "soundcloud"...
Mar 04 09:49:39 volumio volumio[9034]: info: Loading plugin "spop"...
Mar 04 09:49:40 volumio volumio[9034]: info: Loading plugin "squeezelite_mc"...
Mar 04 09:49:41 volumio kernel: hwmon hwmon1: Voltage normalised
Mar 04 09:49:41 volumio volumio[9034]: info: Loading plugin "youtube2"...
Mar 04 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Mar 04 09:49:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:42 volumio go-librespot[9124]: go-librespot daemon starting...
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="app state loaded"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:42 volumio volumio[9034]: info: Loading plugin "ytcr"...
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=info msg="zeroconf server listening on port 35351"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="obtained new client token: AABEIHhpmjMRMwN/v+I1672XfuwKpwBEKHEQX+6+Aq7+op/ARNRMAl/xUZtb+iD8Z9aLr0UwyTQs/CQLVBvKN+izmMmK9ghh9wGWj30Q0gooZ0WzRsBmy0DQWCfJr2q+Q2d170EeIDayhf9k6xR8YLrjYuYOtkLpaRNXgvMxIaM1/HGJ6blA26pntTRoS5ilqa2UL4kAFb45aRQgWYBT7bqPqejJIR0xvAsX8KiSjC0B4610Xgjn9ZZDtw=="
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=debug msg="completed challenge"
Mar 04 09:49:42 volumio go-librespot[9125]: time="2026-03-04T09:49:42-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:43 volumio volumio[9034]: info: Loading plugin "ytmusic"...
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin now_playing is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "outputs"...
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "albumart"...
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin example_plugin is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "inputs"...
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "updater_comm"...
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin mpdemulation is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "rest_api"...
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "websocket"...
Mar 04 09:49:44 volumio volumio[9034]: info: Starting Socket.io Server version 1.7.4
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin fusiondsp is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin mpdoutput is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Plugin RoonBridge is not enabled
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "podcast"...
Mar 04 09:49:44 volumio volumio[9034]: info: ControllerPodcast::constructor
Mar 04 09:49:44 volumio volumio[9034]: info: Loading plugin "volusonic"...
Mar 04 09:49:44 volumio volumio[9133]: Forking 3 albumart workers
Mar 04 09:49:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Mar 04 09:49:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:46 volumio go-librespot[9187]: go-librespot daemon starting...
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="app state loaded"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:46 volumio volumio[9034]: info: Applying required configuration parameters for plugin volusonic
Mar 04 09:49:46 volumio volumio[9034]: info: Loading plugin "backup_restore"...
Mar 04 09:49:46 volumio volumio[9159]: Starting albumart workers
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=info msg="zeroconf server listening on port 42687"
Mar 04 09:49:46 volumio volumio[9157]: Starting albumart workers
Mar 04 09:49:46 volumio volumio[9158]: Starting albumart workers
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="obtained new client token: AABXY0/St/Mz+6wmgNA/kuis6r0BnQUA0dHcq07lXRf9aWitBKy63tQZ0XJoEChU3iW94kHuoiXOrYXPcMGFIh3Jv6G0g4FuIxagLLEFa9HhGyU03UrPmBSeRLj8a+K9jaBxgUq7GW0zoqIKTV7//bVt3LS5YF8vMHWBs2c67MtfqNMoQ4V8xc71s/0lZ89JCyMQTtc37KjNCPfSTTiHHGXCuMJ7FizVNTn0K3sQ/JqXCZMHpgtySxFQbw=="
Mar 04 09:49:46 volumio volumio[9034]: info: Applying required configuration parameters for plugin backup_restore
Mar 04 09:49:46 volumio volumio[9034]: info: Plugin rpi_eeprom_config is not enabled
Mar 04 09:49:46 volumio volumio[9034]: info: Plugin rpi_eeprom_updater is not enabled
Mar 04 09:49:46 volumio volumio[9034]: info: Loading plugin "scheduledrestart"...
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=debug msg="completed challenge"
Mar 04 09:49:46 volumio go-librespot[9188]: time="2026-03-04T09:49:46-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:46 volumio volumio[9034]: info: Applying required configuration parameters for plugin scheduledrestart
Mar 04 09:49:46 volumio volumio[9034]: info: Plugin Bluetoothremote is not enabled
Mar 04 09:49:46 volumio volumio[9034]: info: Plugin music_services_shield is not enabled
Mar 04 09:49:46 volumio volumio[9034]: info: Loading plugin "Systeminfo"...
Mar 04 09:49:47 volumio volumio[9034]: info: Plugin peppymeterbasic is not enabled
Mar 04 09:49:47 volumio volumio[9034]: info: Loading plugin "peppyspectrum"...
Mar 04 09:49:47 volumio volumio-remote-updater[13697]: [2026-03-04 09:49:47] [connect] Successful connection
Mar 04 09:49:47 volumio volumio[9034]: info: Loading i18n strings for locale en
Mar 04 09:49:47 volumio volumio[9034]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Mar 04 09:49:47 volumio volumio[9034]: Updating browse sources language
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::initPlayerControls
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:49:47 volumio volumio[9034]: Express server listening on port 3000
Mar 04 09:49:47 volumio volumio[9034]: [Metrics] WebUI: 16s 153.23ms
Mar 04 09:49:47 volumio volumio[9034]: info: CoreStateMachine::resetVolumioState
Mar 04 09:49:47 volumio volumio[9034]: info: CoreStateMachine::getcurrentVolume
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:49:47 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:47 volumio sudo[9219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 04 09:49:47 volumio sudo[9219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:47 volumio sudo[9219]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:47 volumio sudo[9221]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 04 09:49:48 volumio sudo[9221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio sudo[9221]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:48 volumio volumio[9034]: info: Volumio Network Manager: Network status updated: 1
Mar 04 09:49:48 volumio volumio[9034]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::pushState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioPushState
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::updateTrackBlock
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrackBlock
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:49:48 volumio volumio-remote-updater[13697]: [2026-03-04 09:49:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772639387 101
Mar 04 09:49:48 volumio volumio[9034]: 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 04 09:49:48 volumio volumio[9034]: info: Reloading queue from file
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::setRepeat null single undefined
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::pushState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioPushState
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::setRandom null
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::pushState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioPushState
Mar 04 09:49:48 volumio volumio[9034]: info: Setting Device type: Raspberry PI
Mar 04 09:49:48 volumio volumio[9034]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:49:48 volumio volumio[9034]: info: CoreStateMachine::pushState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioPushState
Mar 04 09:49:48 volumio volumio[9034]: info: Completed loading Core Plugins
Mar 04 09:49:48 volumio volumio[9034]: info: Preparing to generate the ALSA configuration file
Mar 04 09:49:48 volumio sudo[9234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Mar 04 09:49:48 volumio sudo[9234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio volumio[9034]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Mar 04 09:49:48 volumio volumio[9034]: info: Discovery: Found device Volumio
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioGetState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio volumio[9034]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Mar 04 09:49:48 volumio volumio[9034]: info: Discovery: Found device Volumio
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioGetState
Mar 04 09:49:48 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:48 volumio sudo[9234]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:48 volumio volumio[9034]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Mar 04 09:49:48 volumio volumio[9034]: info: Reading ALSA contributions from plugins.
Mar 04 09:49:48 volumio volumio[9034]: info: Upmpdcli Daemon Started
Mar 04 09:49:48 volumio volumio[9034]: info: Asound.conf file unchanged, so no further update is needed
Mar 04 09:49:48 volumio volumio[9034]: info: Output device has changed, restarting MPD
Mar 04 09:49:48 volumio volumio[9034]: info: Output device has changed, restarting Shairport Sync
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:48 volumio sudo[9237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:49:48 volumio sudo[9237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio sudo[9237]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:48 volumio sudo[9239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:49:48 volumio sudo[9239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio volumio[9034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:49:48 volumio volumio[9034]: info: ___________ START PLUGINS ___________
Mar 04 09:49:48 volumio volumio[9034]: info: ControllerMpd::onStart: Initializing MPD
Mar 04 09:49:48 volumio volumio[9034]: info: Creating MPD Configuration file
Mar 04 09:49:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:48 volumio volumio[9034]: info: [1772639388499] CoreMusicLibrary::Adding element Media Servers
Mar 04 09:49:48 volumio sudo[9247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:48 volumio sudo[9247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio sudo[9247]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:48 volumio sudo[9249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:49:48 volumio sudo[9249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:48 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:49:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:49:48 volumio systemd[1]: mpd.service: Consumed 4.319s CPU time.
Mar 04 09:49:48 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:49:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:49:48 volumio volumio[9034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:48 volumio volumio[9034]: info: [1772639388622] CoreMusicLibrary::Adding element Last_100
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:48 volumio volumio[9034]: info: [1772639388626] CoreMusicLibrary::Adding element Webradio
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:49:48 volumio volumio[9034]: info: Initializing BBC Radios
Mar 04 09:49:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:48 volumio volumio[9034]: info: [1772639388711] CoreMusicLibrary::Adding element Bandcamp Discover
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:48 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:48 volumio volumio[9034]: info: [1772639388731] CoreMusicLibrary::Adding element SoundCloud
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:48 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:48 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:48 volumio volumio[9034]: info: Creating Spotify config file
Mar 04 09:49:48 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:48 volumio sudo[9266]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 04 09:49:48 volumio sudo[9266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 04 09:49:48 volumio sudo[9266]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Starting proxy server...
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:49 volumio volumio[9034]: info: [1772639389091] CoreMusicLibrary::Adding element YouTube2
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:49 volumio volumio[9034]: info: [1772639389110] CoreMusicLibrary::Adding element YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:49 volumio volumio[9034]: info: [1772639389121] CoreMusicLibrary::Adding element Podcast
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Podcast
Mar 04 09:49:49 volumio volumio[9034]: info: Loading i18n strings for locale en
Mar 04 09:49:49 volumio volumio[9034]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Mar 04 09:49:49 volumio volumio[9034]: Updating browse sources language
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Podcast
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Podcast
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:49 volumio volumio[9034]: info: [1772639389169] CoreMusicLibrary::Adding element Volusonic
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Podcast
Mar 04 09:49:49 volumio volumio[9034]: Cannot find translation for source Volusonic
Mar 04 09:49:49 volumio volumio[9034]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Mar 04 09:49:49 volumio volumio[9034]: info: Volumio Calling Home
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Proxy server started on port 41949
Mar 04 09:49:49 volumio volumio[9034]: info: Preparing to generate the ALSA configuration file
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:49:49 volumio volumio[9034]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Mar 04 09:49:49 volumio volumio[9034]: info: Reading ALSA contributions from plugins.
Mar 04 09:49:49 volumio volumio[9034]: info: MPD Permissions set
Mar 04 09:49:49 volumio volumio[9034]: info: MPD Permissions set
Mar 04 09:49:49 volumio volumio[9034]: info: Spotify config file written
Mar 04 09:49:49 volumio sudo[9286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Mar 04 09:49:49 volumio sudo[9286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:49 volumio volumio[9034]: 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 04 09:49:49 volumio volumio[9034]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:49:49 volumio volumio[9034]: info: CoreStateMachine::pushState
Mar 04 09:49:49 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::volumioPushState
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Server discovery started
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Player finder started
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Mar 04 09:49:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:49 volumio volumio[9034]: info: No need to fix Spotify hosts
Mar 04 09:49:49 volumio go-librespot[9290]: go-librespot daemon starting...
Mar 04 09:49:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:49 volumio sudo[9286]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=debug msg="app state loaded"
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:49 volumio volumio[9034]: 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 04 09:49:49 volumio volumio[9034]: info: Volumio called home
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Mar 04 09:49:49 volumio volumio[9034]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:49:49 volumio go-librespot[9301]: time="2026-03-04T09:49:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:49:50 volumio volumio[9034]: info: Starting Shairport Sync
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=info msg="zeroconf server listening on port 45133"
Mar 04 09:49:50 volumio volumio[9034]: info: Starting Shairport Sync
Mar 04 09:49:50 volumio volumio[9034]: info: Starting Shairport Sync
Mar 04 09:49:50 volumio sudo[9313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:49:50 volumio sudo[9313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio sudo[9317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:49:50 volumio sudo[9317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio sudo[9316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:49:50 volumio sudo[9316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio sudo[9311]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Mar 04 09:49:50 volumio sudo[9311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=debug msg="obtained new client token: AADg4rBeNLTz0+B/NHTJTtNpXadphe8HmPpW04cYsR795hYBT8JsBqtTxa7lmhYW+0WsxSIKF1WNqhqN9eOzui+wSwkKrKiq0S87sEpnsIeAy57kBaDUd/xpu+N8yPLYy6e8wPhRh/8GC106DzooRhucjo+YP19+S3SZCiIKKwW3rnra0QN/wqC8fS1aO91HJgJrqmmtsU7uYae+7XW9X+CoPl46iyifqrq1kcScMXlF3ludzfAvl3Y="
Mar 04 09:49:50 volumio volumio[9034]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Mar 04 09:49:50 volumio volumio[9034]: SPOTIFY: BQCUAncJlgdhDao6nSoNSqM6HPBaNLWsn5xnfNcg7BYKrGAvOUCnr_QtK6TSSlImdU8Qi2m-_hCw75IkKKlWE3l6xdHvCRLtuySDmJmcSI8i8Xkudt8H_f0pXK6rO3yN0Wa-PbeUM47Q9Cekn0fg1C12KBqIVOo8fQEH98xd3jtqtB7GR95RII730HM9a_mUfsXMfuaqEAIsP-6Bk8J267iHt2RikeKhCUZ2PR8
Mar 04 09:49:50 volumio volumio[9034]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Mar 04 09:49:50 volumio volumio[9034]: info: New Spotify access token = BQCUAncJlgdhDao6nSoNSqM6HPBaNLWsn5xnfNcg7BYKrGAvOUCnr_QtK6TSSlImdU8Qi2m-_hCw75IkKKlWE3l6xdHvCRLtuySDmJmcSI8i8Xkudt8H_f0pXK6rO3yN0Wa-PbeUM47Q9Cekn0fg1C12KBqIVOo8fQEH98xd3jtqtB7GR95RII730HM9a_mUfsXMfuaqEAIsP-6Bk8J267iHt2RikeKhCUZ2PR8
Mar 04 09:49:50 volumio volumio[9034]: info: Spotify credentials grant success - running version from March 24, 2019
Mar 04 09:49:50 volumio sudo[9311]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 04 09:49:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 04 09:49:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:49:50 volumio systemd[1]: shairport-sync.service: Consumed 2.078s CPU time.
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:50 volumio volumio[9034]: info: Asound.conf file unchanged, so no further update is needed
Mar 04 09:49:50 volumio volumio[9034]: info: Output device has changed, restarting MPD
Mar 04 09:49:50 volumio volumio[9034]: info: Output device has changed, restarting Shairport Sync
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:50 volumio sudo[9323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:49:50 volumio sudo[9323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=debug msg="completed challenge"
Mar 04 09:49:50 volumio sudo[9326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:49:50 volumio sudo[9326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:49:50 volumio sudo[9323]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio sudo[9316]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio go-librespot[9301]: time="2026-03-04T09:49:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:50 volumio sudo[9317]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio volumio[9034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:49:50 volumio sudo[9313]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:50 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:49:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:49:50 volumio systemd[1]: mpd.service: Consumed 1.503s CPU time.
Mar 04 09:49:50 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:49:50 volumio volumio[9034]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Mar 04 09:49:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:50 volumio mpd_monitor.sh[9278]: MPD error: Connection reset by peer
Mar 04 09:49:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:49:50 volumio mpd_monitor.sh[8822]: MPD Monitor Service: MPD Appears to be inactive, restarting
Mar 04 09:49:50 volumio mpd_monitor.sh[9349]: mpd: no process found
Mar 04 09:49:50 volumio sudo[9353]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Mar 04 09:49:50 volumio sudo[9353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio sudo[9353]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio volumio[9034]: info: MPD Permissions set
Mar 04 09:49:50 volumio volumio[9034]: info: Shairport-Sync Started
Mar 04 09:49:50 volumio volumio[9034]: Error adding Membership: Error: addMembership EINVAL
Mar 04 09:49:50 volumio volumio[9034]: info: Shairport-Sync Started
Mar 04 09:49:50 volumio volumio[9034]: info: Shairport-Sync Started
Mar 04 09:49:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:49:50 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:49:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:49:50 volumio volumio[9034]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Mar 04 09:49:50 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:49:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:49:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::volumioGetState
Mar 04 09:49:50 volumio volumio[9034]: info: CorePlayQueue::getTrack 0
Mar 04 09:49:50 volumio sudo[9362]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Mar 04 09:49:50 volumio sudo[9362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio sudo[9362]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:50 volumio volumio[9034]: info: Starting Shairport Sync
Mar 04 09:49:50 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Mar 04 09:49:50 volumio volumio[9034]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"}
Mar 04 09:49:50 volumio volumio[9034]: info: Spotify Successfully logged in
Mar 04 09:49:50 volumio sudo[9371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:49:50 volumio sudo[9371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:49:50 volumio volumio[9034]: info: [1772639390776] CoreMusicLibrary::Adding element Spotify
Mar 04 09:49:50 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source Bandcamp Discover
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source SoundCloud
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source YouTube2
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source YouTube Music
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source Podcast
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source Volusonic
Mar 04 09:49:50 volumio volumio[9034]: Cannot find translation for source Spotify
Mar 04 09:49:50 volumio sudo[9373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Mar 04 09:49:50 volumio sudo[9373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:50 volumio systemd[1]: Reloading.
Mar 04 09:49:50 volumio sudo[9363]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 04 09:49:50 volumio sudo[9363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 04 09:49:50 volumio sudo[9363]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:51 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:51 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:51 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:49:51 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:49:52 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 09:49:52 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 09:49:52 volumio sudo[9373]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:52 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:52 volumio sudo[9396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:52 volumio sudo[9396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 04 09:49:52 volumio sudo[9396]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 04 09:49:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:49:52 volumio systemd[1]: shairport-sync.service: Consumed 1.544s CPU time.
Mar 04 09:49:52 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Mar 04 09:49:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:49:52 volumio sudo[9371]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:52 volumio volumio[9034]: info: Shairport-Sync Started
Mar 04 09:49:52 volumio sudo[9400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Mar 04 09:49:52 volumio sudo[9400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:52 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 09:49:52 volumio volumio[9034]: info: go-librespot daemon successfully initialized
Mar 04 09:49:52 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Mar 04 09:49:52 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 09:49:53 volumio sudo[9400]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Mar 04 09:49:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:53 volumio go-librespot[9416]: go-librespot daemon starting...
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="app state loaded"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:53 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:53 volumio sudo[9424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:53 volumio sudo[9424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:53 volumio sudo[9424]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:53 volumio volumio[9034]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Mar 04 09:49:53 volumio sudo[9428]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Mar 04 09:49:53 volumio sudo[9428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:53 volumio sudo[9428]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:53 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Mar 04 09:49:53 volumio sudo[9433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Mar 04 09:49:53 volumio sudo[9433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=info msg="zeroconf server listening on port 38857"
Mar 04 09:49:53 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 09:49:53 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 09:49:53 volumio sudo[9433]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:53 volumio go-librespot[9417]: time="2026-03-04T09:49:53-06:00" level=debug msg="obtained new client token: AAD8aQ+9hmJycsesIY9Yj4vSiFJhIl7jRezQSkgxvoSk2IjlDs+rzPPcYqYOhSt2i4QdOBZ2oDK6dbzLlvmFYrbvJVYidGiuwZyzcDng/dx+Nti6A1olRoZKHyeV9V3r3sQYWQ8CCkHw3LUTtWVY5u4CHMQE9wmPwgXT5vArUwY5FDLUNXeRxe+2C6CrzPTf89yqn+nasEcP3eXwdsy7176CQvkhWOZDm3V5mXN4BPH13tyckVBnHSPRkA=="
Mar 04 09:49:54 volumio go-librespot[9417]: time="2026-03-04T09:49:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:54 volumio go-librespot[9417]: time="2026-03-04T09:49:54-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:54 volumio go-librespot[9417]: time="2026-03-04T09:49:54-06:00" level=debug msg="completed challenge"
Mar 04 09:49:54 volumio go-librespot[9417]: time="2026-03-04T09:49:54-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:54 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:54 volumio sudo[9454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:54 volumio sudo[9454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:54 volumio sudo[9454]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:55 volumio sudo[9457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:55 volumio sudo[9457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:55 volumio sudo[9457]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:55 volumio sudo[9460]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:55 volumio sudo[9460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:55 volumio mpd[9394]: 2026-03-04T09:49:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 04 09:49:55 volumio sudo[9460]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Mar 04 09:49:55 volumio sudo[9326]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio sudo[9249]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio mpd_monitor.sh[8822]: MPD Monitor Service: MPD restarted due to no mpc output.
Mar 04 09:49:55 volumio sudo[9239]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:55 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:56 volumio volumio[9034]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 09:49:56 volumio volumio[9034]: assert.ok(self.idling)
Mar 04 09:49:56 volumio volumio[9034]: error: The expression evaluated to a falsy value:
Mar 04 09:49:56 volumio volumio[9034]: assert.ok(self.idling)
Mar 04 09:49:56 volumio volumio[9034]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 09:49:56 volumio volumio[9034]: assert.ok(self.idling)
Mar 04 09:49:56 volumio volumio[9034]: error: The expression evaluated to a falsy value:
Mar 04 09:49:56 volumio volumio[9034]: assert.ok(self.idling)
Mar 04 09:49:56 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:56 volumio volumio[9034]: error: updateQueue error: null
Mar 04 09:49:56 volumio volumio[9034]: info: MPD running with PID9394
Mar 04 09:49:56 volumio volumio[9034]: ,establishing connection
Mar 04 09:49:56 volumio volumio[9034]: error: updateQueue error: null
Mar 04 09:49:56 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:56 volumio sudo[9468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:56 volumio sudo[9468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:56 volumio sudo[9468]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:56 volumio volumio[9034]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:49:56 volumio sudo[9471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:49:56 volumio sudo[9471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:56 volumio sudo[9471]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:56 volumio volumio[9034]: info: Completed starting Core Plugins
Mar 04 09:49:56 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:56 volumio volumio[9034]: info: ----- MyVolumio plugins startup ----
Mar 04 09:49:56 volumio volumio[9034]: info: -------------------------------------------
Mar 04 09:49:56 volumio volumio[9034]: info: [MyVolumio PluginManager] Fetching plans data....
Mar 04 09:49:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Mar 04 09:49:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:49:57 volumio go-librespot[9473]: go-librespot daemon starting...
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="app state loaded"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="stored credentials not found"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=info msg="zeroconf server listening on port 40247"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="obtained new client token: AACp6nBzzSiCgGwwcPtDl6zUzZq/qOrbYZNAi2PkT2J8gGapECKjkax1aUWQrZN+JX3p1c6n0GSnofLV4s0O9Dl2E7+FIphxREIjBX2evN7Rdfi/1B7boai3DOZerlLG5HB4YuyeM1pAchAUoSVHPj2yjHNR1poKvc1Rcl1Oe8GDP56gu/hbKcdUfu5yprSFSlqLqYJ2XgEiOf6URZOzTdlvd2WZrupEeQQdaq14dpiSHhcz0kk3OQ9SIw=="
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="completed keyexchange"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=debug msg="completed challenge"
Mar 04 09:49:57 volumio go-librespot[9474]: time="2026-03-04T09:49:57-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:49:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:49:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:49:59 volumio sudo[9482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:49:59 volumio sudo[9482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:59 volumio sudo[9484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:49:59 volumio sudo[9484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:59 volumio sudo[9486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:49:59 volumio sudo[9486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:49:59 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Mar 04 09:49:59 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:49:59 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Mar 04 09:49:59 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Mar 04 09:49:59 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:49:59 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Mar 04 09:49:59 volumio sudo[9482]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:59 volumio sudo[9486]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:59 volumio sudo[9484]: pam_unix(sudo:session): session closed for user root
Mar 04 09:49:59 volumio mpd_monitor.sh[9490]: MPD Monitor Service: Starting MPD Monitor Service
Mar 04 09:49:59 volumio volumio[9034]: info: Successfully started MPD Monitor
Mar 04 09:49:59 volumio volumio[9034]: info: Successfully started MPD Monitor
Mar 04 09:49:59 volumio volumio[9034]: info: Successfully started MPD Monitor
Mar 04 09:50:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Mar 04 09:50:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:01 volumio go-librespot[9494]: go-librespot daemon starting...
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="app state loaded"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=info msg="zeroconf server listening on port 33311"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="obtained new client token: AABRuHmlcYifw1wNY5nfujZSBjFz4sdi/rnuWBBAkfrRd9HCnsjAdbUK3SQgVqdi1VSI5yZbn2fCLMI0Kgc/Dqzf/EMtOJXGCvy5nY5y0BD+PWKIya1NtVRNpfQCJ6PJI4oPXhxYK43kYuOVTVyC38RsffL3fVj99iF/GT68mPYySj07IK9RQbQSG1OxM+neLi9Dv5rFcsyqMKtX+EkqBDp29W9rpp5A8rMIAG+qgIB5I/tGG9ES+yO9CA=="
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=debug msg="completed challenge"
Mar 04 09:50:01 volumio go-librespot[9495]: time="2026-03-04T09:50:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:02 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:02 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Mar 04 09:50:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:04 volumio go-librespot[9516]: go-librespot daemon starting...
Mar 04 09:50:04 volumio go-librespot[9517]: time="2026-03-04T09:50:04-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:04 volumio go-librespot[9517]: time="2026-03-04T09:50:04-06:00" level=debug msg="app state loaded"
Mar 04 09:50:04 volumio go-librespot[9517]: time="2026-03-04T09:50:04-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:04 volumio go-librespot[9517]: time="2026-03-04T09:50:04-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=info msg="zeroconf server listening on port 46465"
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin bluetooth to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin multiroom to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin metavolumio to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin cd_controller to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin qobuzconnect to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin smart_inputs to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: Adding plugin tidalconnect to MyMusic Plugins
Mar 04 09:50:05 volumio volumio[9034]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="obtained new client token: AACvMnZUjS9bSZrac3gT38BMcO8de9wjeDf3n6eAuUoCLgNhTqRQQm7bqSx9bt3Wk+lH9Yi/gCnWNrSI7Ulg59f+p6S0YQIQ/YHBYB0uvYvr3+9RV9LPhOQNsqnvVgubAhX1RVjiaLi3vIykU1nraEwU9ZZgtEDlKGseqU0b2DA1oBFjLCShC/hW3tAIRGI1h5eaNQHqFZwvPBvNwCr821xqz0NsPhPNcNWNLlzVT+ZNYPrWoJoJc3KehA=="
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=debug msg="completed challenge"
Mar 04 09:50:05 volumio go-librespot[9517]: time="2026-03-04T09:50:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:06 volumio volumio[9034]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Mar 04 09:50:06 volumio volumio[9034]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Mar 04 09:50:06 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:06 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:06 volumio volumio[9034]: info: Starting MyVolumio Remote Streaming Endpoints
Mar 04 09:50:06 volumio volumio[9034]: info: MyVolumio login type: Token
Mar 04 09:50:06 volumio volumio[9034]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Mar 04 09:50:06 volumio volumio[9034]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Mar 04 09:50:07 volumio volumio[9034]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Mar 04 09:50:07 volumio volumio[9034]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Mar 04 09:50:07 volumio volumio[9034]: info: Streaming services startup
Mar 04 09:50:07 volumio volumio[9034]: info: Starting Streaming Daemon
Mar 04 09:50:07 volumio sudo[9525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Mar 04 09:50:07 volumio sudo[9525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:07 volumio volumio[9034]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Mar 04 09:50:07 volumio sudo[9525]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:07 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:07 volumio volumio[9034]: error: Cannot start Volumio Streaming Daemon
Mar 04 09:50:07 volumio volumio[9034]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Mar 04 09:50:07 volumio volumio[9034]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Mar 04 09:50:07 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:07 volumio volumio[9034]: error: MyVolumio FAILED LOGIN: Invalid assertion format. 3 dot separated segments required.
Mar 04 09:50:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Mar 04 09:50:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:08 volumio go-librespot[9532]: go-librespot daemon starting...
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=debug msg="app state loaded"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:08 volumio go-librespot[9533]: time="2026-03-04T09:50:08-06:00" level=info msg="zeroconf server listening on port 33287"
Mar 04 09:50:09 volumio go-librespot[9533]: time="2026-03-04T09:50:09-06:00" level=debug msg="obtained new client token: AADJ26feFb7VPwavrf62DvlrqFsAjDeAeh64Vgvs1oVqUNYjUfcch55LvDmkhoZ2++3GggwTsitLdZrLomH4W/saVvXw0j6xeWj7APkkAaHe0y0gJWKg/eHrxCz4fpWUPjnjEXcdvMmzfpvVsx/BmJ89fgBTgEeHAVuiR745k1lVJWrtWp2GC+QPzyDRYhD9bEpit43Q7RPtH/wcXvD2IDv/ylBXnL3I6dyIRmreIZWSdbKlbuznKHU="
Mar 04 09:50:09 volumio go-librespot[9533]: time="2026-03-04T09:50:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:09 volumio go-librespot[9533]: time="2026-03-04T09:50:09-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:09 volumio go-librespot[9533]: time="2026-03-04T09:50:09-06:00" level=debug msg="completed challenge"
Mar 04 09:50:09 volumio go-librespot[9533]: time="2026-03-04T09:50:09-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:10 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:10 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Mar 04 09:50:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:12 volumio go-librespot[9541]: go-librespot daemon starting...
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="app state loaded"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=info msg="zeroconf server listening on port 37217"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="obtained new client token: AACKisO2N3lSWRxjXSAJ4sO25bkvyOdxcwX+de0eAErxEJeRbAXNSMbUnY7fr9fxM5tY0IJ48ZVgk8+UOUTdRwcSUB6WDgqqtF5swAaLaxoUB+lidgPmTovje3caeI6TcyvQJDh76+BttYcWOfgFH4I7mMjuKfJSXmdc2ICYYB8kDEcON4kQUWeSiXfwa336D+fSj01XJrhipesWKMh11riPQ5EL3oMKf0woOx1j74736OA78+vGaYh10w=="
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=debug msg="completed challenge"
Mar 04 09:50:12 volumio go-librespot[9542]: time="2026-03-04T09:50:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:13 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:13 volumio volumio[9034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Mar 04 09:50:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:16 volumio go-librespot[9564]: go-librespot daemon starting...
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="app state loaded"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:16 volumio volumio[9034]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="new websocket client"
Mar 04 09:50:16 volumio volumio[9034]: info: Connection to go-librespot Websocket established
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=info msg="zeroconf server listening on port 35713"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="obtained new client token: AAA3qSsBRCHSv63ogenmms83TExVgaTwLE7D43Qn2vlZL2BsiRNht2Up67SHMQscSfgvmTNVKmOJkNFZ0lhFedDJKsk9nEaBcqFda1Skm95GXor5QWzvixkRTeACWD79XsK/BIjJb6bhSIKMU0J558+JO70JRLwQR+mq093ydudKCQcv8OPauV1037z9bi+r1swvaSkQ1wd7oiHuJvSXjnP+9R+yJSU4sC7AKGQtjPkDrzlyVRaETpkuhA=="
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=debug msg="completed challenge"
Mar 04 09:50:16 volumio go-librespot[9565]: time="2026-03-04T09:50:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:16 volumio volumio[9034]: info: Connection to go-librespot Websocket closed
Mar 04 09:50:19 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:50:19 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:19 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Mar 04 09:50:19 volumio volumio-remote-updater[13697]: Test mode disabled
Mar 04 09:50:19 volumio volumio-remote-updater[13697]: Alpha mode disabled
Mar 04 09:50:19 volumio volumio-remote-updater[13697]: Alpha legacy test mode disabled
Mar 04 09:50:19 volumio volumio[9034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Mar 04 09:50:19 volumio volumio[9034]: info: Getting Spotify volume
Mar 04 09:50:19 volumio volumio[9034]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:50:19 volumio volumio[9034]: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:19 volumio volumio[9034]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Mar 04 09:50:19 volumio volumio[9034]: errno: -111,
Mar 04 09:50:19 volumio volumio[9034]: code: 'ECONNREFUSED',
Mar 04 09:50:19 volumio volumio[9034]: syscall: 'connect',
Mar 04 09:50:19 volumio volumio[9034]: address: '127.0.0.1',
Mar 04 09:50:19 volumio volumio[9034]: port: 9879,
Mar 04 09:50:19 volumio volumio[9034]: response: undefined
Mar 04 09:50:19 volumio volumio[9034]: }
Mar 04 09:50:19 volumio volumio[9034]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:50:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Mar 04 09:50:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:19 volumio go-librespot[9591]: go-librespot daemon starting...
Mar 04 09:50:19 volumio go-librespot[9592]: time="2026-03-04T09:50:19-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:19 volumio go-librespot[9592]: time="2026-03-04T09:50:19-06:00" level=debug msg="app state loaded"
Mar 04 09:50:19 volumio go-librespot[9592]: time="2026-03-04T09:50:19-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:19 volumio go-librespot[9592]: time="2026-03-04T09:50:19-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:20 volumio sudo[9600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 09:49'
Mar 04 09:50:20 volumio sudo[9600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=info msg="zeroconf server listening on port 40953"
Mar 04 09:50:20 volumio sudo[9600]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="obtained new client token: AABLfqpId2olP+ARqGyE6eD/mdwswKCZkWv5bPJBkiB2SnMB/a7cODnIrPvEDC4mQQyjXSnp+rCqOv/AAubl9mW7FWNbiETHdAiEBMLpcUrwiJncUyin4sMun8Y2eQ51MlsQDhYZqhShldWaMux/oF1jpxdRv9iQaVeDDBIl31MjyC3RG4Vlm6Tdh7t0uAdQ2Nj0DZw5ySHqRuoTt/1wywTBfkYPwjGQJb33C3jgH5xRlhkGKOG4Oe5oMg=="
Mar 04 09:50:20 volumio volumio-remote-updater[13697]: [2026-03-04 09:50:20] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Mar 04 09:50:20 volumio volumio-remote-updater[13697]: [2026-03-04 09:50:20] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Mar 04 09:50:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Mar 04 09:50:20 volumio systemd[1]: volumio.service: Consumed 44.729s CPU time.
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=debug msg="completed challenge"
Mar 04 09:50:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Mar 04 09:50:20 volumio go-librespot[9592]: time="2026-03-04T09:50:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Mar 04 09:50:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12159.
Mar 04 09:50:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Mar 04 09:50:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Mar 04 09:50:20 volumio systemd[1]: volumio.service: Consumed 44.729s CPU time.
Mar 04 09:50:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Mar 04 09:50:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Mar 04 09:50:22 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:22 volumio volumio[9618]: info: ----- Volumio3 ----
Mar 04 09:50:22 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:22 volumio volumio[9618]: info: ----- System startup ----
Mar 04 09:50:22 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:23 volumio volumio[9618]: info: MYVOLUMIO Environment detected
Mar 04 09:50:23 volumio volumio[9618]: info: Plugin folders cleanup
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning into folder /volumio/app/plugins/
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category audio_interface
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category miscellanea
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category music_service
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category plugins.json
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category system_controller
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category user_interface
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning into folder /data/plugins/
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category audio_interface
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category music_service
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category system_controller
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category system_hardware
Mar 04 09:50:23 volumio volumio[9618]: info: Scanning category user_interface
Mar 04 09:50:23 volumio volumio[9618]: info: Plugin folders cleanup completed
Mar 04 09:50:23 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:23 volumio volumio[9618]: info: ----- Core plugins startup ----
Mar 04 09:50:23 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:23 volumio volumio[9618]: info: Loading plugins from folder /volumio/app/plugins/
Mar 04 09:50:23 volumio volumio[9618]: info: Adding plugin upnp to MyMusic Plugins
Mar 04 09:50:23 volumio volumio[9618]: info: Adding plugin airplay_emulation to MyMusic Plugins
Mar 04 09:50:23 volumio volumio[9618]: info: Adding plugin upnp_browser to MyMusic Plugins
Mar 04 09:50:23 volumio volumio[9618]: info: Loading plugins from folder /data/plugins/
Mar 04 09:50:23 volumio volumio[9618]: info: Loading plugin "system"...
Mar 04 09:50:23 volumio volumio[9618]: info: Loading plugin "appearance"...
Mar 04 09:50:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Mar 04 09:50:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:23 volumio go-librespot[9645]: go-librespot daemon starting...
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=debug msg="app state loaded"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:50:23 volumio go-librespot[9646]: time="2026-03-04T09:50:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=info msg="zeroconf server listening on port 37517"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=debug msg="obtained new client token: AAAjQ1atXKXW3hYO9foIjWZjjtrkm9w72BUDO61Dh4DIDDppaEVFmUtN3fA2q/DCU0uxeszw15tE07l8zIYds61MxunuL48IFU5+jWHYG6p/cWUpHLP5TbPWW+gAnI0jAjHILVpZlPNeyvdqyQGoF/NfTEzXosFRRpArg5JRPJ2lw5btSP1pjfkJgGCjg2AugIV/sAqOSef2A46iyGUZugwcIVHGHdLAytd3xVHO2Sb3wjCuXTofJHs="
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=debug msg="completed challenge"
Mar 04 09:50:24 volumio go-librespot[9646]: time="2026-03-04T09:50:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:24 volumio volumio[9618]: info: Loading plugin "network"...
Mar 04 09:50:24 volumio volumio[9618]: info: Refreshing Cached IP Addresses
Mar 04 09:50:24 volumio sudo[9654]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 04 09:50:24 volumio sudo[9654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:24 volumio sudo[9656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 04 09:50:24 volumio volumio[9618]: info: Loading plugin "services"...
Mar 04 09:50:24 volumio sudo[9656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:24 volumio volumio[9618]: info: Loading plugin "alsa_controller"...
Mar 04 09:50:24 volumio sudo[9654]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:24 volumio sudo[9656]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:24 volumio sudo[9663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Mar 04 09:50:24 volumio sudo[9663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:24 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:50:24 volumio volumio[9618]: info: Loading plugin "wizard"...
Mar 04 09:50:24 volumio volumio[9618]: info: Loading plugin "networkfs"...
Mar 04 09:50:24 volumio volumio[9618]: info: Starting Udev Watcher for removable devices
Mar 04 09:50:24 volumio volumio[9618]: info: Ignoring mount for partition: boot
Mar 04 09:50:24 volumio volumio[9618]: info: Ignoring mount for partition: volumio
Mar 04 09:50:24 volumio volumio[9618]: info: Ignoring mount for partition: volumio_data
Mar 04 09:50:24 volumio volumio[9618]: info: Mounting Device Wikipedia
Mar 04 09:50:25 volumio sudo[9693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Mar 04 09:50:25 volumio sudo[9693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:25 volumio sudo[9693]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:25 volumio volumio[9618]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Mar 04 09:50:25 volumio volumio[9618]: dmesg(1) may have more information after failed mount system call.
Mar 04 09:50:25 volumio volumio[9618]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Mar 04 09:50:25 volumio volumio[9618]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Mar 04 09:50:25 volumio volumio[9618]: dmesg(1) may have more information after failed mount system call.
Mar 04 09:50:25 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:50:25 volumio volumio[9618]: info: Loading plugin "volumio_command_line_client"...
Mar 04 09:50:25 volumio volumio[9618]: info: Loading plugin "upnp"...
Mar 04 09:50:25 volumio volumio[9618]: info: [1772639425086] Starting Upmpd Daemon
Mar 04 09:50:25 volumio kernel: hwmon hwmon1: Undervoltage detected!
Mar 04 09:50:25 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:50:25 volumio volumio[9618]: info: Loading plugin "my_music"...
Mar 04 09:50:25 volumio volumio[9618]: info: Loading plugin "mpd"...
Mar 04 09:50:25 volumio sudo[9663]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:25 volumio volumio-remote-updater[13697]: [2026-03-04 09:50:25] [connect] Successful connection
Mar 04 09:50:25 volumio volumio[9618]: info: Loading plugin "upnp_browser"...
Mar 04 09:50:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Mar 04 09:50:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:27 volumio go-librespot[9696]: go-librespot daemon starting...
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=debug msg="app state loaded"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:27 volumio go-librespot[9697]: time="2026-03-04T09:50:27-06:00" level=info msg="zeroconf server listening on port 45451"
Mar 04 09:50:28 volumio go-librespot[9697]: time="2026-03-04T09:50:28-06:00" level=debug msg="obtained new client token: AADdLfCl+Ac/F65nZyb2hyx4WQCZKheRTuVJvudm2xc0R2LvAZACThLEa5wPxkkf96GCeawF9gdYEMb+n9GqsCt0FoA/KGZPtQ8rz/pSMP8sI295S0pZdt0BhmyK14RBLoVIR0S/kFxk7cD8CoGpdNnclL3eAD7E974NFMgH1RbdycBBgOQBEjCpOIefWcebi11c5d17fx8NZFQPH1Jv3h8yHtDbgvB0fXyEj65Ir547oygG8HQEEGE="
Mar 04 09:50:28 volumio go-librespot[9697]: time="2026-03-04T09:50:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:28 volumio go-librespot[9697]: time="2026-03-04T09:50:28-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:28 volumio go-librespot[9697]: time="2026-03-04T09:50:28-06:00" level=debug msg="completed challenge"
Mar 04 09:50:28 volumio go-librespot[9697]: time="2026-03-04T09:50:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "alarm-clock"...
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "airplay_emulation"...
Mar 04 09:50:28 volumio volumio[9618]: info: Starting Shairport Sync
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "last_100"...
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "webradio"...
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "i2s_dacs"...
Mar 04 09:50:28 volumio volumio[9618]: info: I2S DAC not set, start Auto-detection
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "volumiodiscovery"...
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** For more information see
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:50:28 volumio volumio[9618]: *** WARNING *** For more information see
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:50:28 volumio volumio[9618]: info: Applying required configuration parameters for plugin volumiodiscovery
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** For more information see
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 04 09:50:28 volumio node[9618]: *** WARNING *** For more information see
Mar 04 09:50:28 volumio volumio[9618]: info: Discovery: Started advertising with name: Volumio
Mar 04 09:50:28 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 04 09:50:28 volumio volumio[9618]: info: Loading plugin "bandcamp"...
Mar 04 09:50:30 volumio volumio[9618]: info: Plugin calmradio is not enabled
Mar 04 09:50:30 volumio volumio[9618]: info: Loading plugin "soundcloud"...
Mar 04 09:50:30 volumio volumio[9618]: info: Loading plugin "spop"...
Mar 04 09:50:31 volumio kernel: hwmon hwmon1: Voltage normalised
Mar 04 09:50:31 volumio volumio[9618]: info: Loading plugin "squeezelite_mc"...
Mar 04 09:50:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Mar 04 09:50:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:31 volumio go-librespot[9709]: go-librespot daemon starting...
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="app state loaded"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=info msg="zeroconf server listening on port 43619"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="obtained new client token: AAC5zdf+Yu5cKz1PiFgNG1cX5XbluUufwf+VC6JZm2NBE4e9d7JhPsaz3hJW2BU1lhlTWATAnpY7FMUxQDhqMxP5Up8Ost/tobiXjlJ9gbtTbdEVNhBR4PQ8RacXawdImowqpi9t961oZ0cBV0y1sUyHPrptd0Gj1QSuwUsSCLwW+ZOwK3eaSafT4AkfIqebtdTH37ZX69fRi+K7XMgZ4C5UAUHZwTLL02GAra+BxvYACGpnGv0VUKxexA=="
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:31 volumio go-librespot[9710]: time="2026-03-04T09:50:31-06:00" level=debug msg="completed challenge"
Mar 04 09:50:32 volumio go-librespot[9710]: time="2026-03-04T09:50:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:32 volumio volumio[9618]: info: Loading plugin "youtube2"...
Mar 04 09:50:32 volumio volumio[9618]: info: Loading plugin "ytcr"...
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "ytmusic"...
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin now_playing is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "outputs"...
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "albumart"...
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin example_plugin is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "inputs"...
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "updater_comm"...
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin mpdemulation is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "rest_api"...
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "websocket"...
Mar 04 09:50:34 volumio volumio[9618]: info: Starting Socket.io Server version 1.7.4
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin fusiondsp is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin mpdoutput is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Plugin RoonBridge is not enabled
Mar 04 09:50:34 volumio volumio[9618]: info: Loading plugin "podcast"...
Mar 04 09:50:34 volumio volumio[9618]: info: ControllerPodcast::constructor
Mar 04 09:50:35 volumio volumio[9618]: info: Loading plugin "volusonic"...
Mar 04 09:50:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Mar 04 09:50:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:35 volumio volumio[9717]: Forking 3 albumart workers
Mar 04 09:50:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:35 volumio go-librespot[9741]: go-librespot daemon starting...
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="app state loaded"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=info msg="zeroconf server listening on port 40391"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="obtained new client token: AABIeYnBv66OVqdPXOqRhg/TNY8RsdUtEkg5aBbtSwVfS2mAgWHExCJvI8QYV+I+lfoFXHUeF4ukSIXsOchKj8ZlEpRf86rY4GjPT8qyhHpVS43xKoblEmEX/hAlPHxqldJ8tq6WwqOTbhc/IgCFTMOA9y1j2yM2D4s9mHKhbrm+8jzE3XybhFmUTltrYzuJrb+d8oG7tFZ0WWbWhZkQMXyoTQNYBiYDD+F0fxVoJx8N1//1AQkOE4h8DQ=="
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=debug msg="completed challenge"
Mar 04 09:50:35 volumio go-librespot[9761]: time="2026-03-04T09:50:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:36 volumio volumio[9618]: info: Applying required configuration parameters for plugin volusonic
Mar 04 09:50:36 volumio volumio[9618]: info: Loading plugin "backup_restore"...
Mar 04 09:50:36 volumio volumio[9743]: Starting albumart workers
Mar 04 09:50:36 volumio volumio[9742]: Starting albumart workers
Mar 04 09:50:37 volumio volumio[9618]: info: Applying required configuration parameters for plugin backup_restore
Mar 04 09:50:37 volumio volumio[9618]: info: Plugin rpi_eeprom_config is not enabled
Mar 04 09:50:37 volumio volumio[9618]: info: Plugin rpi_eeprom_updater is not enabled
Mar 04 09:50:37 volumio volumio[9618]: info: Loading plugin "scheduledrestart"...
Mar 04 09:50:37 volumio volumio[9744]: Starting albumart workers
Mar 04 09:50:37 volumio volumio[9618]: info: Applying required configuration parameters for plugin scheduledrestart
Mar 04 09:50:37 volumio volumio[9618]: info: Plugin Bluetoothremote is not enabled
Mar 04 09:50:37 volumio volumio[9618]: info: Plugin music_services_shield is not enabled
Mar 04 09:50:37 volumio volumio[9618]: info: Loading plugin "Systeminfo"...
Mar 04 09:50:37 volumio volumio[9618]: info: Plugin peppymeterbasic is not enabled
Mar 04 09:50:37 volumio volumio[9618]: info: Loading plugin "peppyspectrum"...
Mar 04 09:50:37 volumio volumio-remote-updater[13697]: [2026-03-04 09:50:37] [connect] Successful connection
Mar 04 09:50:38 volumio volumio[9618]: info: Loading i18n strings for locale en
Mar 04 09:50:38 volumio volumio[9618]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Mar 04 09:50:38 volumio volumio[9618]: Updating browse sources language
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::initPlayerControls
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: Express server listening on port 3000
Mar 04 09:50:38 volumio volumio[9618]: [Metrics] WebUI: 16s 199.82ms
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::resetVolumioState
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::getcurrentVolume
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:38 volumio sudo[9803]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 04 09:50:38 volumio sudo[9803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio sudo[9805]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 04 09:50:38 volumio sudo[9805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio sudo[9803]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:38 volumio sudo[9805]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:38 volumio volumio[9618]: info: Volumio Network Manager: Network status updated: 1
Mar 04 09:50:38 volumio volumio[9618]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::pushState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioPushState
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::updateTrackBlock
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrackBlock
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:50:38 volumio volumio-remote-updater[13697]: [2026-03-04 09:50:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772639437 101
Mar 04 09:50:38 volumio volumio[9618]: 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 04 09:50:38 volumio volumio[9618]: info: Reloading queue from file
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::setRepeat null single undefined
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::pushState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioPushState
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::setRandom null
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::pushState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioPushState
Mar 04 09:50:38 volumio volumio[9618]: info: Setting Device type: Raspberry PI
Mar 04 09:50:38 volumio volumio[9618]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:50:38 volumio volumio[9618]: info: CoreStateMachine::pushState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioPushState
Mar 04 09:50:38 volumio volumio[9618]: info: Completed loading Core Plugins
Mar 04 09:50:38 volumio volumio[9618]: info: Preparing to generate the ALSA configuration file
Mar 04 09:50:38 volumio sudo[9819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Mar 04 09:50:38 volumio sudo[9819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio volumio[9618]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Mar 04 09:50:38 volumio volumio[9618]: info: Discovery: Found device Volumio
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioGetState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Mar 04 09:50:38 volumio volumio[9618]: info: Discovery: Found device Volumio
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioGetState
Mar 04 09:50:38 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:38 volumio volumio[9618]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Mar 04 09:50:38 volumio volumio[9618]: info: Reading ALSA contributions from plugins.
Mar 04 09:50:38 volumio sudo[9819]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:38 volumio volumio[9618]: info: Asound.conf file unchanged, so no further update is needed
Mar 04 09:50:38 volumio volumio[9618]: info: Output device has changed, restarting MPD
Mar 04 09:50:38 volumio volumio[9618]: info: Output device has changed, restarting Shairport Sync
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:38 volumio sudo[9822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:50:38 volumio sudo[9822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio sudo[9822]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:38 volumio sudo[9824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:50:38 volumio sudo[9824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio volumio[9618]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:50:38 volumio volumio[9618]: info: ___________ START PLUGINS ___________
Mar 04 09:50:38 volumio volumio[9618]: info: ControllerMpd::onStart: Initializing MPD
Mar 04 09:50:38 volumio volumio[9618]: info: Creating MPD Configuration file
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:38 volumio volumio[9618]: info: [1772639438923] CoreMusicLibrary::Adding element Media Servers
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:38 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Mar 04 09:50:38 volumio sudo[9832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:50:38 volumio sudo[9832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio sudo[9834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:50:38 volumio sudo[9834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:38 volumio sudo[9832]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:38 volumio volumio[9618]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:50:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:39 volumio volumio[9618]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439058] CoreMusicLibrary::Adding element Last_100
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439064] CoreMusicLibrary::Adding element Webradio
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:50:39 volumio volumio[9618]: info: Initializing BBC Radios
Mar 04 09:50:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:39 volumio go-librespot[9842]: go-librespot daemon starting...
Mar 04 09:50:39 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:50:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:50:39 volumio systemd[1]: mpd.service: Consumed 4.123s CPU time.
Mar 04 09:50:39 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:50:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:50:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="app state loaded"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439168] CoreMusicLibrary::Adding element Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439182] CoreMusicLibrary::Adding element SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: info: Creating Spotify config file
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:39 volumio sudo[9866]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 04 09:50:39 volumio sudo[9866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 04 09:50:39 volumio sudo[9866]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=info msg="zeroconf server listening on port 44579"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="obtained new client token: AACC6QqQEZs+qMhwBhYeSWPsuCmVF332aRmt+70XLwiDeXbLytP9nikFye4QQnIrTtvHmpXnWK157vlgRzXSt8q0N7Rm3eMcz4CsP283jCcRrfd0SOx+j62xKOTow+p7vLa117BXQxqDIgGEk+r5U7BUlcoU8TqfduUSKN9gAGR+0vj88qq0n5O1Z16dd2gUPyt1H4D/1px1VvdWgIPf6bFmSpSo1mazv+zdbkuFQq6e3XA7hKLD6pbPGg=="
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:39 volumio volumio[9618]: info: [squeezelite_mc] Starting proxy server...
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439602] CoreMusicLibrary::Adding element YouTube2
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439621] CoreMusicLibrary::Adding element YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439634] CoreMusicLibrary::Adding element Podcast
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Podcast
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=debug msg="completed challenge"
Mar 04 09:50:39 volumio volumio[9618]: info: Loading i18n strings for locale en
Mar 04 09:50:39 volumio volumio[9618]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Mar 04 09:50:39 volumio volumio[9618]: Updating browse sources language
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Podcast
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Podcast
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:39 volumio volumio[9618]: info: [1772639439683] CoreMusicLibrary::Adding element Volusonic
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Podcast
Mar 04 09:50:39 volumio volumio[9618]: Cannot find translation for source Volusonic
Mar 04 09:50:39 volumio go-librespot[9849]: time="2026-03-04T09:50:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:39 volumio volumio[9618]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Mar 04 09:50:39 volumio volumio[9618]: info: Volumio Calling Home
Mar 04 09:50:39 volumio volumio[9618]: info: [squeezelite_mc] Proxy server started on port 46223
Mar 04 09:50:39 volumio volumio[9618]: info: Preparing to generate the ALSA configuration file
Mar 04 09:50:39 volumio volumio[9618]: info: CoreCommandRouter::volumioRetrievevolume
Mar 04 09:50:39 volumio volumio[9618]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Mar 04 09:50:39 volumio volumio[9618]: info: Reading ALSA contributions from plugins.
Mar 04 09:50:39 volumio volumio[9618]: info: MPD Permissions set
Mar 04 09:50:39 volumio volumio[9618]: info: MPD Permissions set
Mar 04 09:50:39 volumio volumio[9618]: info: Upmpdcli Daemon Started
Mar 04 09:50:40 volumio volumio[9618]: info: Spotify config file written
Mar 04 09:50:40 volumio sudo[9880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Mar 04 09:50:40 volumio sudo[9880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio volumio[9618]: 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 04 09:50:40 volumio volumio[9618]: info: VolumeController:: Volume=100 Mute =false
Mar 04 09:50:40 volumio volumio[9618]: info: CoreStateMachine::pushState
Mar 04 09:50:40 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::volumioPushState
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Server discovery started
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Player finder started
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Mar 04 09:50:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: No need to fix Spotify hosts
Mar 04 09:50:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:40 volumio go-librespot[9884]: go-librespot daemon starting...
Mar 04 09:50:40 volumio sudo[9880]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="app state loaded"
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:40 volumio volumio[9618]: 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 04 09:50:40 volumio volumio[9618]: info: Volumio called home
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:40 volumio volumio[9618]: info: Starting Shairport Sync
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=info msg="zeroconf server listening on port 35891"
Mar 04 09:50:40 volumio volumio[9618]: info: Starting Shairport Sync
Mar 04 09:50:40 volumio volumio[9618]: info: Starting Shairport Sync
Mar 04 09:50:40 volumio sudo[9907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:50:40 volumio sudo[9907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio sudo[9910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:50:40 volumio sudo[9910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio sudo[9904]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Mar 04 09:50:40 volumio sudo[9904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="obtained new client token: AACC1rk0BZ0kStyKkTt+1TprDk+kHbojJeQVko4vuIxAKp/JJ8hMsglNfovPABc/YXJ9zmsVmEZ68Hm/ECrg7Y8vmmlm77l//ZfmZ3z66VY2XhDuEiaVeNJA2rMUkBpKqU82orS+6AWRnbpK/2J47hsH1mCKJhqGQHCr5psVi2M+Ocj2ss1/teU0df7Bk8+inqnSzULY3TgDX/lsxYJKX5UG4+DLeALWX3bSKFuy9c/MT79eMDMqWtGgtQ=="
Mar 04 09:50:40 volumio sudo[9912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:50:40 volumio sudo[9912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio sudo[9904]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio volumio[9618]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Mar 04 09:50:40 volumio volumio[9618]: SPOTIFY: BQCbAs9NfUiFFiro-NwJsvw8fFassk76LzrkXNI2LxCAAMleb2ioCQDHKsN4QzHDZeHM8oPCrebk6n80VTCFr9qcHHaLVZCqmXyxGxSRetKGi0lx0H_QPkEyfJLDYTikhIDXvB_Q1M2n_s6RhN74WPXSz55vOyPWpvFEXIzJHLcopGJ7uzKAH8HpdiVovwFzSGk0Ud0f06-aS_m3hsT0Yluw1MU3ac2EpJQNoHQ
Mar 04 09:50:40 volumio volumio[9618]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Mar 04 09:50:40 volumio volumio[9618]: info: New Spotify access token = BQCbAs9NfUiFFiro-NwJsvw8fFassk76LzrkXNI2LxCAAMleb2ioCQDHKsN4QzHDZeHM8oPCrebk6n80VTCFr9qcHHaLVZCqmXyxGxSRetKGi0lx0H_QPkEyfJLDYTikhIDXvB_Q1M2n_s6RhN74WPXSz55vOyPWpvFEXIzJHLcopGJ7uzKAH8HpdiVovwFzSGk0Ud0f06-aS_m3hsT0Yluw1MU3ac2EpJQNoHQ
Mar 04 09:50:40 volumio volumio[9618]: info: Spotify credentials grant success - running version from March 24, 2019
Mar 04 09:50:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 04 09:50:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 04 09:50:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:50:40 volumio systemd[1]: shairport-sync.service: Consumed 2.009s CPU time.
Mar 04 09:50:40 volumio go-librespot[9895]: time="2026-03-04T09:50:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:40 volumio volumio[9618]: info: Asound.conf file unchanged, so no further update is needed
Mar 04 09:50:40 volumio volumio[9618]: info: Output device has changed, restarting MPD
Mar 04 09:50:40 volumio volumio[9618]: info: Output device has changed, restarting Shairport Sync
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:40 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:40 volumio sudo[9918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 04 09:50:40 volumio sudo[9918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:50:40 volumio sudo[9910]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio sudo[9920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 04 09:50:40 volumio sudo[9920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio sudo[9907]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio sudo[9918]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio volumio[9618]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 04 09:50:40 volumio sudo[9912]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:40 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:50:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:50:40 volumio systemd[1]: mpd.service: Consumed 1.542s CPU time.
Mar 04 09:50:40 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:50:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:50:40 volumio mpd_monitor.sh[9868]: MPD error: Connection reset by peer
Mar 04 09:50:40 volumio mpd_monitor.sh[9490]: MPD Monitor Service: MPD Appears to be inactive, restarting
Mar 04 09:50:40 volumio mpd_monitor.sh[9944]: mpd: no process found
Mar 04 09:50:40 volumio volumio[9618]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Mar 04 09:50:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:40 volumio sudo[9949]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Mar 04 09:50:40 volumio sudo[9949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:50:41 volumio sudo[9949]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 04 09:50:41 volumio volumio[9618]: info: MPD Permissions set
Mar 04 09:50:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 04 09:50:41 volumio volumio[9618]: info: Shairport-Sync Started
Mar 04 09:50:41 volumio volumio[9618]: Error adding Membership: Error: addMembership EINVAL
Mar 04 09:50:41 volumio volumio[9618]: info: Shairport-Sync Started
Mar 04 09:50:41 volumio volumio[9618]: info: Shairport-Sync Started
Mar 04 09:50:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 04 09:50:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 04 09:50:41 volumio go-librespot[9895]: time="2026-03-04T09:50:41-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:41 volumio go-librespot[9895]: time="2026-03-04T09:50:41-06:00" level=debug msg="completed challenge"
Mar 04 09:50:41 volumio volumio[9618]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Mar 04 09:50:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 04 09:50:41 volumio go-librespot[9895]: time="2026-03-04T09:50:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:41 volumio sudo[9956]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Mar 04 09:50:41 volumio sudo[9956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::volumioGetState
Mar 04 09:50:41 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:41 volumio sudo[9956]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:41 volumio volumio[9618]: info: Starting Shairport Sync
Mar 04 09:50:41 volumio sudo[9965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 04 09:50:41 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Mar 04 09:50:41 volumio sudo[9965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:41 volumio volumio[9618]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"}
Mar 04 09:50:41 volumio volumio[9618]: info: Spotify Successfully logged in
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 04 09:50:41 volumio sudo[9968]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Mar 04 09:50:41 volumio sudo[9968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:41 volumio volumio[9618]: info: [1772639441393] CoreMusicLibrary::Adding element Spotify
Mar 04 09:50:41 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source Bandcamp Discover
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source SoundCloud
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source YouTube2
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source YouTube Music
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source Podcast
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source Volusonic
Mar 04 09:50:41 volumio volumio[9618]: Cannot find translation for source Spotify
Mar 04 09:50:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 04 09:50:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 04 09:50:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:50:41 volumio sudo[9957]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 04 09:50:41 volumio sudo[9957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 04 09:50:41 volumio sudo[9957]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 04 09:50:41 volumio sudo[9965]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:41 volumio volumio[9618]: info: Shairport-Sync Started
Mar 04 09:50:41 volumio systemd[1]: Reloading.
Mar 04 09:50:42 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:42 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:42 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 04 09:50:42 volumio volumio[9618]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 04 09:50:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 09:50:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Mar 04 09:50:43 volumio sudo[9968]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:43 volumio volumio[9618]: info: go-librespot daemon successfully initialized
Mar 04 09:50:43 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:43 volumio sudo[10005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:43 volumio sudo[10005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:43 volumio sudo[10005]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:43 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Mar 04 09:50:43 volumio sudo[10008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Mar 04 09:50:43 volumio sudo[10008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:43 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 09:50:43 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Mar 04 09:50:43 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 09:50:43 volumio sudo[10008]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Mar 04 09:50:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:44 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:44 volumio sudo[10012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:44 volumio sudo[10012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:44 volumio go-librespot[10010]: go-librespot daemon starting...
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="app state loaded"
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:44 volumio sudo[10012]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:44 volumio volumio[9618]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Mar 04 09:50:44 volumio sudo[10022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Mar 04 09:50:44 volumio sudo[10022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:44 volumio sudo[10022]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:44 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Mar 04 09:50:44 volumio sudo[10025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Mar 04 09:50:44 volumio sudo[10025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:44 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:44 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Mar 04 09:50:44 volumio sudo[10025]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=info msg="zeroconf server listening on port 45163"
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="obtained new client token: AACT+cohH6/dG84C75Wd6GavRzGXoKbmo1RSqIVGlRcv9iT29Q7FElHgg1uvm8EEMxn/7MouLIoLDtGThb17P5zYel/mUL9nUsZj24z9igYWWnqdv+cvZyp0FxNZljuTH7tUyyfW8cF6z4QlcbilxIONjacxlG/zFu12+CrbVMp9fBKFi9w686y6UVB7X01unyLjPDMlv3639ZoFgiaHRqLq2z6gQ0URYvO0VdXaMnyoXKp6NbJjN+tD6g=="
Mar 04 09:50:44 volumio mpd[9972]: 2026-03-04T09:50:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 04 09:50:44 volumio go-librespot[10014]: time="2026-03-04T09:50:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:45 volumio go-librespot[10014]: time="2026-03-04T09:50:45-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:45 volumio go-librespot[10014]: time="2026-03-04T09:50:45-06:00" level=debug msg="completed challenge"
Mar 04 09:50:45 volumio go-librespot[10014]: time="2026-03-04T09:50:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:45 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Mar 04 09:50:45 volumio sudo[9834]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:45 volumio mpd_monitor.sh[9490]: MPD Monitor Service: MPD restarted due to no mpc output.
Mar 04 09:50:45 volumio sudo[9824]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:45 volumio sudo[9920]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:45 volumio volumio[9618]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 09:50:45 volumio volumio[9618]: assert.ok(self.idling)
Mar 04 09:50:45 volumio volumio[9618]: error: The expression evaluated to a falsy value:
Mar 04 09:50:45 volumio volumio[9618]: assert.ok(self.idling)
Mar 04 09:50:45 volumio volumio[9618]: error: MPD error: The expression evaluated to a falsy value:
Mar 04 09:50:45 volumio volumio[9618]: assert.ok(self.idling)
Mar 04 09:50:45 volumio volumio[9618]: error: The expression evaluated to a falsy value:
Mar 04 09:50:45 volumio volumio[9618]: assert.ok(self.idling)
Mar 04 09:50:45 volumio volumio[9618]: info: MPD running with PID9972
Mar 04 09:50:45 volumio volumio[9618]: ,establishing connection
Mar 04 09:50:45 volumio volumio[9618]: error: updateQueue error: null
Mar 04 09:50:45 volumio volumio[9618]: error: updateQueue error: null
Mar 04 09:50:45 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:45 volumio sudo[10052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:45 volumio sudo[10052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:45 volumio sudo[10052]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:45 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:45 volumio sudo[10055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:45 volumio sudo[10055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:45 volumio sudo[10055]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:46 volumio volumio[9618]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:46 volumio volumio[9618]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 04 09:50:46 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:46 volumio sudo[10058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:46 volumio sudo[10058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:46 volumio sudo[10058]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:47 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:47 volumio sudo[10061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:47 volumio sudo[10061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:47 volumio sudo[10061]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:47 volumio volumio[9618]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Mar 04 09:50:47 volumio sudo[10064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Mar 04 09:50:47 volumio sudo[10064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:47 volumio sudo[10064]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:47 volumio volumio[9618]: info: Completed starting Core Plugins
Mar 04 09:50:47 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:47 volumio volumio[9618]: info: ----- MyVolumio plugins startup ----
Mar 04 09:50:47 volumio volumio[9618]: info: -------------------------------------------
Mar 04 09:50:47 volumio volumio[9618]: info: [MyVolumio PluginManager] Fetching plans data....
Mar 04 09:50:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Mar 04 09:50:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:48 volumio sudo[10068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:50:48 volumio go-librespot[10066]: go-librespot daemon starting...
Mar 04 09:50:48 volumio sudo[10068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:48 volumio sudo[10070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:50:48 volumio sudo[10070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="app state loaded"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:48 volumio sudo[10074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:48 volumio sudo[10074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 04 09:50:48 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Mar 04 09:50:48 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Mar 04 09:50:48 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Mar 04 09:50:48 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Mar 04 09:50:48 volumio sudo[10070]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:48 volumio mpd_monitor.sh[10082]: MPD Monitor Service: Starting MPD Monitor Service
Mar 04 09:50:48 volumio sudo[10074]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:48 volumio sudo[10068]: pam_unix(sudo:session): session closed for user root
Mar 04 09:50:48 volumio volumio[9618]: info: Successfully started MPD Monitor
Mar 04 09:50:48 volumio volumio[9618]: info: Successfully started MPD Monitor
Mar 04 09:50:48 volumio volumio[9618]: info: Successfully started MPD Monitor
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=info msg="zeroconf server listening on port 42387"
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="obtained new client token: AABYpfAMM35lrfwVUe8DYNXkjOLwX5lEzpCrllzM/4vBDrFYoRKGfBTThBa29YnSn1VJBQ5vd20f+tBEvKvVqKPsgDKxmWaVv4J4WBB/rIWluWP+PFcrC5gVx8cbUJ1KEN+7mJzjksjZrB3pBum1xf5IfTt9lTe1xE16KXbzX/uHPiLxVMcYBqw2gg7stA4Fn29O/Qb4uM1UkisyV56vvrtRr2nG9Vl3c7vyjXaQTMsXAhViPpgooEnzWw=="
Mar 04 09:50:48 volumio go-librespot[10071]: time="2026-03-04T09:50:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Mar 04 09:50:49 volumio volumio[9618]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:49 volumio go-librespot[10071]: time="2026-03-04T09:50:49-06:00" level=debug msg="new websocket client"
Mar 04 09:50:49 volumio volumio[9618]: info: Connection to go-librespot Websocket established
Mar 04 09:50:49 volumio go-librespot[10071]: time="2026-03-04T09:50:49-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:49 volumio go-librespot[10071]: time="2026-03-04T09:50:49-06:00" level=debug msg="completed challenge"
Mar 04 09:50:49 volumio go-librespot[10071]: time="2026-03-04T09:50:49-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:49 volumio volumio[9618]: info: Connection to go-librespot Websocket closed
Mar 04 09:50:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Mar 04 09:50:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Mar 04 09:50:52 volumio go-librespot[10088]: go-librespot daemon starting...
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=info msg="running go-librespot 0.4.0"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=debug msg="app state loaded"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=debug msg="stored credentials not found"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Mar 04 09:50:52 volumio go-librespot[10089]: time="2026-03-04T09:50:52-06:00" level=info msg="zeroconf server listening on port 39465"
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=debug msg="obtained new client token: AACPOG0iJ8XGGry1JavSO6/beSBvXYe2yBD2uRMe7d+LS2AkFenvvmHgQUknvsCE7EdNK0S5sj4Uki+PtEC+jBj1VnErxcSr2JhoksNF3uhM/E2TSJ/L9ehKzd/hDfVrtq95u21SsfvCdqxdCNu1sP1OuD2RSqTCFFIvzy02W17V90GxKWKkXEjMYH5pjIUhgTzRvLiJVWOqPM44ubKd2Pb/FtFV5FE8JOzBunCpxgpSfJqUvQrbaHw="
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Mar 04 09:50:53 volumio volumio[9618]: info: Getting Spotify volume
Mar 04 09:50:53 volumio volumio[9618]: info: Initializing connection to go-librespot Websocket
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=debug msg="new websocket client"
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Mar 04 09:50:53 volumio volumio[9618]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Mar 04 09:50:53 volumio volumio[9618]: info: Connection to go-librespot Websocket established
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=debug msg="completed keyexchange"
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=debug msg="completed challenge"
Mar 04 09:50:53 volumio volumio[9618]: info: CoreCommandRouter::volumioGetState
Mar 04 09:50:53 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:53 volumio volumio[9618]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Mar 04 09:50:53 volumio volumio[9618]: SPOTIFY: SPOTIFY VOLUME undefined
Mar 04 09:50:53 volumio volumio[9618]: SPOTIFY: VOLUMIO VOLUME 100
Mar 04 09:50:53 volumio volumio[9618]: info: Aligning Spotify Volume to Volumio Volume
Mar 04 09:50:53 volumio volumio[9618]: info: CoreCommandRouter::volumioGetState
Mar 04 09:50:53 volumio volumio[9618]: info: CorePlayQueue::getTrack 0
Mar 04 09:50:53 volumio volumio[9618]: info: Setting Spotify Volume from Volumio: 100
Mar 04 09:50:53 volumio go-librespot[10089]: time="2026-03-04T09:50:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Mar 04 09:50:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 04 09:50:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 04 09:50:53 volumio volumio[9618]: info: Connection to go-librespot Websocket closed
Mar 04 09:50:53 volumio volumio[9618]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:50:53 volumio volumio[9618]: Error: socket hang up
Mar 04 09:50:53 volumio volumio[9618]: at connResetException (node:internal/errors:720:14)
Mar 04 09:50:53 volumio volumio[9618]: at Socket.socketOnEnd (node:_http_client:519:23)
Mar 04 09:50:53 volumio volumio[9618]: at Socket.emit (node:events:526:35)
Mar 04 09:50:53 volumio volumio[9618]: at endReadableNT (node:internal/streams/readable:1376:12)
Mar 04 09:50:53 volumio volumio[9618]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Mar 04 09:50:53 volumio volumio[9618]: code: 'ECONNRESET',
Mar 04 09:50:53 volumio volumio[9618]: response: undefined
Mar 04 09:50:53 volumio volumio[9618]: }
Mar 04 09:50:53 volumio volumio[9618]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 09:50:54 volumio sudo[10111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 09:49'
Mar 04 09:50:54 volumio sudo[10111]: 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025"
VOLUMIO_VERSION="4.069"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"