Feb 12 15:09:00 volumio volumio[23934]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:00 volumio volumio[23934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:00 volumio volumio[23934]: info: Setting Geolocation for MyVolumio to us1
Feb 12 15:09:00 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:00 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:00 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:00 volumio volumio[23934]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 15:09:01 volumio volumio[23934]: info: Updating MyVolumio device info
Feb 12 15:09:01 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:01 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:01 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Feb 12 15:09:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:01 volumio volumio[23934]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 15:09:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:01 volumio go-librespot[24506]: go-librespot daemon starting...
Feb 12 15:09:01 volumio go-librespot[24507]: time="2026-02-12T15:09:01-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:01 volumio go-librespot[24507]: time="2026-02-12T15:09:01-06:00" level=debug msg="app state loaded"
Feb 12 15:09:01 volumio go-librespot[24507]: time="2026-02-12T15:09:01-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:01 volumio go-librespot[24507]: time="2026-02-12T15:09:01-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-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]"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-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]"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-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]"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-06:00" level=info msg="zeroconf server listening on port 44627"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-06:00" level=debug msg="obtained new client token: AAASG54PALt5+NMYUYO04mV90AJPF1FU+bUc8VhxeZoF464sQaEDuBw43nw0RNG9g0iAAlTLQTuSw7RErvctpow4nvYE1xvk+JfIePs0gxVeh1E55/vJ+gmMQ2jCgVdSIafNxAzZYmmH9QePQsnaZd7LEvFmC7ZhRRliwWb1a7cqzIPHSfMcKwW5Q/5n6/Myu9qVDkXqMaPSGYW9pWUg1974K/aPTs6oiozUS81EVrONjCet/iFExi8="
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-06:00" level=debug msg="completed challenge"
Feb 12 15:09:02 volumio go-librespot[24507]: time="2026-02-12T15:09:02-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 "
Feb 12 15:09:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:03 volumio volumio[23934]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:03 volumio volumio[23934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:04 volumio volumio[23934]: info: MYVOLUMIO: Adding device
Feb 12 15:09:04 volumio volumio[23934]: info: MYVOLUMIO: Evaluating Server
Feb 12 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Feb 12 15:09:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:05 volumio go-librespot[24532]: go-librespot daemon starting...
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=debug msg="app state loaded"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-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]"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-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]"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=info msg="zeroconf server listening on port 36461"
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=debug msg="obtained new client token: AABmm6Vh3NhD/5L1JvZSVIfql9fVTxI/Y/zdthdMHyq65iwseY7sgUPyovythOJcs5fAcyoyEP7hMNy43d59binSuJYfhJ48KIjIoOna9aDi9naLnRAcJFqaaqDzsdQ5JflhnbuYy2WE1OIQ77Sk/FxO85sIc5QIzvvyOFgafcFlNbQamN8bXUnE/8fM+loS1/jNmBcbqgzWmMZ87Z0iJbAe+IPWpvU/iUbrQHYlpPVUfCd3Q2h/VfYrEA=="
Feb 12 15:09:05 volumio go-librespot[24533]: time="2026-02-12T15:09:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:06 volumio go-librespot[24533]: time="2026-02-12T15:09:06-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:06 volumio go-librespot[24533]: time="2026-02-12T15:09:06-06:00" level=debug msg="completed challenge"
Feb 12 15:09:06 volumio go-librespot[24533]: time="2026-02-12T15:09:06-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 "
Feb 12 15:09:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:06 volumio volumio[23934]: info: Setting Geolocation for MyVolumio to us1
Feb 12 15:09:06 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:06 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:06 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:06 volumio volumio[23934]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 15:09:06 volumio volumio[23934]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:06 volumio volumio[23934]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:07 volumio volumio[23934]: info: Updating MyVolumio device info
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:07 volumio volumio[23934]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 12 15:09:07 volumio volumio-remote-updater[2265]: Test mode disabled
Feb 12 15:09:07 volumio volumio-remote-updater[2265]: Alpha mode disabled
Feb 12 15:09:07 volumio volumio-remote-updater[2265]: Alpha legacy test mode disabled
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 12 15:09:07 volumio volumio[23934]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 12 15:09:07 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 12 15:09:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Feb 12 15:09:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:09 volumio go-librespot[24547]: go-librespot daemon starting...
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="app state loaded"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:09 volumio volumio[23934]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="new websocket client"
Feb 12 15:09:09 volumio volumio[23934]: info: Connection to go-librespot Websocket established
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-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]"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-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]"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-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]"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=info msg="zeroconf server listening on port 37797"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="obtained new client token: AADCUOjK+w/mrjxtSdwJUfsjEhmkC378lwSZHMWAw9KI+Ct3uhsBzeOnDwnD8os/h/B1nAjfaSJIWQWlOHzxe1p0xFa/+WDuPwfx6F7C1sQ6Uj4x+HasqY4DEQYUBZQ4O3Rw++4EeXgvtVmViMWK/bYSbLncG4RelxrA7yKbFbM7KX6S0VkpfIYolziYjkhjfaIksLvGHV1NujnnJrxNFFQjFy9xIGcjhCMD55wLaO/OpTCrtcHnwTTssg=="
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09:09-06:00" level=debug msg="completed challenge"
Feb 12 15:09:09 volumio go-librespot[24548]: time="2026-02-12T15:09: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 "
Feb 12 15:09:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:09 volumio volumio[23934]: info: Connection to go-librespot Websocket closed
Feb 12 15:09:11 volumio volumio[23934]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 12 15:09:11 volumio volumio[23934]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Feb 12 15:09:11 volumio volumio[23934]: info: CoreCommandRouter::volumioGetState
Feb 12 15:09:11 volumio volumio[23934]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:12 volumio volumio[23934]: info: Getting Spotify volume
Feb 12 15:09:12 volumio volumio[23934]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:09:12 volumio volumio[23934]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:12 volumio volumio[23934]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 15:09:12 volumio volumio[23934]:   errno: -111,
Feb 12 15:09:12 volumio volumio[23934]:   code: 'ECONNREFUSED',
Feb 12 15:09:12 volumio volumio[23934]:   syscall: 'connect',
Feb 12 15:09:12 volumio volumio[23934]:   address: '127.0.0.1',
Feb 12 15:09:12 volumio volumio[23934]:   port: 9879,
Feb 12 15:09:12 volumio volumio[23934]:   response: undefined
Feb 12 15:09:12 volumio volumio[23934]: }
Feb 12 15:09:12 volumio volumio[23934]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:09:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Feb 12 15:09:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:13 volumio go-librespot[24583]: go-librespot daemon starting...
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="app state loaded"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:13 volumio sudo[24593]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 15:08'
Feb 12 15:09:13 volumio sudo[24593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-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]"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-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]"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-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]"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=info msg="zeroconf server listening on port 40507"
Feb 12 15:09:13 volumio sudo[24593]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="obtained new client token: AADOea4b+TJfccjn1csTMEGsDnk1lBExjjDZhWPxaVA5G9L2lnATckabx9GevNpGPMrfw6Tye7AlF3koUWbpo1DFpjBFny/66QlfJLAb9510SXQ1lrRZS+3XyJkPAlc7Ov5h9RpqIYxOJ2LFqpB80V5iHStuu9KPI9SvQC4Rt1EZKNfchFOFK5D5XxmQ9HI6OVNFdwDCXV8EuTCUmSwAfnU5lEqV3Otb1ktNaq8WuurXVk1GawB050luMg=="
Feb 12 15:09:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:13 volumio volumio-remote-updater[2265]: [2026-02-12 15:09:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 15:09:13 volumio volumio-remote-updater[2265]: [2026-02-12 15:09:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 15:09:13 volumio systemd[1]: volumio.service: Consumed 55.961s CPU time.
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-06:00" level=debug msg="completed challenge"
Feb 12 15:09:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 15:09:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 15:09:13 volumio go-librespot[24584]: time="2026-02-12T15:09:13-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 "
Feb 12 15:09:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6640.
Feb 12 15:09:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 15:09:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 15:09:13 volumio systemd[1]: volumio.service: Consumed 55.961s CPU time.
Feb 12 15:09:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 15:09:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 15:09:15 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:15 volumio volumio[24605]: info: -----            Volumio3              ----
Feb 12 15:09:15 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:15 volumio volumio[24605]: info: -----          System startup          ----
Feb 12 15:09:15 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:16 volumio volumio[24605]: info: MYVOLUMIO Environment detected
Feb 12 15:09:16 volumio volumio[24605]: info: Plugin folders cleanup
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning into folder /volumio/app/plugins/
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category audio_interface
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category miscellanea
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category music_service
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category plugins.json
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category system_controller
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category user_interface
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning into folder /data/plugins/
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category audio_interface
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category music_service
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category system_controller
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category system_hardware
Feb 12 15:09:16 volumio volumio[24605]: info: Scanning category user_interface
Feb 12 15:09:16 volumio volumio[24605]: info: Plugin folders cleanup completed
Feb 12 15:09:16 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:16 volumio volumio[24605]: info: -----      Core plugins startup        ----
Feb 12 15:09:16 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:16 volumio volumio[24605]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 15:09:16 volumio volumio[24605]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 15:09:16 volumio volumio[24605]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 15:09:16 volumio volumio[24605]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 15:09:16 volumio volumio[24605]: info: Loading plugins from folder /data/plugins/
Feb 12 15:09:16 volumio volumio[24605]: info: Loading plugin "system"...
Feb 12 15:09:16 volumio volumio[24605]: info: Loading plugin "appearance"...
Feb 12 15:09:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Feb 12 15:09:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:16 volumio go-librespot[24632]: go-librespot daemon starting...
Feb 12 15:09:16 volumio go-librespot[24633]: time="2026-02-12T15:09:16-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:16 volumio go-librespot[24633]: time="2026-02-12T15:09:16-06:00" level=debug msg="app state loaded"
Feb 12 15:09:16 volumio go-librespot[24633]: time="2026-02-12T15:09:16-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:16 volumio go-librespot[24633]: time="2026-02-12T15:09:16-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-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]"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-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]"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-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]"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-06:00" level=info msg="zeroconf server listening on port 42251"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-06:00" level=debug msg="obtained new client token: AACSON32bOZhS4yJNVGnjqe5K/zTYYiR2iHnQ3DzEUcFZ5HryLJC34geBR2uDijwitoy6kZDGxYtf8RwwYRCimZSot68ghRk9EiY4mEF7HUmwavjlzPFSXQrqnwcXEnMG1sc0CGYPDSxzouDtPh25h6QAhjeJAhny+HdntwGEs+MTySfyvurQvqnDygxzvoTwQX55nw6q1Xl2Uv8/o3Zcrq2H3yrithwBVvdIRR+4wEUNwqnGvQyXT0="
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-06:00" level=debug msg="completed challenge"
Feb 12 15:09:17 volumio go-librespot[24633]: time="2026-02-12T15:09:17-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 "
Feb 12 15:09:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:17 volumio volumio[24605]: info: Loading plugin "network"...
Feb 12 15:09:17 volumio volumio[24605]: info: Refreshing Cached IP Addresses
Feb 12 15:09:17 volumio sudo[24641]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 15:09:17 volumio sudo[24641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:17 volumio sudo[24643]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 15:09:17 volumio sudo[24643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:17 volumio sudo[24641]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:17 volumio volumio[24605]: info: Loading plugin "services"...
Feb 12 15:09:17 volumio volumio[24605]: info: Loading plugin "alsa_controller"...
Feb 12 15:09:17 volumio sudo[24643]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:17 volumio sudo[24652]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 15:09:17 volumio sudo[24652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:18 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "wizard"...
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "networkfs"...
Feb 12 15:09:18 volumio volumio[24605]: info: Starting Udev Watcher for removable devices
Feb 12 15:09:18 volumio volumio[24605]: info: Ignoring mount for partition: boot
Feb 12 15:09:18 volumio volumio[24605]: info: Ignoring mount for partition: volumio
Feb 12 15:09:18 volumio volumio[24605]: info: Ignoring mount for partition: volumio_data
Feb 12 15:09:18 volumio volumio[24605]: info: Mounting Device Wikipedia
Feb 12 15:09:18 volumio sudo[24680]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 15:09:18 volumio sudo[24680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:18 volumio sudo[24680]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:18 volumio volumio[24605]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 15:09:18 volumio volumio[24605]:        dmesg(1) may have more information after failed mount system call.
Feb 12 15:09:18 volumio volumio[24605]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 15:09:18 volumio volumio[24605]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 15:09:18 volumio volumio[24605]:        dmesg(1) may have more information after failed mount system call.
Feb 12 15:09:18 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "volumio_command_line_client"...
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "upnp"...
Feb 12 15:09:18 volumio volumio[24605]: info: [1770930558291] Starting Upmpd Daemon
Feb 12 15:09:18 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "my_music"...
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "mpd"...
Feb 12 15:09:18 volumio volumio-remote-updater[2265]: [2026-02-12 15:09:18] [connect] Successful connection
Feb 12 15:09:18 volumio sudo[24652]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:18 volumio volumio[24605]: info: Loading plugin "upnp_browser"...
Feb 12 15:09:19 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:09:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Feb 12 15:09:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:20 volumio go-librespot[24683]: go-librespot daemon starting...
Feb 12 15:09:20 volumio go-librespot[24684]: time="2026-02-12T15:09:20-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:20 volumio go-librespot[24684]: time="2026-02-12T15:09:20-06:00" level=debug msg="app state loaded"
Feb 12 15:09:20 volumio go-librespot[24684]: time="2026-02-12T15:09:20-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:20 volumio go-librespot[24684]: time="2026-02-12T15:09:20-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-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]"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-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]"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-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]"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-06:00" level=info msg="zeroconf server listening on port 43289"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-06:00" level=debug msg="obtained new client token: AADvENr1bl/nCBNx8JZwlmC/0W1EOgodzGhz/3VFWhBJyjTWa0iErHcZL0H2BXAleoHE+5EZo7q0serfjzebHa0OqGouwIesDsvRetbMoTY++6iqVrnwZENUOAAaWmsQopEef6wI/BQD/Dbdp2Vc+z9MUWqAYcvbD4mBLrb1k4SZa2IihgXWfLB6QP8XJ7hpcY1rkUnW97Cmys/qPl5vod46wXOgsV0qzUg/ybvN6+q5OnAWcbUBPyc="
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-06:00" level=debug msg="completed challenge"
Feb 12 15:09:21 volumio go-librespot[24684]: time="2026-02-12T15:09:21-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 "
Feb 12 15:09:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "alarm-clock"...
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "airplay_emulation"...
Feb 12 15:09:21 volumio volumio[24605]: info: Starting Shairport Sync
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "last_100"...
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "webradio"...
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "i2s_dacs"...
Feb 12 15:09:21 volumio volumio[24605]: info: I2S DAC not set, start Auto-detection
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "volumiodiscovery"...
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** For more information see 
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:09:21 volumio volumio[24605]: *** WARNING *** For more information see 
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** For more information see 
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:09:21 volumio node[24605]: *** WARNING *** For more information see 
Feb 12 15:09:21 volumio volumio[24605]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 15:09:21 volumio volumio[24605]: info: Discovery: Started advertising with name: Volumio
Feb 12 15:09:21 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:09:21 volumio volumio[24605]: info: Loading plugin "bandcamp"...
Feb 12 15:09:23 volumio volumio[24605]: info: Plugin calmradio is not enabled
Feb 12 15:09:23 volumio volumio[24605]: info: Loading plugin "soundcloud"...
Feb 12 15:09:23 volumio volumio[24605]: info: Loading plugin "spop"...
Feb 12 15:09:24 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:09:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Feb 12 15:09:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:24 volumio go-librespot[24694]: go-librespot daemon starting...
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-06:00" level=debug msg="app state loaded"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:24 volumio volumio[24605]: info: Loading plugin "squeezelite_mc"...
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-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]"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-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]"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-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]"
Feb 12 15:09:24 volumio go-librespot[24695]: time="2026-02-12T15:09:24-06:00" level=info msg="zeroconf server listening on port 44205"
Feb 12 15:09:25 volumio go-librespot[24695]: time="2026-02-12T15:09:25-06:00" level=debug msg="obtained new client token: AAB9yjkiz00qwtLwH2Rx3b+jQdjRzyUVjru7QX8+kSyVzd1LagnfM5iWmfBoX6taAGejbCedCzI/jk5bar82S95AFw+UEOdExWE93/9stkxad6j8Ux4C/omB4Xt7frnegszXyjoFmYwFloK/EO3CUcy5QjwQgHsGfSUx3Frp5ONQqx+Qlbb1h5iONG1VztsWTXwk9NoY1UqFkNj/kkjN0cVtAnixbKwRhsbTJRfjsySiYdjPydHWdQU="
Feb 12 15:09:25 volumio go-librespot[24695]: time="2026-02-12T15:09:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:25 volumio go-librespot[24695]: time="2026-02-12T15:09:25-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:25 volumio go-librespot[24695]: time="2026-02-12T15:09:25-06:00" level=debug msg="completed challenge"
Feb 12 15:09:25 volumio go-librespot[24695]: time="2026-02-12T15:09:25-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 "
Feb 12 15:09:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:25 volumio volumio[24605]: info: Loading plugin "youtube2"...
Feb 12 15:09:26 volumio volumio[24605]: info: Loading plugin "ytcr"...
Feb 12 15:09:27 volumio volumio[24605]: info: Loading plugin "ytmusic"...
Feb 12 15:09:27 volumio volumio[24605]: info: Plugin now_playing is not enabled
Feb 12 15:09:27 volumio volumio[24605]: info: Loading plugin "outputs"...
Feb 12 15:09:27 volumio volumio[24605]: info: Loading plugin "albumart"...
Feb 12 15:09:27 volumio volumio[24605]: info: Plugin example_plugin is not enabled
Feb 12 15:09:27 volumio volumio[24605]: info: Loading plugin "inputs"...
Feb 12 15:09:27 volumio volumio[24605]: info: Loading plugin "updater_comm"...
Feb 12 15:09:28 volumio volumio[24605]: info: Plugin mpdemulation is not enabled
Feb 12 15:09:28 volumio volumio[24605]: info: Loading plugin "rest_api"...
Feb 12 15:09:28 volumio volumio[24605]: info: Loading plugin "websocket"...
Feb 12 15:09:28 volumio volumio[24605]: info: Starting Socket.io Server version 1.7.4
Feb 12 15:09:28 volumio volumio[24605]: info: Plugin fusiondsp is not enabled
Feb 12 15:09:28 volumio volumio[24605]: info: Plugin mpdoutput is not enabled
Feb 12 15:09:28 volumio volumio[24605]: info: Plugin RoonBridge is not enabled
Feb 12 15:09:28 volumio volumio[24605]: info: Loading plugin "podcast"...
Feb 12 15:09:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Feb 12 15:09:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:28 volumio go-librespot[24729]: go-librespot daemon starting...
Feb 12 15:09:28 volumio volumio[24605]: info: ControllerPodcast::constructor
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="app state loaded"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:28 volumio volumio[24605]: info: Loading plugin "volusonic"...
Feb 12 15:09:28 volumio volumio[24713]: Forking 3 albumart workers
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-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]"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-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]"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-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]"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=info msg="zeroconf server listening on port 37375"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="obtained new client token: AADvAnrQhqRGmkVwM1F8LKf3KN8MnDPOlcNvOgR2qupevgoVWxIXhcSXcW543+uAoEN1HISrTWN8hnPAfNyUSTXUGM6UjNhN3FGgTaQ2oktYsMQl0tsB0g5JWy8RaWWK+qM0azP2vHT0C2iOxWfbj+nxX0QH1u3kZUI3treu5E6eMB0TI7kaHx1coP32cy5t4woQEaPmSQutMk2jKzeIfrYYmfrxscmXydcyrnn4r4NWJVK8o6EGXO/VnQ=="
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09:28-06:00" level=debug msg="completed challenge"
Feb 12 15:09:28 volumio go-librespot[24730]: time="2026-02-12T15:09: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 "
Feb 12 15:09:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:30 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:09:30 volumio volumio[24739]: Starting albumart workers
Feb 12 15:09:30 volumio volumio[24605]: info: Applying required configuration parameters for plugin volusonic
Feb 12 15:09:30 volumio volumio[24605]: info: Loading plugin "backup_restore"...
Feb 12 15:09:30 volumio volumio[24738]: Starting albumart workers
Feb 12 15:09:30 volumio volumio[24740]: Starting albumart workers
Feb 12 15:09:31 volumio volumio-remote-updater[2265]: [2026-02-12 15:09:31] [connect] Successful connection
Feb 12 15:09:31 volumio volumio[24605]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 15:09:31 volumio volumio[24605]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 15:09:31 volumio volumio[24605]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 15:09:31 volumio volumio[24605]: info: Loading plugin "scheduledrestart"...
Feb 12 15:09:31 volumio volumio[24605]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 15:09:31 volumio volumio[24605]: info: Plugin Bluetoothremote is not enabled
Feb 12 15:09:31 volumio volumio[24605]: info: Plugin music_services_shield is not enabled
Feb 12 15:09:31 volumio volumio[24605]: info: Loading plugin "Systeminfo"...
Feb 12 15:09:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Feb 12 15:09:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:32 volumio go-librespot[24783]: go-librespot daemon starting...
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="app state loaded"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:32 volumio volumio[24605]: info: Plugin peppymeterbasic is not enabled
Feb 12 15:09:32 volumio volumio[24605]: info: Loading plugin "peppyspectrum"...
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-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]"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-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]"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-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]"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=info msg="zeroconf server listening on port 35505"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="obtained new client token: AAAtLyQdAsPBRh3IyhEsONyxZk15l+dHeiVxfw6CKTBp4RGsHQyoA3VzlCBvwm2shYwTk/dd/ChCASVcQ+vDi1PPhDwd8K/xauNi6CB2bn+t2OR+UK81lLqPaTcr8jgpIY2C58rJU1qmJ/P81TLyVZs2G1GW29xMjEpozsmA8ehKm5fH7HxLpXq981uOBljC6myQGFwEC+PUjLFII1hCsYlwFqXWLLX4/+A552DK+ZB/kFIPF/+wy0V2zg=="
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09:32-06:00" level=debug msg="completed challenge"
Feb 12 15:09:32 volumio go-librespot[24789]: time="2026-02-12T15:09: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 "
Feb 12 15:09:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:32 volumio volumio[24605]: info: Loading i18n strings for locale en
Feb 12 15:09:32 volumio volumio[24605]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 15:09:32 volumio volumio[24605]: Updating browse sources language
Feb 12 15:09:32 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::initPlayerControls
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: Express server listening on port 3000
Feb 12 15:09:33 volumio volumio[24605]:  [Metrics]  WebUI:  17s 841.83ms 
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::resetVolumioState
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::getcurrentVolume
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:33 volumio sudo[24801]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 15:09:33 volumio sudo[24801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio sudo[24803]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 15:09:33 volumio sudo[24803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio sudo[24801]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:33 volumio sudo[24803]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:33 volumio volumio[24605]: info: Volumio Network Manager: Network status updated: 1
Feb 12 15:09:33 volumio volumio[24605]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::pushState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioPushState
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::updateTrackBlock
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrackBlock
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:09:33 volumio volumio-remote-updater[2265]: [2026-02-12 15:09:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770930571 101
Feb 12 15:09:33 volumio volumio[24605]: 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
Feb 12 15:09:33 volumio volumio[24605]: info: Reloading queue from file
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::pushState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioPushState
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::setRandom null
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::pushState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioPushState
Feb 12 15:09:33 volumio volumio[24605]: info: Setting Device type: Raspberry PI
Feb 12 15:09:33 volumio volumio[24605]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:09:33 volumio volumio[24605]: info: CoreStateMachine::pushState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioPushState
Feb 12 15:09:33 volumio volumio[24605]: info: Completed loading Core Plugins
Feb 12 15:09:33 volumio volumio[24605]: info: Preparing to generate the ALSA configuration file
Feb 12 15:09:33 volumio sudo[24817]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 15:09:33 volumio sudo[24817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio volumio[24605]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 15:09:33 volumio volumio[24605]: info: Discovery: Found device Volumio
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioGetState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 15:09:33 volumio volumio[24605]: info: Discovery: Found device Volumio
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioGetState
Feb 12 15:09:33 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:33 volumio volumio[24605]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 15:09:33 volumio volumio[24605]: info: Reading ALSA contributions from plugins.
Feb 12 15:09:33 volumio sudo[24817]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:33 volumio volumio[24605]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 15:09:33 volumio volumio[24605]: info: Output device has changed, restarting MPD
Feb 12 15:09:33 volumio volumio[24605]: info: Output device has changed, restarting Shairport Sync
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:33 volumio sudo[24820]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:09:33 volumio sudo[24820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio sudo[24820]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:33 volumio sudo[24822]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:09:33 volumio sudo[24822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio volumio[24605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:09:33 volumio volumio[24605]: info: ___________ START PLUGINS ___________
Feb 12 15:09:33 volumio volumio[24605]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 15:09:33 volumio volumio[24605]: info: Creating MPD Configuration file
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:33 volumio volumio[24605]: info: [1770930573697] CoreMusicLibrary::Adding element Media Servers
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 15:09:33 volumio sudo[24830]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:09:33 volumio sudo[24830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio sudo[24830]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:33 volumio sudo[24832]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:33 volumio sudo[24832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:33 volumio volumio[24605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:33 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 15:09:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 15:09:33 volumio systemd[1]: mpd.service: Consumed 5.617s CPU time.
Feb 12 15:09:33 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 15:09:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 15:09:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 15:09:33 volumio volumio[24605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:33 volumio volumio[24605]: info: [1770930573827] CoreMusicLibrary::Adding element Last_100
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:33 volumio volumio[24605]: info: [1770930573831] CoreMusicLibrary::Adding element Webradio
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:09:33 volumio volumio[24605]: info: Initializing BBC Radios
Feb 12 15:09:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 15:09:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:33 volumio volumio[24605]: info: [1770930573912] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:33 volumio volumio[24605]: info: [1770930573924] CoreMusicLibrary::Adding element SoundCloud
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:33 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:33 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:33 volumio volumio[24605]: info: Creating Spotify config file
Feb 12 15:09:33 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio sudo[24854]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 15:09:34 volumio sudo[24854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 15:09:34 volumio sudo[24854]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:34 volumio volumio[24605]: info: [squeezelite_mc] Starting proxy server...
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:34 volumio volumio[24605]: info: [1770930574272] CoreMusicLibrary::Adding element YouTube2
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:34 volumio volumio[24605]: info: [1770930574290] CoreMusicLibrary::Adding element YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:34 volumio volumio[24605]: info: [1770930574302] CoreMusicLibrary::Adding element Podcast
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Podcast
Feb 12 15:09:34 volumio volumio[24605]: info: Loading i18n strings for locale en
Feb 12 15:09:34 volumio volumio[24605]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 15:09:34 volumio volumio[24605]: Updating browse sources language
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Podcast
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Podcast
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:34 volumio volumio[24605]: info: [1770930574357] CoreMusicLibrary::Adding element Volusonic
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Podcast
Feb 12 15:09:34 volumio volumio[24605]: Cannot find translation for source Volusonic
Feb 12 15:09:34 volumio volumio[24605]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 15:09:34 volumio volumio[24605]: info: Volumio Calling Home
Feb 12 15:09:34 volumio volumio[24605]: info: [squeezelite_mc] Proxy server started on port 38975
Feb 12 15:09:34 volumio volumio[24605]: info: Preparing to generate the ALSA configuration file
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:09:34 volumio volumio[24605]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 15:09:34 volumio volumio[24605]: info: Reading ALSA contributions from plugins.
Feb 12 15:09:34 volumio volumio[24605]: info: MPD Permissions set
Feb 12 15:09:34 volumio volumio[24605]: info: MPD Permissions set
Feb 12 15:09:34 volumio volumio[24605]: info: Upmpdcli Daemon Started
Feb 12 15:09:34 volumio volumio[24605]: info: Spotify config file written
Feb 12 15:09:34 volumio sudo[24867]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 15:09:34 volumio sudo[24867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:34 volumio volumio[24605]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 12 15:09:34 volumio volumio[24605]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:09:34 volumio volumio[24605]: info: CoreStateMachine::pushState
Feb 12 15:09:34 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::volumioPushState
Feb 12 15:09:34 volumio volumio[24605]: info: [squeezelite_mc] Server discovery started
Feb 12 15:09:34 volumio volumio[24605]: info: [squeezelite_mc] Player finder started
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 15:09:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:34 volumio go-librespot[24870]: go-librespot daemon starting...
Feb 12 15:09:34 volumio sudo[24867]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:34 volumio volumio[24605]: info: No need to fix Spotify hosts
Feb 12 15:09:34 volumio go-librespot[24878]: time="2026-02-12T15:09:34-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:34 volumio go-librespot[24878]: time="2026-02-12T15:09:34-06:00" level=debug msg="app state loaded"
Feb 12 15:09:34 volumio go-librespot[24878]: time="2026-02-12T15:09:34-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:34 volumio go-librespot[24878]: time="2026-02-12T15:09:34-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:35 volumio volumio[24605]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 12 15:09:35 volumio volumio[24605]: info: Volumio called home
Feb 12 15:09:35 volumio volumio[24605]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 15:09:35 volumio volumio[24605]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 15:09:35 volumio volumio[24605]: 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
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09: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]"
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09: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]"
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09: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]"
Feb 12 15:09:35 volumio volumio[24605]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 15:09:35 volumio volumio[24605]: SPOTIFY: BQBEMe5FWlLTwoUwl_jk1amSP8SLP2cmynd8cu6fdoISm55yz0BsbDVLt4hLL0N4XjvkLHzM7BN2uMNicJHiOu_y_ULlCk4ysVMvZuKezym3XRhDsvIh-oExKcyCZPfzvlXlFecycgUSQIk2j9Yjc0dt_L2a0cfCIC-ce___-4J7NJugZ304U4jd9wQLPPOnfEZNo_pUSSV0iMaVQHVyxDQlzPWOyxxQ0Ghb7Yg
Feb 12 15:09:35 volumio volumio[24605]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 15:09:35 volumio volumio[24605]: info: New Spotify access token = BQBEMe5FWlLTwoUwl_jk1amSP8SLP2cmynd8cu6fdoISm55yz0BsbDVLt4hLL0N4XjvkLHzM7BN2uMNicJHiOu_y_ULlCk4ysVMvZuKezym3XRhDsvIh-oExKcyCZPfzvlXlFecycgUSQIk2j9Yjc0dt_L2a0cfCIC-ce___-4J7NJugZ304U4jd9wQLPPOnfEZNo_pUSSV0iMaVQHVyxDQlzPWOyxxQ0Ghb7Yg
Feb 12 15:09:35 volumio volumio[24605]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09:35-06:00" level=info msg="zeroconf server listening on port 44253"
Feb 12 15:09:35 volumio volumio[24605]: info: Starting Shairport Sync
Feb 12 15:09:35 volumio sudo[24891]:  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
Feb 12 15:09:35 volumio sudo[24891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio volumio[24605]: info: Starting Shairport Sync
Feb 12 15:09:35 volumio sudo[24891]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio volumio[24605]: info: Starting Shairport Sync
Feb 12 15:09:35 volumio sudo[24894]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09:35-06:00" level=debug msg="obtained new client token: AACpJVMKsUIzBFuJ4cL9NYebpjD66zKKEXJWly3mbDUdUR3Jlc/9Gw7QNwzlxmDVmKaplu+mhDV3azP7yDtHzGMyQo5HpawDsaTh7k9xFBvYULRHSiVTVY0U8WgUSLDPcP1dYrWUqcNd4W5TSHzcZZGr5jL2YtV998XyU3XQqOUvhUpg+bUytXtQ0CpdhjTXXB/rGKxVQx2vH0tsxWx0Q7AhRWiv97EOAxAgwI9blva5LHkyY4xJ+r3oLA=="
Feb 12 15:09:35 volumio sudo[24894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio sudo[24897]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:09:35 volumio sudo[24897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio volumio[24605]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 15:09:35 volumio sudo[24898]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:09:35 volumio sudo[24898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio volumio[24605]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 15:09:35 volumio volumio[24605]: info: Output device has changed, restarting MPD
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:35 volumio sudo[24904]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 15:09:35 volumio sudo[24904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio volumio[24605]: info: Output device has changed, restarting Shairport Sync
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09:35-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09:35-06:00" level=debug msg="completed challenge"
Feb 12 15:09:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 15:09:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:09:35 volumio systemd[1]: shairport-sync.service: Consumed 2.143s CPU time.
Feb 12 15:09:35 volumio sudo[24904]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio sudo[24907]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:09:35 volumio sudo[24907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio sudo[24909]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:09:35 volumio sudo[24909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio sudo[24907]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio go-librespot[24878]: time="2026-02-12T15:09: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 "
Feb 12 15:09:35 volumio volumio[24605]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:09:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:09:35 volumio sudo[24897]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio sudo[24894]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:35 volumio sudo[24898]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 15:09:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 15:09:35 volumio systemd[1]: mpd.service: Consumed 1.586s CPU time.
Feb 12 15:09:35 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 15:09:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 15:09:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 15:09:35 volumio volumio[24605]: info: MPD Permissions set
Feb 12 15:09:35 volumio volumio[24605]: info: Shairport-Sync Started
Feb 12 15:09:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 15:09:35 volumio volumio[24605]: Error adding Membership: Error: addMembership EINVAL
Feb 12 15:09:35 volumio volumio[24605]: info: Shairport-Sync Started
Feb 12 15:09:35 volumio volumio[24605]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 15:09:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 15:09:35 volumio volumio[24605]: info: Shairport-Sync Started
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio sudo[24940]:  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
Feb 12 15:09:35 volumio sudo[24940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:35 volumio sudo[24940]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:35 volumio volumio[24605]: info: CoreCommandRouter::volumioGetState
Feb 12 15:09:35 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:09:35 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 15:09:35 volumio volumio[24605]: info: Starting Shairport Sync
Feb 12 15:09:35 volumio volumio[24605]: 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"}
Feb 12 15:09:36 volumio volumio[24605]: info: Spotify Successfully logged in
Feb 12 15:09:36 volumio sudo[24948]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 15:09:36 volumio sudo[24948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:36 volumio volumio[24605]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:09:36 volumio volumio[24605]: info: [1770930576017] CoreMusicLibrary::Adding element Spotify
Feb 12 15:09:36 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source Bandcamp Discover
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source SoundCloud
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source YouTube2
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source YouTube Music
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source Podcast
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source Volusonic
Feb 12 15:09:36 volumio volumio[24605]: Cannot find translation for source Spotify
Feb 12 15:09:36 volumio sudo[24950]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:09:36 volumio sudo[24950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:36 volumio sudo[24937]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 15:09:36 volumio sudo[24937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 15:09:36 volumio sudo[24937]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:36 volumio systemd[1]: Reloading.
Feb 12 15:09:36 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:09:37 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:37 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:37 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:09:37 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:09:38 volumio volumio[24605]: info: go-librespot daemon successfully initialized
Feb 12 15:09:38 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:09:38 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.
Feb 12 15:09:38 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.
Feb 12 15:09:39 volumio sudo[24948]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:39 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Feb 12 15:09:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:39 volumio sudo[24988]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:39 volumio sudo[24988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:39 volumio go-librespot[24989]: go-librespot daemon starting...
Feb 12 15:09:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 15:09:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 15:09:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:09:39 volumio systemd[1]: shairport-sync.service: Consumed 1.531s CPU time.
Feb 12 15:09:39 volumio go-librespot[24991]: time="2026-02-12T15:09:39-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:39 volumio go-librespot[24991]: time="2026-02-12T15:09:39-06:00" level=debug msg="app state loaded"
Feb 12 15:09:39 volumio go-librespot[24991]: time="2026-02-12T15:09:39-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:39 volumio go-librespot[24991]: time="2026-02-12T15:09:39-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:39 volumio sudo[24988]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:39 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 15:09:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:09:39 volumio sudo[24950]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:39 volumio volumio[24605]: info: Shairport-Sync Started
Feb 12 15:09:39 volumio sudo[24999]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 15:09:39 volumio sudo[24999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:39 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 15:09:40 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 15:09:40 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09: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]"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09: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]"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09: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]"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-06:00" level=info msg="zeroconf server listening on port 36095"
Feb 12 15:09:40 volumio sudo[24999]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-06:00" level=debug msg="obtained new client token: AACAklzFUiWcM81coXtZ8MOyxAxLgc7Tc6WE6k0z26BcVRorkmjP0pDGDGbCrODh6/w9kwgw+FUM50HgKfbtymclWL7V9u53CmpQGWV18QsDCCtsyUC4NOyWISjY7BryAWyiwgTYadVLTiNHMMRgyi0vN+esnR66EAOS9OIXQ53T4kI5ta4gCDgzL9kAB9KmCIlPW745rU7kq2l5DrEWRD+bctvY6HnCZkilom0OhMFJOtufO/m6F2U="
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-06:00" level=debug msg="completed challenge"
Feb 12 15:09:40 volumio go-librespot[24991]: time="2026-02-12T15:09:40-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 "
Feb 12 15:09:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:40 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:40 volumio sudo[25017]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:40 volumio sudo[25017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:40 volumio sudo[25017]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:40 volumio volumio[24605]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 15:09:40 volumio sudo[25021]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 15:09:40 volumio sudo[25021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:40 volumio sudo[25021]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:40 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 15:09:40 volumio sudo[25024]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 15:09:40 volumio sudo[25024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:40 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 15:09:40 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 15:09:40 volumio sudo[25024]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:41 volumio mpd[24954]: 2026-02-12T15:09:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 15:09:41 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:41 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:41 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 15:09:41 volumio sudo[24832]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:41 volumio sudo[24909]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:41 volumio sudo[24822]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:41 volumio volumio[24605]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 15:09:41 volumio volumio[24605]:   assert.ok(self.idling)
Feb 12 15:09:41 volumio volumio[24605]: error: The expression evaluated to a falsy value:
Feb 12 15:09:41 volumio volumio[24605]:   assert.ok(self.idling)
Feb 12 15:09:41 volumio volumio[24605]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 15:09:41 volumio volumio[24605]:   assert.ok(self.idling)
Feb 12 15:09:41 volumio volumio[24605]: error: The expression evaluated to a falsy value:
Feb 12 15:09:41 volumio volumio[24605]:   assert.ok(self.idling)
Feb 12 15:09:41 volumio volumio[24605]: info: MPD running with PID24954
Feb 12 15:09:41 volumio volumio[24605]:  ,establishing connection
Feb 12 15:09:41 volumio volumio[24605]: error: updateQueue error: null
Feb 12 15:09:41 volumio volumio[24605]: error: updateQueue error: null
Feb 12 15:09:41 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:41 volumio sudo[25035]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:41 volumio sudo[25035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:41 volumio sudo[25035]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:42 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:42 volumio sudo[25038]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:42 volumio sudo[25038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:42 volumio sudo[25038]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:42 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:42 volumio sudo[25041]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:42 volumio sudo[25041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:42 volumio sudo[25041]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:42 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:09:43 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:43 volumio sudo[25045]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:43 volumio sudo[25045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:43 volumio sudo[25045]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Feb 12 15:09:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:43 volumio go-librespot[25047]: go-librespot daemon starting...
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=debug msg="app state loaded"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:43 volumio volumio[24605]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-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]"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-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]"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-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]"
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=info msg="zeroconf server listening on port 40671"
Feb 12 15:09:43 volumio sudo[25056]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:09:43 volumio sudo[25056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:43 volumio sudo[25056]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:43 volumio volumio[24605]: info: Completed starting Core Plugins
Feb 12 15:09:43 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:43 volumio volumio[24605]: info: -----    MyVolumio plugins startup     ----
Feb 12 15:09:43 volumio volumio[24605]: info: -------------------------------------------
Feb 12 15:09:43 volumio volumio[24605]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=debug msg="obtained new client token: AADnBfc0s98HfwLyfoPRoIvE1ApnCzCbpoeuG3KUIdYOhBRaUckf0B3NWA3St1Mhm64y9R9L1xwobSXD5SGpl8j8JXE6DI1kSpEnsPsSXv1SrR5goL1t3ss3Lhm7MuJZ1bRaCrwfpbG87ESa5W39mAy6Q/RQtfJnOFYrETLxZTmVr5NN+cfUAcgDk7TioCYSbIGn8/einrVahrzQ2+jB6xjJWO60HQeg979uEOt5K/6U2UsijnJd665HdQ=="
Feb 12 15:09:43 volumio go-librespot[25048]: time="2026-02-12T15:09:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:44 volumio go-librespot[25048]: time="2026-02-12T15:09:44-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:44 volumio go-librespot[25048]: time="2026-02-12T15:09:44-06:00" level=debug msg="completed challenge"
Feb 12 15:09:44 volumio go-librespot[25048]: time="2026-02-12T15:09:44-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 "
Feb 12 15:09:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:44 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:44 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:44 volumio sudo[25059]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:09:44 volumio sudo[25059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:44 volumio sudo[25061]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:09:44 volumio sudo[25061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:44 volumio sudo[25064]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:09:44 volumio sudo[25064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:44 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 15:09:44 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 15:09:44 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 15:09:44 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 15:09:44 volumio sudo[25064]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:44 volumio sudo[25059]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:44 volumio sudo[25061]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:44 volumio mpd_monitor.sh[25067]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 15:09:44 volumio volumio[24605]: info: Successfully started MPD Monitor
Feb 12 15:09:44 volumio volumio[24605]: info: Successfully started MPD Monitor
Feb 12 15:09:44 volumio volumio[24605]: info: Successfully started MPD Monitor
Feb 12 15:09:47 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Feb 12 15:09:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:47 volumio go-librespot[25071]: go-librespot daemon starting...
Feb 12 15:09:47 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="app state loaded"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-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]"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-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]"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-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]"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=info msg="zeroconf server listening on port 42329"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="obtained new client token: AAAkEO28eJ8Dy4iz/91Z8A7SkvNzMj8zEf6zBqa4pN2uTlm/PFJS4Qt+A64Keo4/p5pBE2VggIvyPiZ9rIiGqSAi14mqCMu8hbwXQRNkd03nq7G6WQdNrfeJVtmYo1C0sW12lYXqkIh1UjcrDD/KzlHLxUyTHhBwyTX9ReDFwP1g8Dbe4kIPlk6Dc5rUTY9CLaD1ObDs67pkuzQVLVZGQ7gmRCBGvymP0geEQeMeGPtNsalVhdRp3CNkOg=="
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-06:00" level=debug msg="completed challenge"
Feb 12 15:09:47 volumio go-librespot[25072]: time="2026-02-12T15:09:47-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 "
Feb 12 15:09:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:49 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:09:50 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:50 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Feb 12 15:09:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:51 volumio go-librespot[25095]: go-librespot daemon starting...
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="app state loaded"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-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]"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-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]"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-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]"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=info msg="zeroconf server listening on port 36753"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="obtained new client token: AADTIA9ofTjOdL1QFyMHeiMML09HHdO5Fipn4+cgRbr/WTr82Y5GYbuObTLpiP1GV6xKfr+xql9j4RFeV4m6yGM8anlCDuotWsuZWG4KqmcAznlwiJqMVCY5yLw1r1dHT6gESIkIK20J5uTVosjP3p8b+TsmM3FTcuqENUW8vmj24pnqO1LjYzDwCBNtZ4wJNjsqramVMFbrvzz5FZsP3ViONlj62khA/+NlvpbumDsnGoMuxq0ld37w8w=="
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-06:00" level=debug msg="completed challenge"
Feb 12 15:09:51 volumio go-librespot[25096]: time="2026-02-12T15:09:51-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 "
Feb 12 15:09:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 15:09:52 volumio volumio[24605]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 15:09:53 volumio volumio[24605]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 15:09:53 volumio volumio[24605]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 15:09:53 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:53 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:53 volumio volumio[24605]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 15:09:53 volumio volumio[24605]: info: MyVolumio login type: Token
Feb 12 15:09:53 volumio volumio[24605]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 15:09:53 volumio volumio[24605]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 15:09:53 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:09:54 volumio volumio[24605]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 15:09:54 volumio volumio[24605]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 15:09:54 volumio volumio[24605]: info: Streaming services startup
Feb 12 15:09:54 volumio volumio[24605]: info: Starting Streaming Daemon
Feb 12 15:09:54 volumio sudo[25105]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 15:09:54 volumio sudo[25105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:54 volumio volumio[24605]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 15:09:54 volumio sudo[25105]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:54 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:54 volumio volumio[24605]: error: Cannot start Volumio Streaming Daemon
Feb 12 15:09:54 volumio volumio[24605]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 15:09:54 volumio volumio[24605]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 15:09:54 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:54 volumio volumio[24605]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 12 15:09:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Feb 12 15:09:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:54 volumio go-librespot[25111]: go-librespot daemon starting...
Feb 12 15:09:54 volumio go-librespot[25112]: time="2026-02-12T15:09:54-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:54 volumio go-librespot[25112]: time="2026-02-12T15:09:54-06:00" level=debug msg="app state loaded"
Feb 12 15:09:54 volumio go-librespot[25112]: time="2026-02-12T15:09:54-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:54 volumio go-librespot[25112]: time="2026-02-12T15:09:54-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:54 volumio volumio[24605]: info: MyVolumio token set successfully
Feb 12 15:09:54 volumio volumio[24605]: info: MYVOLUMIO: Adding device
Feb 12 15:09:54 volumio volumio[24605]: info: MYVOLUMIO: Evaluating Server
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-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]"
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-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]"
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-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]"
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-06:00" level=info msg="zeroconf server listening on port 42249"
Feb 12 15:09:55 volumio volumio[24605]: info: MyVolumio status changed
Feb 12 15:09:55 volumio volumio[24605]: info: Streaming services startup
Feb 12 15:09:55 volumio volumio[24605]: info: Starting Streaming Daemon
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-06:00" level=debug msg="obtained new client token: AAB9v5uobUKFuDVPAVIPIK5ZDgcTmlKLn7LY70TjgSGY16mMl2MRS5AFdHrgW3WgOKuwhPkKky+0T3ZYfnVJlPItEN8DtBh48hNyKlinNUT3iUZfOrn6hjKPt6Su3MFkqbKlSjlrwlrReK+V5FDFwmXa8IE/4yU7dw9qbxAAg8mTXwqzsS2zvJBPVacu2hm+FxXzAzvF3fwLlKSLlNPIqkgakmlovsOHPrF0CnA5liZi+LAFT0Ks5oc="
Feb 12 15:09:55 volumio volumio[24605]: info: Removing browser output: myVolumio user plan is not superstar
Feb 12 15:09:55 volumio volumio[24605]: info: Removing audio output:
Feb 12 15:09:55 volumio volumio[24605]: info: Stoppping Tunnel 1
Feb 12 15:09:55 volumio sudo[25140]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 15:09:55 volumio sudo[25140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:55 volumio sudo[25142]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 12 15:09:55 volumio sudo[25142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:55 volumio sudo[25140]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio volumio[24605]: error: Cannot start Volumio Streaming Daemon
Feb 12 15:09:55 volumio volumio[24605]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 15:09:55 volumio volumio[24605]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-06:00" level=debug msg="completed challenge"
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 15:09:55 volumio sudo[25142]: pam_unix(sudo:session): session closed for user root
Feb 12 15:09:55 volumio volumio[24605]: info: Remote SSH Stopped
Feb 12 15:09:55 volumio go-librespot[25112]: time="2026-02-12T15:09:55-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 "
Feb 12 15:09:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:55 volumio volumio[24605]: info: Setting Geolocation for MyVolumio to us4
Feb 12 15:09:55 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:55 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:55 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:55 volumio volumio[24605]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 15:09:56 volumio volumio[24605]: info: Updating MyVolumio device info
Feb 12 15:09:56 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:56 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:56 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:09:56 volumio volumio[24605]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 15:09:57 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:09:57 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:09:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Feb 12 15:09:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:09:58 volumio go-librespot[25159]: go-librespot daemon starting...
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=debug msg="app state loaded"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=debug msg="stored credentials not found"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-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]"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-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]"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-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]"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=info msg="zeroconf server listening on port 33433"
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=debug msg="obtained new client token: AACibawemwucMOagHXQ8CJ8SZyrK4pnMj5/9Ea6qdJpxVaKhHaYykvAvfwgMNk6N52Vn6S0vCwT4tQvS6NZuiCaccOBzKq718zWvP6LICXeJQpj3edJDx8nnoXEvViSCAsGU/E9JxKWL1LMAKeCemHfyPoOwiMa5uR+CbPUzP3Ew/d1OvHpnRcEgVskrXCvcSayddvW82bIbq0qXHbHzm5nPkbpGZ9zwMEf2zphHhGSEkRghNLA846O7cQ=="
Feb 12 15:09:58 volumio go-librespot[25160]: time="2026-02-12T15:09:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:09:59 volumio go-librespot[25160]: time="2026-02-12T15:09:59-06:00" level=debug msg="completed keyexchange"
Feb 12 15:09:59 volumio go-librespot[25160]: time="2026-02-12T15:09:59-06:00" level=debug msg="completed challenge"
Feb 12 15:09:59 volumio go-librespot[25160]: time="2026-02-12T15:09:59-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 "
Feb 12 15:09:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:09:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:09:59 volumio volumio[24605]: info: MYVOLUMIO: Adding device
Feb 12 15:09:59 volumio volumio[24605]: info: MYVOLUMIO: Evaluating Server
Feb 12 15:10:00 volumio volumio[24605]: info: Setting Geolocation for MyVolumio to us4
Feb 12 15:10:00 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:00 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:00 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:00 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:00 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:10:00 volumio volumio[24605]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 15:10:01 volumio volumio[24605]: info: Updating MyVolumio device info
Feb 12 15:10:01 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:01 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:01 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:01 volumio volumio[24605]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 15:10:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Feb 12 15:10:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:02 volumio go-librespot[25186]: go-librespot daemon starting...
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="app state loaded"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-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]"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-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]"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-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]"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=info msg="zeroconf server listening on port 41741"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="obtained new client token: AABlFDFWLe0An4fd9t6OFfO4sd1en3kLXjv2gp1q8sCpsoFUvG6+nXrjry3UmyFrFRGRzMkniQqZ6SDqYzHrs6bXRLpSE5MxSS7y2H4ohsWJPsgDYpDhWBT9oEhjqQxnD/t8kyDd546YZVOyA18esmcA76E/XnFzpTDyp8XCL1OK/6nFmn9arRaDmYKiO5T232DIC4Um8wf2W1qu7ByYcLm1o9dDihss5A6YCEf0SNIfqLA/TKehNHuIZg=="
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-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"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-06:00" level=debug msg="completed challenge"
Feb 12 15:10:02 volumio go-librespot[25187]: time="2026-02-12T15:10:02-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 "
Feb 12 15:10:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:03 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:03 volumio volumio[24605]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:10:04 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:10:04 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:04 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 12 15:10:04 volumio volumio-remote-updater[2265]: Test mode disabled
Feb 12 15:10:04 volumio volumio-remote-updater[2265]: Alpha mode disabled
Feb 12 15:10:04 volumio volumio-remote-updater[2265]: Alpha legacy test mode disabled
Feb 12 15:10:04 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 12 15:10:04 volumio volumio[24605]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 12 15:10:04 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 12 15:10:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Feb 12 15:10:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:06 volumio go-librespot[25201]: go-librespot daemon starting...
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="app state loaded"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:06 volumio volumio[24605]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="new websocket client"
Feb 12 15:10:06 volumio volumio[24605]: info: Connection to go-librespot Websocket established
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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]"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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]"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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]"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=info msg="zeroconf server listening on port 39731"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="obtained new client token: AACzzWVH3BHj3HueJcDs5KaX2VMr+lMCfv+3EFxEf+Mg5qVFXMpw+KzgA1YHtCieTewOtl2iORqf1ztc8XQmHjVcfH0g+e06QplYcnqj+k1HR9b4nHOjTkPhdeu6CQHRHBUeWis5VCCe7XpQ8Y19pbmgUuuje1/Gh9hWPgJs28jMyutL3twYfW8Ns3cTNzuVwgKk8WWggRVeZ8maM4uzpv0nIhpAzQXvI0BnZpq359k/9I/ZwfTP+b4bVw=="
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:80"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-06:00" level=debug msg="completed challenge"
Feb 12 15:10:06 volumio go-librespot[25202]: time="2026-02-12T15:10:06-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 "
Feb 12 15:10:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:06 volumio volumio[24605]: info: Connection to go-librespot Websocket closed
Feb 12 15:10:08 volumio volumio[24605]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 12 15:10:08 volumio volumio[24605]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Feb 12 15:10:08 volumio volumio[24605]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:08 volumio volumio[24605]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:09 volumio volumio[24605]: info: Getting Spotify volume
Feb 12 15:10:09 volumio volumio[24605]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:10:09 volumio volumio[24605]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:10:09 volumio volumio[24605]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 15:10:09 volumio volumio[24605]:   errno: -111,
Feb 12 15:10:09 volumio volumio[24605]:   code: 'ECONNREFUSED',
Feb 12 15:10:09 volumio volumio[24605]:   syscall: 'connect',
Feb 12 15:10:09 volumio volumio[24605]:   address: '127.0.0.1',
Feb 12 15:10:09 volumio volumio[24605]:   port: 9879,
Feb 12 15:10:09 volumio volumio[24605]:   response: undefined
Feb 12 15:10:09 volumio volumio[24605]: }
Feb 12 15:10:09 volumio volumio[24605]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:10:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Feb 12 15:10:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:09 volumio go-librespot[25235]: go-librespot daemon starting...
Feb 12 15:10:09 volumio go-librespot[25236]: time="2026-02-12T15:10:09-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:09 volumio go-librespot[25236]: time="2026-02-12T15:10:09-06:00" level=debug msg="app state loaded"
Feb 12 15:10:09 volumio go-librespot[25236]: time="2026-02-12T15:10:09-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:09 volumio go-librespot[25236]: time="2026-02-12T15:10:09-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:10 volumio sudo[25245]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 15:09'
Feb 12 15:10:10 volumio sudo[25245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-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]"
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-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]"
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-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]"
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-06:00" level=info msg="zeroconf server listening on port 46227"
Feb 12 15:10:10 volumio sudo[25245]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-06:00" level=debug msg="obtained new client token: AAAoWFI+gMRfosgaIaoeSuYHjD92Sg62wGbwb3TqU/oGP0xBSIjSzjmPhdvArwj8tX8SihXSVywdNAFe4qzPqZ5RPrpYsE5Z8YMR+DzczMmukgk7SSD6nexEQSWtHnCTed5RPh+pXLxPN7M6Ye5qbr8T/h+p3uq3khNU8hQk1XOD8E0cSf3votS3EQiSB+PnmP5K0NvWm2ErmNS9SWIs7+Rm2gJhIGW3j1Q3aXQ1VLV6bp4oFycGDmY="
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:10 volumio volumio-remote-updater[2265]: [2026-02-12 15:10:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 15:10:10 volumio volumio-remote-updater[2265]: [2026-02-12 15:10:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 15:10:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 15:10:10 volumio systemd[1]: volumio.service: Consumed 53.471s CPU time.
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-06:00" level=debug msg="completed challenge"
Feb 12 15:10:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 15:10:10 volumio go-librespot[25236]: time="2026-02-12T15:10:10-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 "
Feb 12 15:10:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 15:10:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6641.
Feb 12 15:10:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 15:10:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 15:10:10 volumio systemd[1]: volumio.service: Consumed 53.471s CPU time.
Feb 12 15:10:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 15:10:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 15:10:12 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:12 volumio volumio[25262]: info: -----            Volumio3              ----
Feb 12 15:10:12 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:12 volumio volumio[25262]: info: -----          System startup          ----
Feb 12 15:10:12 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:13 volumio volumio[25262]: info: MYVOLUMIO Environment detected
Feb 12 15:10:13 volumio volumio[25262]: info: Plugin folders cleanup
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning into folder /volumio/app/plugins/
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category audio_interface
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category miscellanea
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category music_service
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category plugins.json
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category system_controller
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category user_interface
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning into folder /data/plugins/
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category audio_interface
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category music_service
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category system_controller
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category system_hardware
Feb 12 15:10:13 volumio volumio[25262]: info: Scanning category user_interface
Feb 12 15:10:13 volumio volumio[25262]: info: Plugin folders cleanup completed
Feb 12 15:10:13 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:13 volumio volumio[25262]: info: -----      Core plugins startup        ----
Feb 12 15:10:13 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:13 volumio volumio[25262]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 15:10:13 volumio volumio[25262]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 15:10:13 volumio volumio[25262]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 15:10:13 volumio volumio[25262]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 15:10:13 volumio volumio[25262]: info: Loading plugins from folder /data/plugins/
Feb 12 15:10:13 volumio volumio[25262]: info: Loading plugin "system"...
Feb 12 15:10:13 volumio volumio[25262]: info: Loading plugin "appearance"...
Feb 12 15:10:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Feb 12 15:10:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:13 volumio go-librespot[25289]: go-librespot daemon starting...
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-06:00" level=debug msg="app state loaded"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-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]"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-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]"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-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]"
Feb 12 15:10:13 volumio go-librespot[25290]: time="2026-02-12T15:10:13-06:00" level=info msg="zeroconf server listening on port 38627"
Feb 12 15:10:14 volumio go-librespot[25290]: time="2026-02-12T15:10:14-06:00" level=debug msg="obtained new client token: AAA0/uVKMIHZJCnY2QALhSQKebEOJPkq4D5F623HZz4jtCIkhr93vNAXl/IbqNQgHYVTUhTKMQWQL3tlvSAcwKHfT5FyhrVWSyXJHWK8QORyiEA+XEd6KmOLTs8tJAOQZ7CcxEYmx+FiOx1XM8f2LjxIY8jE5lPWpBvZnlbT+yX17o0w435uXFk5zyEO7D/Qor3A+HfOCERyMVqvFV7jYSNxtcvtTEAVPo6xWgZIEH/YH0OExYy3OykPVA=="
Feb 12 15:10:14 volumio go-librespot[25290]: time="2026-02-12T15:10:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:14 volumio go-librespot[25290]: time="2026-02-12T15:10:14-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:14 volumio go-librespot[25290]: time="2026-02-12T15:10:14-06:00" level=debug msg="completed challenge"
Feb 12 15:10:14 volumio go-librespot[25290]: time="2026-02-12T15:10:14-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 "
Feb 12 15:10:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:14 volumio volumio[25262]: info: Loading plugin "network"...
Feb 12 15:10:14 volumio volumio[25262]: info: Refreshing Cached IP Addresses
Feb 12 15:10:14 volumio sudo[25299]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 15:10:14 volumio sudo[25299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:14 volumio sudo[25301]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 15:10:14 volumio sudo[25301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:14 volumio sudo[25299]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:14 volumio sudo[25301]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:14 volumio volumio[25262]: info: Loading plugin "services"...
Feb 12 15:10:14 volumio volumio[25262]: info: Loading plugin "alsa_controller"...
Feb 12 15:10:14 volumio sudo[25310]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 15:10:14 volumio sudo[25310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:14 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:10:14 volumio volumio[25262]: info: Loading plugin "wizard"...
Feb 12 15:10:14 volumio volumio[25262]: info: Loading plugin "networkfs"...
Feb 12 15:10:14 volumio volumio[25262]: info: Starting Udev Watcher for removable devices
Feb 12 15:10:14 volumio volumio[25262]: info: Ignoring mount for partition: boot
Feb 12 15:10:14 volumio volumio[25262]: info: Ignoring mount for partition: volumio
Feb 12 15:10:14 volumio volumio[25262]: info: Ignoring mount for partition: volumio_data
Feb 12 15:10:14 volumio volumio[25262]: info: Mounting Device Wikipedia
Feb 12 15:10:14 volumio sudo[25338]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 15:10:14 volumio sudo[25338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:14 volumio sudo[25338]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:14 volumio volumio[25262]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 15:10:14 volumio volumio[25262]:        dmesg(1) may have more information after failed mount system call.
Feb 12 15:10:14 volumio volumio[25262]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 15:10:14 volumio volumio[25262]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 15:10:14 volumio volumio[25262]:        dmesg(1) may have more information after failed mount system call.
Feb 12 15:10:14 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:10:15 volumio volumio[25262]: info: Loading plugin "volumio_command_line_client"...
Feb 12 15:10:15 volumio volumio[25262]: info: Loading plugin "upnp"...
Feb 12 15:10:15 volumio volumio[25262]: info: [1770930615022] Starting Upmpd Daemon
Feb 12 15:10:15 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:10:15 volumio volumio[25262]: info: Loading plugin "my_music"...
Feb 12 15:10:15 volumio volumio[25262]: info: Loading plugin "mpd"...
Feb 12 15:10:15 volumio sudo[25310]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:15 volumio volumio-remote-updater[2265]: [2026-02-12 15:10:15] [connect] Successful connection
Feb 12 15:10:15 volumio volumio[25262]: info: Loading plugin "upnp_browser"...
Feb 12 15:10:16 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:10:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Feb 12 15:10:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:17 volumio go-librespot[25341]: go-librespot daemon starting...
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=debug msg="app state loaded"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-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]"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-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]"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-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]"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=info msg="zeroconf server listening on port 39573"
Feb 12 15:10:17 volumio go-librespot[25342]: time="2026-02-12T15:10:17-06:00" level=debug msg="obtained new client token: AAATQbUkK9aGuA9QIDR11Tlo+m7inyc5BElhnt7ivkIoLO4a4aVwaqUfue8LMDA+pGj0bkseJv06qAxP2oJLnQX9mOhrZXSPHDXScIT52VhCV5+mlSIsYOGWx/ctvBFstJZqk2CjE1dANb1x0SPLsWnFKTTZZvKAeNjZT5bq+56OTHIzleg7dO8iu/xPITcT5RQQfTz7rzA8ds+0VuWdoMtvmTCCAqMKiR8tlD1Ycf6OarcLLRTSBSVTmQ=="
Feb 12 15:10:18 volumio go-librespot[25342]: time="2026-02-12T15:10:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:18 volumio go-librespot[25342]: time="2026-02-12T15:10:18-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:18 volumio go-librespot[25342]: time="2026-02-12T15:10:18-06:00" level=debug msg="completed challenge"
Feb 12 15:10:18 volumio go-librespot[25342]: time="2026-02-12T15:10: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 "
Feb 12 15:10:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "alarm-clock"...
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "airplay_emulation"...
Feb 12 15:10:18 volumio volumio[25262]: info: Starting Shairport Sync
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "last_100"...
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "webradio"...
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "i2s_dacs"...
Feb 12 15:10:18 volumio volumio[25262]: info: I2S DAC not set, start Auto-detection
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "volumiodiscovery"...
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** For more information see 
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:10:18 volumio volumio[25262]: *** WARNING *** For more information see 
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** For more information see 
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 15:10:18 volumio node[25262]: *** WARNING *** For more information see 
Feb 12 15:10:18 volumio volumio[25262]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 15:10:18 volumio volumio[25262]: info: Discovery: Started advertising with name: Volumio
Feb 12 15:10:18 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 15:10:18 volumio volumio[25262]: info: Loading plugin "bandcamp"...
Feb 12 15:10:19 volumio volumio[25262]: info: Plugin calmradio is not enabled
Feb 12 15:10:19 volumio volumio[25262]: info: Loading plugin "soundcloud"...
Feb 12 15:10:20 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:10:20 volumio volumio[25262]: info: Loading plugin "spop"...
Feb 12 15:10:21 volumio volumio[25262]: info: Loading plugin "squeezelite_mc"...
Feb 12 15:10:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Feb 12 15:10:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:21 volumio go-librespot[25352]: go-librespot daemon starting...
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="app state loaded"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-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]"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-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]"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-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]"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=info msg="zeroconf server listening on port 37051"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="obtained new client token: AABbvdLJ8ixrAYE38+vDR/xMW07HFaXvHwe83Nk+yXBrRgoKwBvu2QmiMkOS4bibeWrCnCVb5Zahb4uhhLtlA1gy8uWw96f4aqCs7VWSJ2d57fK+365is4I08WR+Uf4gb4KVnc+JS3i/6hBFC+tu/Zc7SxiWWP7q1N7bYGCVlhdVTeSX2wDjUk8t5L3E/n3Tql6eR7thchEAnhtLUSHBFzAHuGa9oCm3wdXeVkLWaFFvdyaq/ArZr1OhnA=="
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-06:00" level=debug msg="completed challenge"
Feb 12 15:10:21 volumio go-librespot[25353]: time="2026-02-12T15:10:21-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 "
Feb 12 15:10:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:21 volumio volumio[25262]: info: Loading plugin "youtube2"...
Feb 12 15:10:22 volumio volumio[25262]: info: Loading plugin "ytcr"...
Feb 12 15:10:23 volumio volumio[25262]: info: Loading plugin "ytmusic"...
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin now_playing is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "outputs"...
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "albumart"...
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin example_plugin is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "inputs"...
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "updater_comm"...
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin mpdemulation is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "rest_api"...
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "websocket"...
Feb 12 15:10:24 volumio volumio[25262]: info: Starting Socket.io Server version 1.7.4
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin fusiondsp is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin mpdoutput is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Plugin RoonBridge is not enabled
Feb 12 15:10:24 volumio volumio[25262]: info: Loading plugin "podcast"...
Feb 12 15:10:24 volumio volumio[25262]: info: ControllerPodcast::constructor
Feb 12 15:10:25 volumio volumio[25262]: info: Loading plugin "volusonic"...
Feb 12 15:10:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Feb 12 15:10:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:25 volumio go-librespot[25387]: go-librespot daemon starting...
Feb 12 15:10:25 volumio volumio[25363]: Forking 3 albumart workers
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="app state loaded"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-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]"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-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]"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-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]"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=info msg="zeroconf server listening on port 39463"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="obtained new client token: AAC64ILcLxnHVZbViCC/NRh305KYZ6KjZ174ipknqZaRYfQDHgz0+UD3AePXFol0ILtj+I27aqMZL3HwdwnRh7rEs6qiXRMBABwB1RjETP5hJeuT6bLc5qxp/CYaEgbCMedhXeMedJnFFSArsTORan0L1pFHaQxbsPFf9c6JgzquyJIcBLCs/cDCgW0oLrt2OONIKyjDtKsDbHdwkK7GawfYcknxYz/0CYnGq0ITwwrn+F47hJFG96Olfw=="
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-06:00" level=debug msg="completed challenge"
Feb 12 15:10:25 volumio go-librespot[25388]: time="2026-02-12T15:10:25-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 "
Feb 12 15:10:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:26 volumio volumio[25262]: info: Applying required configuration parameters for plugin volusonic
Feb 12 15:10:26 volumio volumio[25262]: info: Loading plugin "backup_restore"...
Feb 12 15:10:26 volumio volumio[25394]: Starting albumart workers
Feb 12 15:10:26 volumio volumio[25395]: Starting albumart workers
Feb 12 15:10:26 volumio volumio[25396]: Starting albumart workers
Feb 12 15:10:27 volumio volumio[25262]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 15:10:27 volumio volumio[25262]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 15:10:27 volumio volumio[25262]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 15:10:27 volumio volumio[25262]: info: Loading plugin "scheduledrestart"...
Feb 12 15:10:27 volumio volumio[25262]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 15:10:27 volumio volumio[25262]: info: Plugin Bluetoothremote is not enabled
Feb 12 15:10:27 volumio volumio[25262]: info: Plugin music_services_shield is not enabled
Feb 12 15:10:27 volumio volumio[25262]: info: Loading plugin "Systeminfo"...
Feb 12 15:10:27 volumio volumio[25262]: info: Plugin peppymeterbasic is not enabled
Feb 12 15:10:27 volumio volumio[25262]: info: Loading plugin "peppyspectrum"...
Feb 12 15:10:27 volumio volumio-remote-updater[2265]: [2026-02-12 15:10:27] [connect] Successful connection
Feb 12 15:10:28 volumio volumio[25262]: info: Loading i18n strings for locale en
Feb 12 15:10:28 volumio volumio[25262]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 15:10:28 volumio volumio[25262]: Updating browse sources language
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::initPlayerControls
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: Express server listening on port 3000
Feb 12 15:10:28 volumio volumio[25262]:  [Metrics]  WebUI:  16s 207.41ms 
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::resetVolumioState
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::getcurrentVolume
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:28 volumio sudo[25448]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 15:10:28 volumio sudo[25448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio sudo[25448]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:28 volumio sudo[25450]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 15:10:28 volumio sudo[25450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio sudo[25450]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:28 volumio volumio[25262]: info: Volumio Network Manager: Network status updated: 1
Feb 12 15:10:28 volumio volumio[25262]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::pushState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioPushState
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::updateTrackBlock
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrackBlock
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:10:28 volumio volumio-remote-updater[2265]: [2026-02-12 15:10:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770930627 101
Feb 12 15:10:28 volumio volumio[25262]: 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
Feb 12 15:10:28 volumio volumio[25262]: info: Reloading queue from file
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::pushState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioPushState
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::setRandom null
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::pushState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioPushState
Feb 12 15:10:28 volumio volumio[25262]: info: Setting Device type: Raspberry PI
Feb 12 15:10:28 volumio volumio[25262]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:10:28 volumio volumio[25262]: info: CoreStateMachine::pushState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioPushState
Feb 12 15:10:28 volumio volumio[25262]: info: Completed loading Core Plugins
Feb 12 15:10:28 volumio volumio[25262]: info: Preparing to generate the ALSA configuration file
Feb 12 15:10:28 volumio sudo[25463]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 15:10:28 volumio sudo[25463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio volumio[25262]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 15:10:28 volumio volumio[25262]: info: Discovery: Found device Volumio
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 15:10:28 volumio volumio[25262]: info: Discovery: Found device Volumio
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:28 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:28 volumio volumio[25262]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 15:10:28 volumio volumio[25262]: info: Reading ALSA contributions from plugins.
Feb 12 15:10:28 volumio sudo[25463]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:28 volumio volumio[25262]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 15:10:28 volumio volumio[25262]: info: Output device has changed, restarting MPD
Feb 12 15:10:28 volumio volumio[25262]: info: Output device has changed, restarting Shairport Sync
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:28 volumio sudo[25466]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:10:28 volumio sudo[25466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio sudo[25466]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:28 volumio sudo[25468]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:10:28 volumio sudo[25468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio volumio[25262]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:10:28 volumio volumio[25262]: info: ___________ START PLUGINS ___________
Feb 12 15:10:28 volumio volumio[25262]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 15:10:28 volumio volumio[25262]: info: Creating MPD Configuration file
Feb 12 15:10:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Feb 12 15:10:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:28 volumio volumio[25262]: info: [1770930628798] CoreMusicLibrary::Adding element Media Servers
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:28 volumio go-librespot[25478]: go-librespot daemon starting...
Feb 12 15:10:28 volumio sudo[25476]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:10:28 volumio sudo[25479]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:10:28 volumio sudo[25479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio sudo[25476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:28 volumio sudo[25476]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 15:10:28 volumio go-librespot[25480]: time="2026-02-12T15:10:28-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:28 volumio go-librespot[25480]: time="2026-02-12T15:10:28-06:00" level=debug msg="app state loaded"
Feb 12 15:10:28 volumio go-librespot[25480]: time="2026-02-12T15:10:28-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:28 volumio go-librespot[25480]: time="2026-02-12T15:10:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:28 volumio volumio[25262]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:28 volumio volumio[25262]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:28 volumio volumio[25262]: info: [1770930628924] CoreMusicLibrary::Adding element Last_100
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:28 volumio volumio[25262]: info: [1770930628931] CoreMusicLibrary::Adding element Webradio
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:28 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:10:28 volumio volumio[25262]: info: Initializing BBC Radios
Feb 12 15:10:28 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 15:10:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 15:10:28 volumio systemd[1]: mpd.service: Consumed 5.761s CPU time.
Feb 12 15:10:28 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 15:10:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 15:10:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629022] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629034] CoreMusicLibrary::Adding element SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: info: Creating Spotify config file
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 15:10:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-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]"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-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]"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-06:00" level=info msg="zeroconf server listening on port 37423"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-06:00" level=debug msg="obtained new client token: AAAMcunyd6WHlbN11TACbcIcY1ehAjibB2kXUWkW6dDRCvLh8K3OYYHkFQVr3oqL3Ir85y7s9hT91YjH8vVzsGIu58iuEAYuxZvuBvtzObd4huVlP+Ff4s5MOJmRS0lPpkjoUWTXcGDeBEeLus89Cf2ivneJfLLVLakNCG1j7IXBddDDVYVD/EAkQYo/tJJCHVcMbEcP982aEaz4MA4tw0EMkmpkOhfmH3H6lT+wZ2//BRgG38tqH1E="
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:29 volumio sudo[25512]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 15:10:29 volumio sudo[25512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 15:10:29 volumio sudo[25512]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-06:00" level=debug msg="completed challenge"
Feb 12 15:10:29 volumio go-librespot[25480]: time="2026-02-12T15:10:29-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 "
Feb 12 15:10:29 volumio volumio[25262]: info: [squeezelite_mc] Starting proxy server...
Feb 12 15:10:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629428] CoreMusicLibrary::Adding element YouTube2
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629450] CoreMusicLibrary::Adding element YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629462] CoreMusicLibrary::Adding element Podcast
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Podcast
Feb 12 15:10:29 volumio volumio[25262]: info: Loading i18n strings for locale en
Feb 12 15:10:29 volumio volumio[25262]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 15:10:29 volumio volumio[25262]: Updating browse sources language
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Podcast
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Podcast
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:29 volumio volumio[25262]: info: [1770930629510] CoreMusicLibrary::Adding element Volusonic
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Podcast
Feb 12 15:10:29 volumio volumio[25262]: Cannot find translation for source Volusonic
Feb 12 15:10:29 volumio volumio[25262]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 15:10:29 volumio volumio[25262]: info: Volumio Calling Home
Feb 12 15:10:29 volumio volumio[25262]: info: [squeezelite_mc] Proxy server started on port 39325
Feb 12 15:10:29 volumio volumio[25262]: info: Preparing to generate the ALSA configuration file
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 15:10:29 volumio volumio[25262]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 15:10:29 volumio volumio[25262]: info: Reading ALSA contributions from plugins.
Feb 12 15:10:29 volumio volumio[25262]: info: MPD Permissions set
Feb 12 15:10:29 volumio volumio[25262]: info: MPD Permissions set
Feb 12 15:10:29 volumio volumio[25262]: info: Upmpdcli Daemon Started
Feb 12 15:10:29 volumio volumio[25262]: info: Spotify config file written
Feb 12 15:10:29 volumio sudo[25522]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 15:10:29 volumio volumio[25262]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 12 15:10:29 volumio sudo[25522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:29 volumio volumio[25262]: info: VolumeController:: Volume=100 Mute =false
Feb 12 15:10:29 volumio volumio[25262]: info: CoreStateMachine::pushState
Feb 12 15:10:29 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::volumioPushState
Feb 12 15:10:29 volumio volumio[25262]: info: [squeezelite_mc] Server discovery started
Feb 12 15:10:29 volumio volumio[25262]: info: [squeezelite_mc] Player finder started
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 15:10:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:29 volumio go-librespot[25526]: go-librespot daemon starting...
Feb 12 15:10:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:30 volumio sudo[25522]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:30 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:30 volumio volumio[25262]: info: No need to fix Spotify hosts
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="app state loaded"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:30 volumio volumio[25262]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 12 15:10:30 volumio volumio[25262]: info: Volumio called home
Feb 12 15:10:30 volumio volumio[25262]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 15:10:30 volumio volumio[25262]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 15:10:30 volumio volumio[25262]: 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
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-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]"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-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]"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-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]"
Feb 12 15:10:30 volumio volumio[25262]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 15:10:30 volumio volumio[25262]: SPOTIFY: BQBpXQbxMlD6GFvO9BUR7AJ7Vrd2NY85nTu_H41ZvZMzYYtFe5kq1E4Vgja7PmDUnMQFloQZAYL38fAyyTKOtuPfGCn2eBB25HdOQY-PSmougM2hCGTk9VgHi2LzTNtntHrzZBfeBA6FHCoEiN504Ct-L3qYOg4ODAODZj8_igEhwTmk3hCUoe_xa6tXS3uOVxLMYdIX4_nKbW4PlQncnN69ZBr9_0pp_3q8nlI
Feb 12 15:10:30 volumio volumio[25262]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 15:10:30 volumio volumio[25262]: info: New Spotify access token = BQBpXQbxMlD6GFvO9BUR7AJ7Vrd2NY85nTu_H41ZvZMzYYtFe5kq1E4Vgja7PmDUnMQFloQZAYL38fAyyTKOtuPfGCn2eBB25HdOQY-PSmougM2hCGTk9VgHi2LzTNtntHrzZBfeBA6FHCoEiN504Ct-L3qYOg4ODAODZj8_igEhwTmk3hCUoe_xa6tXS3uOVxLMYdIX4_nKbW4PlQncnN69ZBr9_0pp_3q8nlI
Feb 12 15:10:30 volumio volumio[25262]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=info msg="zeroconf server listening on port 38337"
Feb 12 15:10:30 volumio volumio[25262]: info: Starting Shairport Sync
Feb 12 15:10:30 volumio volumio[25262]: info: Starting Shairport Sync
Feb 12 15:10:30 volumio volumio[25262]: info: Starting Shairport Sync
Feb 12 15:10:30 volumio sudo[25547]:  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
Feb 12 15:10:30 volumio sudo[25547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio sudo[25550]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:10:30 volumio sudo[25547]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="obtained new client token: AACZnF6OtTAIeGkcc5CHWDvSrTKuDwYJgZNKeQEzWhsqBtq5V3iMVtTgEQP7pqzBDmJYHGLifyP3NClXK3M6QkdFN2gJdqZVQik1ZlnDkZRB2O2U9c3/z8bGc/xeMazb5ryqy0bEyqeQvaJgKuPsYnRp7+I9MVRXF6T0fl1+M7EB1RDEOCRySPzfhM3SRrt/ecMqRuDPpjlHpRDHL9Sf8mPCOL24SNtmZCye7OHjsCzBo0nSMrLyz/16bg=="
Feb 12 15:10:30 volumio sudo[25550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio sudo[25554]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:10:30 volumio sudo[25554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 15:10:30 volumio sudo[25552]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:10:30 volumio sudo[25552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 15:10:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:30 volumio systemd[1]: shairport-sync.service: Consumed 2.134s CPU time.
Feb 12 15:10:30 volumio volumio[25262]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 15:10:30 volumio volumio[25262]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 15:10:30 volumio volumio[25262]: info: Output device has changed, restarting MPD
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10:30-06:00" level=debug msg="completed challenge"
Feb 12 15:10:30 volumio volumio[25262]: info: Output device has changed, restarting Shairport Sync
Feb 12 15:10:30 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:30 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:30 volumio sudo[25550]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio sudo[25562]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 15:10:30 volumio sudo[25562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio sudo[25567]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 15:10:30 volumio sudo[25567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio go-librespot[25533]: time="2026-02-12T15:10: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 "
Feb 12 15:10:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:30 volumio sudo[25562]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio sudo[25564]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 15:10:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 15:10:30 volumio sudo[25564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 15:10:30 volumio sudo[25564]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio volumio[25262]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 15:10:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:30 volumio sudo[25554]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio sudo[25552]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:30 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 15:10:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 15:10:30 volumio systemd[1]: mpd.service: Consumed 1.493s CPU time.
Feb 12 15:10:30 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 15:10:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 15:10:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 15:10:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 15:10:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 15:10:30 volumio volumio[25262]: info: MPD Permissions set
Feb 12 15:10:30 volumio volumio[25262]: info: Shairport-Sync Started
Feb 12 15:10:30 volumio volumio[25262]: Error adding Membership: Error: addMembership EINVAL
Feb 12 15:10:30 volumio volumio[25262]: info: Shairport-Sync Started
Feb 12 15:10:30 volumio volumio[25262]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 15:10:30 volumio volumio[25262]: info: Shairport-Sync Started
Feb 12 15:10:31 volumio sudo[25609]:  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
Feb 12 15:10:31 volumio sudo[25609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:31 volumio sudo[25609]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:31 volumio sudo[25591]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 15:10:31 volumio sudo[25591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 15:10:31 volumio sudo[25591]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:31 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:31 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:31 volumio sudo[25619]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 15:10:31 volumio sudo[25619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:31 volumio volumio[25262]: info: Starting Shairport Sync
Feb 12 15:10:31 volumio systemd[1]: Reloading.
Feb 12 15:10:31 volumio sudo[25622]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 15:10:31 volumio sudo[25622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:31 volumio volumio[25262]: 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"}
Feb 12 15:10:31 volumio volumio[25262]: info: Spotify Successfully logged in
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 15:10:31 volumio volumio[25262]: info: [1770930631313] CoreMusicLibrary::Adding element Spotify
Feb 12 15:10:31 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source Bandcamp Discover
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source SoundCloud
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source YouTube2
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source YouTube Music
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source Podcast
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source Volusonic
Feb 12 15:10:31 volumio volumio[25262]: Cannot find translation for source Spotify
Feb 12 15:10:32 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:32 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:32 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 15:10:32 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 15:10:32 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:10:33 volumio volumio[25262]: info: go-librespot daemon successfully initialized
Feb 12 15:10:33 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.
Feb 12 15:10:33 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.
Feb 12 15:10:34 volumio sudo[25619]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:34 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Feb 12 15:10:34 volumio sudo[25643]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:34 volumio sudo[25643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:34 volumio go-librespot[25645]: go-librespot daemon starting...
Feb 12 15:10:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 15:10:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 15:10:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:34 volumio systemd[1]: shairport-sync.service: Consumed 1.379s CPU time.
Feb 12 15:10:34 volumio go-librespot[25646]: time="2026-02-12T15:10:34-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:34 volumio go-librespot[25646]: time="2026-02-12T15:10:34-06:00" level=debug msg="app state loaded"
Feb 12 15:10:34 volumio go-librespot[25646]: time="2026-02-12T15:10:34-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:34 volumio go-librespot[25646]: time="2026-02-12T15:10:34-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 15:10:34 volumio sudo[25622]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:34 volumio volumio[25262]: info: Shairport-Sync Started
Feb 12 15:10:34 volumio sudo[25643]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:34 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 15:10:35 volumio sudo[25669]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 15:10:35 volumio sudo[25669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:35 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 15:10:35 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 15:10:35 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-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]"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-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]"
Feb 12 15:10:35 volumio sudo[25669]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-06:00" level=info msg="zeroconf server listening on port 33253"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-06:00" level=debug msg="obtained new client token: AAAWTlmhQcwaZvfhdgGHJrALn2Ji5A+ZencneWwbJIVz5q++mg8iDLdqPb4kDhAkDYbbTb1HwZLUVkyF9SADrQ9eioWwkPCixOXGZ6gAgYJ89ZIWZuCBVJyDi90lvkCWAIQfw4yszngTHBGNRz3Y3rzIO02fxEgYzxXwdWf0yRCOw4HUAwRjQ8GDhoTxtiltjJX/KH2somHt8y9tT/2zLbFhGU/Sb72jjZJ5noHb42KP2p/VJ4wO+d1WZg=="
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10:35-06:00" level=debug msg="completed challenge"
Feb 12 15:10:35 volumio go-librespot[25646]: time="2026-02-12T15:10: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 "
Feb 12 15:10:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:35 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:35 volumio sudo[25687]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:35 volumio sudo[25687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:35 volumio sudo[25687]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:35 volumio volumio[25262]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 15:10:35 volumio sudo[25691]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 15:10:35 volumio sudo[25691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:35 volumio sudo[25691]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:35 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 15:10:36 volumio sudo[25694]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 15:10:36 volumio sudo[25694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:36 volumio mpd[25618]: 2026-02-12T15:10:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 15:10:36 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 15:10:36 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 15:10:36 volumio sudo[25694]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:36 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 15:10:36 volumio sudo[25567]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:36 volumio sudo[25479]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:36 volumio volumio[25262]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:36 volumio sudo[25468]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:36 volumio volumio[25262]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 15:10:36 volumio volumio[25262]:   assert.ok(self.idling)
Feb 12 15:10:36 volumio volumio[25262]: error: The expression evaluated to a falsy value:
Feb 12 15:10:36 volumio volumio[25262]:   assert.ok(self.idling)
Feb 12 15:10:36 volumio volumio[25262]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 15:10:36 volumio volumio[25262]:   assert.ok(self.idling)
Feb 12 15:10:36 volumio volumio[25262]: error: The expression evaluated to a falsy value:
Feb 12 15:10:36 volumio volumio[25262]:   assert.ok(self.idling)
Feb 12 15:10:36 volumio volumio[25262]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:10:36 volumio volumio[25262]: error: updateQueue error: null
Feb 12 15:10:36 volumio volumio[25262]: info: MPD running with PID25618
Feb 12 15:10:36 volumio volumio[25262]:  ,establishing connection
Feb 12 15:10:36 volumio volumio[25262]: error: updateQueue error: null
Feb 12 15:10:36 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:36 volumio sudo[25705]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:36 volumio sudo[25705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:36 volumio sudo[25705]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:37 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:37 volumio sudo[25708]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:37 volumio sudo[25708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:37 volumio sudo[25708]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:37 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:37 volumio sudo[25711]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:37 volumio sudo[25711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:37 volumio sudo[25711]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:38 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:38 volumio sudo[25714]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:38 volumio sudo[25714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:38 volumio sudo[25714]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Feb 12 15:10:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:38 volumio go-librespot[25716]: go-librespot daemon starting...
Feb 12 15:10:38 volumio go-librespot[25717]: time="2026-02-12T15:10:38-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:38 volumio go-librespot[25717]: time="2026-02-12T15:10:38-06:00" level=debug msg="app state loaded"
Feb 12 15:10:38 volumio go-librespot[25717]: time="2026-02-12T15:10:38-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:38 volumio go-librespot[25717]: time="2026-02-12T15:10:38-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:39 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:10:39 volumio volumio[25262]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 15:10:39 volumio sudo[25726]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 15:10:39 volumio sudo[25726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-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]"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-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]"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-06:00" level=info msg="zeroconf server listening on port 44899"
Feb 12 15:10:39 volumio sudo[25726]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:39 volumio volumio[25262]: info: Completed starting Core Plugins
Feb 12 15:10:39 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:39 volumio volumio[25262]: info: -----    MyVolumio plugins startup     ----
Feb 12 15:10:39 volumio volumio[25262]: info: -------------------------------------------
Feb 12 15:10:39 volumio volumio[25262]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-06:00" level=debug msg="obtained new client token: AABc3W6KcK/ezBl+JCMSZqnk/o47ysrPSsSclB+CURfjK7dyHr4e9p8TXqDT0pmaI6IGZlz12Ami99luKLcoeWJD2S4gMYXGrvXHh5qw8H5AQqwuhiRMdUv15lGpZujR2iA3l6C/7polo05r6n5R8vdZOSIChjxEPUDcIOXFBSwvQKqOPKNRMbmdyiMgECDaDGgES1sKXOqzUIXfL0MHtXhyyr77QiAVCieqSgrYT4zYXPWiEhP3aYI="
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10:39-06:00" level=debug msg="completed challenge"
Feb 12 15:10:39 volumio go-librespot[25717]: time="2026-02-12T15:10: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 "
Feb 12 15:10:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:39 volumio sudo[25729]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:10:39 volumio sudo[25729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:39 volumio sudo[25731]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:10:39 volumio sudo[25731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:39 volumio sudo[25733]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 15:10:39 volumio sudo[25733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:39 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 15:10:39 volumio volumio[25262]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:39 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 15:10:39 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 15:10:39 volumio volumio[25262]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 15:10:39 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 15:10:39 volumio sudo[25731]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:39 volumio sudo[25733]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:39 volumio mpd_monitor.sh[25737]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 15:10:39 volumio sudo[25729]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:39 volumio volumio[25262]: info: Successfully started MPD Monitor
Feb 12 15:10:39 volumio volumio[25262]: info: Successfully started MPD Monitor
Feb 12 15:10:39 volumio volumio[25262]: info: Successfully started MPD Monitor
Feb 12 15:10:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54.
Feb 12 15:10:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:42 volumio volumio[25262]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:42 volumio go-librespot[25741]: go-librespot daemon starting...
Feb 12 15:10:42 volumio go-librespot[25742]: time="2026-02-12T15:10:42-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:42 volumio go-librespot[25742]: time="2026-02-12T15:10:42-06:00" level=debug msg="app state loaded"
Feb 12 15:10:42 volumio go-librespot[25742]: time="2026-02-12T15:10:42-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:42 volumio go-librespot[25742]: time="2026-02-12T15:10:42-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=debug msg="new websocket client"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-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]"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-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]"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-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]"
Feb 12 15:10:43 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=info msg="zeroconf server listening on port 35603"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=debug msg="obtained new client token: AACPh2UJJT0YKN6hrqMyMZk22Ovk2Z52hwy6oYr0ZMflugIs4n9R+nD541jg1TDHcy0Q8rBdiefGOWym3iEAz7qYeWRBDBGEfIHcfxsbxE/0bzpvNr6uLCXSsDxMi+3Z9++IB5/JVkafBmy8SUEdFjd2AX0aWmtHzFvbIQHZioTA2MGEYrMTZunGwtxalnXYM9SW9nirOImQQH6GcEYyyNwTEJos1gOjgfXOqgvUYJt/CdKSK9Dq8WwyHg=="
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-06:00" level=debug msg="completed challenge"
Feb 12 15:10:43 volumio go-librespot[25742]: time="2026-02-12T15:10:43-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 "
Feb 12 15:10:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:43 volumio volumio[25262]: info: Connection to go-librespot Websocket established
Feb 12 15:10:45 volumio volumio[25262]: info: Connection to go-librespot Websocket closed
Feb 12 15:10:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55.
Feb 12 15:10:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 15:10:46 volumio go-librespot[25765]: go-librespot daemon starting...
Feb 12 15:10:46 volumio go-librespot[25766]: time="2026-02-12T15:10:46-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 15:10:46 volumio go-librespot[25766]: time="2026-02-12T15:10:46-06:00" level=debug msg="app state loaded"
Feb 12 15:10:46 volumio go-librespot[25766]: time="2026-02-12T15:10:46-06:00" level=debug msg="stored credentials not found"
Feb 12 15:10:46 volumio go-librespot[25766]: time="2026-02-12T15:10:46-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 15:10:46 volumio volumio[25262]: info: Getting Spotify volume
Feb 12 15:10:46 volumio volumio[25262]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Feb 12 15:10:47 volumio volumio[25262]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:47 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:47 volumio volumio[25262]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 12 15:10:47 volumio volumio[25262]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 12 15:10:47 volumio volumio[25262]: SPOTIFY: VOLUMIO VOLUME 100
Feb 12 15:10:47 volumio volumio[25262]: info: Aligning Spotify Volume to Volumio Volume
Feb 12 15:10:47 volumio volumio[25262]: info: CoreCommandRouter::volumioGetState
Feb 12 15:10:47 volumio volumio[25262]: info: CorePlayQueue::getTrack 0
Feb 12 15:10:47 volumio volumio[25262]: info: Setting Spotify Volume from Volumio: 100
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-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]"
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-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]"
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-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]"
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-06:00" level=info msg="zeroconf server listening on port 42517"
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-06:00" level=debug msg="obtained new client token: AAAa0XhaOZdAj/XUW/ZkcCZvQAOYxt0Ae9eSFmR3sDBH8rDSUACsN7asRitKvqhFH3eZGRk43f4nUoY/Nk3ILvfEmE25By7VurhFhfF6VnJGT8dP5xpSamh2O43e76E2uCKfCBMLVbAn9yZVjpTDD3FVsqCWxLI0/43z483+zdADluUK3C3AvTdcEMh0q8jSfa0F8uG6tcnH8dt8bm1MZgkXwZaTXs09vS/Mm9jrYczJ6mKzTG2NX4Q="
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-06:00" level=debug msg="completed keyexchange"
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-06:00" level=debug msg="completed challenge"
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 15:10:47 volumio volumio[25262]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 15:10:47 volumio go-librespot[25766]: time="2026-02-12T15:10:47-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 "
Feb 12 15:10:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 15:10:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 15:10:48 volumio volumio[25262]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 15:10:48 volumio volumio[25262]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 15:10:48 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:48 volumio volumio[25262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 15:10:48 volumio volumio[25262]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 15:10:48 volumio volumio[25262]: info: MyVolumio login type: Token
Feb 12 15:10:48 volumio volumio[25262]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 15:10:48 volumio volumio[25262]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 15:10:49 volumio volumio[25262]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 15:10:49 volumio volumio[25262]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 15:10:49 volumio volumio[25262]: info: Streaming services startup
Feb 12 15:10:49 volumio volumio[25262]: info: Starting Streaming Daemon
Feb 12 15:10:49 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 15:10:49 volumio volumio[25262]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 15:10:49 volumio sudo[25777]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 15:10:49 volumio sudo[25777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 15:10:49 volumio sudo[25777]: pam_unix(sudo:session): session closed for user root
Feb 12 15:10:49 volumio volumio[25262]: SPOTIFY: SETTING SPOTIFY VOLUME 100
Feb 12 15:10:49 volumio volumio[25262]: info: Sending Spotify command with payload to local API: /player/volume
Feb 12 15:10:49 volumio volumio[25262]: info: Initializing connection to go-librespot Websocket
Feb 12 15:10:49 volumio volumio[25262]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:10:49 volumio volumio[25262]: Error: socket hang up
Feb 12 15:10:49 volumio volumio[25262]:     at connResetException (node:internal/errors:720:14)
Feb 12 15:10:49 volumio volumio[25262]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 12 15:10:49 volumio volumio[25262]:     at Socket.emit (node:events:526:35)
Feb 12 15:10:49 volumio volumio[25262]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 12 15:10:49 volumio volumio[25262]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 12 15:10:49 volumio volumio[25262]:   code: 'ECONNRESET',
Feb 12 15:10:49 volumio volumio[25262]:   response: undefined
Feb 12 15:10:49 volumio volumio[25262]: }
Feb 12 15:10:49 volumio volumio[25262]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 15:10:50 volumio sudo[25796]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 15:09'
Feb 12 15:10:50 volumio sudo[25796]: 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"