Feb 12 04:43:00 volumio volumio[17713]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 04:43:00 volumio volumio[17713]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 04:43:00 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:43:00 volumio volumio[17713]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 04:43:00 volumio volumio[17713]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 04:43:00 volumio volumio[17713]: info: Streaming services startup
Feb 12 04:43:00 volumio volumio[17713]: info: Starting Streaming Daemon
Feb 12 04:43:00 volumio sudo[18215]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 04:43:00 volumio sudo[18215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:00 volumio volumio[17713]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 04:43:00 volumio sudo[18215]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:00 volumio volumio[17713]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:00 volumio volumio[17713]: error: Cannot start Volumio Streaming Daemon
Feb 12 04:43:00 volumio volumio[17713]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 04:43:00 volumio volumio[17713]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 04:43:00 volumio volumio[17713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:01 volumio volumio[17713]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 12 04:43:01 volumio volumio[17713]: info: MyVolumio token set successfully
Feb 12 04:43:01 volumio volumio[17713]: info: MYVOLUMIO: Adding device
Feb 12 04:43:01 volumio volumio[17713]: info: MYVOLUMIO: Evaluating Server
Feb 12 04:43:01 volumio volumio[17713]: info: MyVolumio status changed
Feb 12 04:43:01 volumio volumio[17713]: info: Streaming services startup
Feb 12 04:43:01 volumio volumio[17713]: info: Starting Streaming Daemon
Feb 12 04:43:01 volumio volumio[17713]: info: Removing browser output: myVolumio user plan is not superstar
Feb 12 04:43:01 volumio volumio[17713]: info: Removing audio output:
Feb 12 04:43:01 volumio volumio[17713]: info: Stoppping Tunnel 1
Feb 12 04:43:01 volumio sudo[18242]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 04:43:01 volumio sudo[18242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:01 volumio sudo[18244]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 12 04:43:01 volumio sudo[18244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:01 volumio sudo[18242]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:01 volumio volumio[17713]: error: Cannot start Volumio Streaming Daemon
Feb 12 04:43:01 volumio volumio[17713]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 04:43:01 volumio volumio[17713]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 04:43:01 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 04:43:01 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 04:43:01 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 04:43:01 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 04:43:02 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 04:43:02 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 04:43:02 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 04:43:02 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 04:43:02 volumio sudo[18244]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:02 volumio volumio[17713]: info: Remote SSH Stopped
Feb 12 04:43:02 volumio volumio[17713]: info: Setting Geolocation for MyVolumio to us1
Feb 12 04:43:02 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:02 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:02 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115.
Feb 12 04:43:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:02 volumio volumio[17713]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 04:43:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:02 volumio go-librespot[18247]: go-librespot daemon starting...
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="app state loaded"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43: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-gew4.spotify.com:80]"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-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 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-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 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=info msg="zeroconf server listening on port 35855"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="obtained new client token: AACfx0Wj4mtBrm83t5RG789htnvjhxrZBKzzTdToi6jwE0oNalQGwYVfX1QGbvq1t+SO1uqcQJ+gGtF0M1NWeIE10acsdTEfDg0gWA4QHr3I/GjIrOaEiQKcPxGrwKLnYKwf2QNy3tpb5PUak4qOYm/KW/h4bSqKzo/gIoGi9e2oP3oAKrgSvwi4XtN28jYHOD5rdgE8v7X5BfPr86RLZHsL0NEIh744tYKpDuhqWT/flJlHj81QD68MGQ=="
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43:02-06:00" level=debug msg="completed challenge"
Feb 12 04:43:02 volumio go-librespot[18248]: time="2026-02-12T04:43: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 04:43:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:03 volumio volumio[17713]: info: Updating MyVolumio device info
Feb 12 04:43:03 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:03 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:03 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:03 volumio volumio[17713]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 04:43:03 volumio volumio[17713]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:04 volumio volumio[17713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116.
Feb 12 04:43:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:06 volumio go-librespot[18255]: go-librespot daemon starting...
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="app state loaded"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:06 volumio volumio[17713]: info: MYVOLUMIO: Adding device
Feb 12 04:43:06 volumio volumio[17713]: info: MYVOLUMIO: Evaluating Server
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-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 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-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 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=info msg="zeroconf server listening on port 33353"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="obtained new client token: AADQYqMTIL+LkeNCCN+3zQM3hbKNO8XgP5LwoP0Wmc43oIDA2iIsUowpD/85D87x9EjVuiulJKUlupjVMGkuDlnQ2FU+axAxYRvBQsZR1cNVvbTs0JvUyemJdowHeW3Rn3e5XF9AaHFQ13LevjoJVlntWAfIYUb+oYLBFNb1T4zw2yo8ZBIy+YhacZaOsW+wDXi4VnYKjIITkcI/8/ZBmq8ZrCvlar642bVdnKVUatU86IPOopcLq2zU4A=="
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43:06-06:00" level=debug msg="completed challenge"
Feb 12 04:43:06 volumio go-librespot[18256]: time="2026-02-12T04:43: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 04:43:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:06 volumio volumio[17713]: info: Setting Geolocation for MyVolumio to us1
Feb 12 04:43:06 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:06 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:06 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:06 volumio volumio[17713]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 04:43:07 volumio volumio[17713]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:07 volumio volumio[17713]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:07 volumio volumio[17713]: info: Updating MyVolumio device info
Feb 12 04:43:07 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:07 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:07 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:07 volumio volumio[17713]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 04:43:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117.
Feb 12 04:43:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:09 volumio go-librespot[18297]: go-librespot daemon starting...
Feb 12 04:43:09 volumio go-librespot[18298]: time="2026-02-12T04:43:09-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:09 volumio go-librespot[18298]: time="2026-02-12T04:43:09-06:00" level=debug msg="app state loaded"
Feb 12 04:43:09 volumio go-librespot[18298]: time="2026-02-12T04:43:09-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:09 volumio go-librespot[18298]: time="2026-02-12T04:43:09-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:10 volumio volumio[17713]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=debug msg="new websocket client"
Feb 12 04:43:10 volumio volumio[17713]: info: Connection to go-librespot Websocket established
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43: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-gew4.spotify.com:80]"
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-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 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-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 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=info msg="zeroconf server listening on port 46367"
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=debug msg="obtained new client token: AAA2oI44uL3ntzfU4Nxn+JSjiNcIhgmz+6dSCe2rbKezOTrFET/Z9U5glxqudZCxBMzXuiorR0Lzromzj+4+sJoF1I/plyBNxB2W1rNBHrQbCMakMrr0xQ7kPqJ1M2O1bRjJfm0BIH6oDZsZYeVES6ZqmGMxT6aH2aHI+cJMB6U1GWVk20RZ0Uvb5bxx4f0eqPgpdFK/MHjMzpmSOMxb6hLrTxGJ04OpJROnBlTZ/j093m5xUg0L6lM="
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43:10-06:00" level=debug msg="completed challenge"
Feb 12 04:43:10 volumio go-librespot[18298]: time="2026-02-12T04:43: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 04:43:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:10 volumio volumio[17713]: info: Connection to go-librespot Websocket closed
Feb 12 04:43:12 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:43:12 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:12 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 12 04:43:12 volumio volumio-remote-updater[2265]: Test mode disabled
Feb 12 04:43:12 volumio volumio-remote-updater[2265]: Alpha mode disabled
Feb 12 04:43:12 volumio volumio-remote-updater[2265]: Alpha legacy test mode disabled
Feb 12 04:43:12 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 12 04:43:12 volumio volumio[17713]: 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 04:43:12 volumio volumio[17713]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 12 04:43:13 volumio volumio[17713]: info: Getting Spotify volume
Feb 12 04:43:13 volumio volumio[17713]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:43:13 volumio volumio[17713]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:13 volumio volumio[17713]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 04:43:13 volumio volumio[17713]:   errno: -111,
Feb 12 04:43:13 volumio volumio[17713]:   code: 'ECONNREFUSED',
Feb 12 04:43:13 volumio volumio[17713]:   syscall: 'connect',
Feb 12 04:43:13 volumio volumio[17713]:   address: '127.0.0.1',
Feb 12 04:43:13 volumio volumio[17713]:   port: 9879,
Feb 12 04:43:13 volumio volumio[17713]:   response: undefined
Feb 12 04:43:13 volumio volumio[17713]: }
Feb 12 04:43:13 volumio volumio[17713]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:43:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118.
Feb 12 04:43:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:13 volumio go-librespot[18324]: go-librespot daemon starting...
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=debug msg="app state loaded"
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:13 volumio sudo[18334]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 04:42'
Feb 12 04:43:13 volumio sudo[18334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43: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 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43: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 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43: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 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=info msg="zeroconf server listening on port 34507"
Feb 12 04:43:13 volumio go-librespot[18325]: time="2026-02-12T04:43:13-06:00" level=debug msg="obtained new client token: AAA24aGpDQX2ZOBeCrslPDb+nEbqSI1ZyZquvJIWRykKpHcvglFHM0i3C3ndMq75aMyRJ8pWvUpj+na2snI6RL9kiwXVenwRSF/iRIq3bcLOZpmgcmtjndRDXRl05BVXfRfOUBlNujhtQrCXErBEwU3YVZwfA+7gGEz4PvZVDJ43gQ0Qxt/MSmcbrOWKoq2+jPhEauCaTStaErByscqM7x2U/z9ycKZz2UwSjojUJZ9Jy86q2/hI+dQiIA=="
Feb 12 04:43:14 volumio sudo[18334]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:14 volumio go-librespot[18325]: time="2026-02-12T04:43:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:14 volumio go-librespot[18325]: time="2026-02-12T04:43:14-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:14 volumio go-librespot[18325]: time="2026-02-12T04:43:14-06:00" level=debug msg="completed challenge"
Feb 12 04:43:14 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 04:43:14 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 04:43:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:14 volumio go-librespot[18325]: time="2026-02-12T04:43: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 04:43:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 04:43:14 volumio systemd[1]: volumio.service: Consumed 52.222s CPU time.
Feb 12 04:43:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 04:43:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 04:43:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6200.
Feb 12 04:43:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 04:43:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 04:43:14 volumio systemd[1]: volumio.service: Consumed 52.222s CPU time.
Feb 12 04:43:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 04:43:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 04:43:16 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:16 volumio volumio[18348]: info: -----            Volumio3              ----
Feb 12 04:43:16 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:16 volumio volumio[18348]: info: -----          System startup          ----
Feb 12 04:43:16 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119.
Feb 12 04:43:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:17 volumio volumio[18348]: info: MYVOLUMIO Environment detected
Feb 12 04:43:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:17 volumio go-librespot[18370]: go-librespot daemon starting...
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="app state loaded"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:17 volumio volumio[18348]: info: Plugin folders cleanup
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning into folder /volumio/app/plugins/
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category audio_interface
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category miscellanea
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category music_service
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category plugins.json
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category system_controller
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category user_interface
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning into folder /data/plugins/
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category audio_interface
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category music_service
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category system_controller
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category system_hardware
Feb 12 04:43:17 volumio volumio[18348]: info: Scanning category user_interface
Feb 12 04:43:17 volumio volumio[18348]: info: Plugin folders cleanup completed
Feb 12 04:43:17 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:17 volumio volumio[18348]: info: -----      Core plugins startup        ----
Feb 12 04:43:17 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:17 volumio volumio[18348]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 04:43:17 volumio volumio[18348]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 04:43:17 volumio volumio[18348]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 04:43:17 volumio volumio[18348]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 04:43:17 volumio volumio[18348]: info: Loading plugins from folder /data/plugins/
Feb 12 04:43:17 volumio volumio[18348]: info: Loading plugin "system"...
Feb 12 04:43:17 volumio volumio[18348]: info: Loading plugin "appearance"...
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-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 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-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 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=info msg="zeroconf server listening on port 38453"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="obtained new client token: AAASqix9697D6iSzk7ObZvBPKWR4+j//OwjyrwbuXlidwDN2i0P1rJ+Qs+vhX9qkUBX5bnTiCpMkPkgOnmotwdwHcOyLfinpjsgX5eA6a8yteAQlPvheWiQCqWyis6FdHbsdh3ro8xipse8pv4kxznzljReWlo9O3k+IJhUu0o/LkBQYrYewfo+roK6cdlOOYAwz3rG4bbwvltiEAVVYUcJqQzG5wTfUu26iL/IK/2AWFcrujCt0wcqlPw=="
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43:17-06:00" level=debug msg="completed challenge"
Feb 12 04:43:17 volumio go-librespot[18374]: time="2026-02-12T04:43: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 04:43:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:18 volumio volumio[18348]: info: Loading plugin "network"...
Feb 12 04:43:18 volumio volumio[18348]: info: Refreshing Cached IP Addresses
Feb 12 04:43:18 volumio sudo[18385]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 04:43:18 volumio sudo[18385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:18 volumio sudo[18387]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 04:43:18 volumio sudo[18387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:18 volumio volumio[18348]: info: Loading plugin "services"...
Feb 12 04:43:18 volumio sudo[18385]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:18 volumio sudo[18387]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:18 volumio volumio[18348]: info: Loading plugin "alsa_controller"...
Feb 12 04:43:18 volumio sudo[18398]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 04:43:18 volumio sudo[18398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:18 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:43:18 volumio volumio[18348]: info: Loading plugin "wizard"...
Feb 12 04:43:18 volumio volumio[18348]: info: Loading plugin "networkfs"...
Feb 12 04:43:18 volumio volumio[18348]: info: Starting Udev Watcher for removable devices
Feb 12 04:43:18 volumio volumio[18348]: info: Ignoring mount for partition: boot
Feb 12 04:43:18 volumio volumio[18348]: info: Ignoring mount for partition: volumio
Feb 12 04:43:18 volumio volumio[18348]: info: Ignoring mount for partition: volumio_data
Feb 12 04:43:18 volumio volumio[18348]: info: Mounting Device Wikipedia
Feb 12 04:43:19 volumio sudo[18424]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 04:43:19 volumio sudo[18424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:19 volumio sudo[18424]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:19 volumio volumio[18348]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 04:43:19 volumio volumio[18348]:        dmesg(1) may have more information after failed mount system call.
Feb 12 04:43:19 volumio volumio[18348]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 04:43:19 volumio volumio[18348]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 04:43:19 volumio volumio[18348]:        dmesg(1) may have more information after failed mount system call.
Feb 12 04:43:19 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:43:19 volumio volumio[18348]: info: Loading plugin "volumio_command_line_client"...
Feb 12 04:43:19 volumio volumio[18348]: info: Loading plugin "upnp"...
Feb 12 04:43:19 volumio volumio[18348]: info: [1770892999068] Starting Upmpd Daemon
Feb 12 04:43:19 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:43:19 volumio volumio[18348]: info: Loading plugin "my_music"...
Feb 12 04:43:19 volumio volumio[18348]: info: Loading plugin "mpd"...
Feb 12 04:43:19 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:43:19 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:19] [connect] Successful connection
Feb 12 04:43:19 volumio sudo[18398]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:19 volumio volumio[18348]: info: Loading plugin "upnp_browser"...
Feb 12 04:43:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120.
Feb 12 04:43:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:21 volumio go-librespot[18427]: go-librespot daemon starting...
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="app state loaded"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43: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-gew1.spotify.com:80]"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-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 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-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 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=info msg="zeroconf server listening on port 38943"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="obtained new client token: AAACs+5HwgHxCLTwvfO383Rs9f1C1hTw7+XAww1RUn7IH5JqjYYnS/ZQVz7aMZfUvy0Fcg2fHg0sKBPspArWskHVrN7YDHnmf71p5PCMz+I65cizzjuQNYo2tenygMqjVL92MTznTZ9c05KJiJqeX+t6OSBNc8oZEHJzMZ081I6Z6NcNfY7DbdM+LoOK6lr5uxd1FQAwJHGZhgC/vevXAHga5iG/ClmKZu/ueC9dakBoTNFU5cifI9Z1RA=="
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43:21-06:00" level=debug msg="completed challenge"
Feb 12 04:43:21 volumio go-librespot[18428]: time="2026-02-12T04:43: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 04:43:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "alarm-clock"...
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "airplay_emulation"...
Feb 12 04:43:22 volumio volumio[18348]: info: Starting Shairport Sync
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "last_100"...
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "webradio"...
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "i2s_dacs"...
Feb 12 04:43:22 volumio volumio[18348]: info: I2S DAC not set, start Auto-detection
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "volumiodiscovery"...
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** For more information see 
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:43:22 volumio volumio[18348]: *** WARNING *** For more information see 
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** For more information see 
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:43:22 volumio node[18348]: *** WARNING *** For more information see 
Feb 12 04:43:22 volumio volumio[18348]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 04:43:22 volumio volumio[18348]: info: Discovery: Started advertising with name: Volumio
Feb 12 04:43:22 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:43:22 volumio volumio[18348]: info: Loading plugin "bandcamp"...
Feb 12 04:43:23 volumio volumio[18348]: info: Plugin calmradio is not enabled
Feb 12 04:43:23 volumio volumio[18348]: info: Loading plugin "soundcloud"...
Feb 12 04:43:24 volumio volumio[18348]: info: Loading plugin "spop"...
Feb 12 04:43:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121.
Feb 12 04:43:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:25 volumio go-librespot[18437]: go-librespot daemon starting...
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="app state loaded"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:25 volumio volumio[18348]: info: Loading plugin "squeezelite_mc"...
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-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 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-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 04:43:25 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=info msg="zeroconf server listening on port 37267"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="obtained new client token: AADXOETVDFQxslFxfFnFl1v/2tm7ZgTcwwW2XuMYWSbXmdih2uPSF8luNfo53j00tCcl/gOxWvfXftEdgCvt8kRM0VMX0CkQzyykcY4234axbIM6w7UYAOWk6fmalmZqcU2Whk28+Q30tV30pG5PYFRPlTP/DNFZ+3rvK27aVNnQu/Q5v8QaSPkOB+c9cFFt+tAUf+bxuZYqFGCjqTDmDbHwLTK3NdSxtrb7B4Sh3M/ieKBfqrSa8d9IUg=="
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43:25-06:00" level=debug msg="completed challenge"
Feb 12 04:43:25 volumio go-librespot[18438]: time="2026-02-12T04:43: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 04:43:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:26 volumio volumio[18348]: info: Loading plugin "youtube2"...
Feb 12 04:43:26 volumio volumio[18348]: info: Loading plugin "ytcr"...
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "ytmusic"...
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin now_playing is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "outputs"...
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "albumart"...
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin example_plugin is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "inputs"...
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "updater_comm"...
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin mpdemulation is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "rest_api"...
Feb 12 04:43:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122.
Feb 12 04:43:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "websocket"...
Feb 12 04:43:28 volumio volumio[18348]: info: Starting Socket.io Server version 1.7.4
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin fusiondsp is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin mpdoutput is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Plugin RoonBridge is not enabled
Feb 12 04:43:28 volumio volumio[18348]: info: Loading plugin "podcast"...
Feb 12 04:43:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:28 volumio go-librespot[18471]: go-librespot daemon starting...
Feb 12 04:43:28 volumio go-librespot[18472]: time="2026-02-12T04:43:28-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:28 volumio go-librespot[18472]: time="2026-02-12T04:43:28-06:00" level=debug msg="app state loaded"
Feb 12 04:43:28 volumio go-librespot[18472]: time="2026-02-12T04:43:28-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:28 volumio go-librespot[18472]: time="2026-02-12T04:43:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:29 volumio volumio[18348]: info: ControllerPodcast::constructor
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-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 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-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 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=info msg="zeroconf server listening on port 42583"
Feb 12 04:43:29 volumio volumio[18348]: info: Loading plugin "volusonic"...
Feb 12 04:43:29 volumio volumio[18447]: Forking 3 albumart workers
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=debug msg="obtained new client token: AAAZTZtIrb3mgsQNGLUnE7eo3G2eod7JZR2Rn36iIgvq/oakBSyHX/KuSUGRhAEFT65tkAI5ZdmtRjuAZ3JiFB34c8wQaUD4UCx/MZgRzlJcgYhT+VEYCDbR7GbL4Pxg6kLrFrhrixlISjcVFNwGW20DMrbRu0gi5eFjNjxREtDXSUGZ5gMZA9ini4UaJjFPZdOi/9Hi8g+zNdqxrSOWb0LxDEEN2UaFYojpniJNyo8TQ63XbJpIjKU="
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43:29-06:00" level=debug msg="completed challenge"
Feb 12 04:43:29 volumio go-librespot[18472]: time="2026-02-12T04:43: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 04:43:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:30 volumio volumio[18479]: Starting albumart workers
Feb 12 04:43:30 volumio volumio[18348]: info: Applying required configuration parameters for plugin volusonic
Feb 12 04:43:30 volumio volumio[18348]: info: Loading plugin "backup_restore"...
Feb 12 04:43:30 volumio volumio[18480]: Starting albumart workers
Feb 12 04:43:30 volumio volumio[18481]: Starting albumart workers
Feb 12 04:43:31 volumio volumio[18348]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 04:43:31 volumio volumio[18348]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 04:43:31 volumio volumio[18348]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 04:43:31 volumio volumio[18348]: info: Loading plugin "scheduledrestart"...
Feb 12 04:43:31 volumio volumio[18348]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 04:43:31 volumio volumio[18348]: info: Plugin Bluetoothremote is not enabled
Feb 12 04:43:31 volumio volumio[18348]: info: Plugin music_services_shield is not enabled
Feb 12 04:43:31 volumio volumio[18348]: info: Loading plugin "Systeminfo"...
Feb 12 04:43:31 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:31] [connect] Successful connection
Feb 12 04:43:31 volumio volumio[18348]: info: Plugin peppymeterbasic is not enabled
Feb 12 04:43:31 volumio volumio[18348]: info: Loading plugin "peppyspectrum"...
Feb 12 04:43:32 volumio volumio[18348]: info: Loading i18n strings for locale en
Feb 12 04:43:32 volumio volumio[18348]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 04:43:32 volumio volumio[18348]: Updating browse sources language
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::initPlayerControls
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: Express server listening on port 3000
Feb 12 04:43:32 volumio volumio[18348]:  [Metrics]  WebUI:  16s 295.00ms 
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::resetVolumioState
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::getcurrentVolume
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:32 volumio sudo[18535]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 04:43:32 volumio sudo[18535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio sudo[18535]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:32 volumio sudo[18537]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 04:43:32 volumio sudo[18537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio sudo[18537]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:32 volumio volumio[18348]: info: Volumio Network Manager: Network status updated: 1
Feb 12 04:43:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123.
Feb 12 04:43:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:32 volumio volumio[18348]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::pushState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioPushState
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::updateTrackBlock
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrackBlock
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:43:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:32 volumio go-librespot[18542]: go-librespot daemon starting...
Feb 12 04:43:32 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770893011 101
Feb 12 04:43:32 volumio volumio[18348]: 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 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-06:00" level=debug msg="app state loaded"
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:32 volumio volumio[18348]: info: Reloading queue from file
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::pushState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioPushState
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::setRandom null
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::pushState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioPushState
Feb 12 04:43:32 volumio volumio[18348]: info: Setting Device type: Raspberry PI
Feb 12 04:43:32 volumio volumio[18348]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:43:32 volumio volumio[18348]: info: CoreStateMachine::pushState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioPushState
Feb 12 04:43:32 volumio volumio[18348]: info: Completed loading Core Plugins
Feb 12 04:43:32 volumio volumio[18348]: info: Preparing to generate the ALSA configuration file
Feb 12 04:43:32 volumio sudo[18559]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 04:43:32 volumio sudo[18559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio volumio[18348]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 04:43:32 volumio volumio[18348]: info: Discovery: Found device Volumio
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioGetState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio volumio[18348]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 04:43:32 volumio volumio[18348]: info: Discovery: Found device Volumio
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioGetState
Feb 12 04:43:32 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:32 volumio sudo[18559]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:32 volumio volumio[18348]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 04:43:32 volumio volumio[18348]: info: Reading ALSA contributions from plugins.
Feb 12 04:43:32 volumio volumio[18348]: info: Upmpdcli Daemon Started
Feb 12 04:43:32 volumio volumio[18348]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 04:43:32 volumio volumio[18348]: info: Output device has changed, restarting MPD
Feb 12 04:43:32 volumio volumio[18348]: info: Output device has changed, restarting Shairport Sync
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:32 volumio sudo[18563]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:43:32 volumio sudo[18563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio sudo[18563]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:32 volumio sudo[18565]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-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 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-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 04:43:32 volumio sudo[18565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio volumio[18348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:43:32 volumio volumio[18348]: info: ___________ START PLUGINS ___________
Feb 12 04:43:32 volumio go-librespot[18544]: time="2026-02-12T04:43:32-06:00" level=info msg="zeroconf server listening on port 46761"
Feb 12 04:43:32 volumio volumio[18348]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 04:43:32 volumio volumio[18348]: info: Creating MPD Configuration file
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:32 volumio volumio[18348]: info: [1770893012957] CoreMusicLibrary::Adding element Media Servers
Feb 12 04:43:32 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:32 volumio sudo[18574]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:43:32 volumio sudo[18574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:32 volumio sudo[18574]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 04:43:33 volumio sudo[18576]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:33 volumio sudo[18576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:33 volumio go-librespot[18544]: time="2026-02-12T04:43:33-06:00" level=debug msg="obtained new client token: AACm7OBIzIjwPpNpFu1xQ6E1+iWiecFCmUkIANWuYjnTkFtRp5POOTcs+Zh65v+jXynMzPFinRiplzVNMvOSZrUgNNdYAfhMWsdIqaVYY9Aob+/qiepBPDYZuqq3sMrh8PiAgRv3Q37801H5GyubSEw0DDtqRJm75zLdqVJHQ/PBpn9jDUuQY+K2nr1LjqHkpxY/Z1btvzOfFC6K0Ci0ogBd/DEzhDy7Xv+c/2QxaKIp6GhdVFA2NBQ="
Feb 12 04:43:33 volumio volumio[18348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:33 volumio volumio[18348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013082] CoreMusicLibrary::Adding element Last_100
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013087] CoreMusicLibrary::Adding element Webradio
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:43:33 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 04:43:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 04:43:33 volumio systemd[1]: mpd.service: Consumed 4.458s CPU time.
Feb 12 04:43:33 volumio volumio[18348]: info: Initializing BBC Radios
Feb 12 04:43:33 volumio go-librespot[18544]: time="2026-02-12T04:43:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:33 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 04:43:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 04:43:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:33 volumio go-librespot[18544]: time="2026-02-12T04:43:33-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:33 volumio go-librespot[18544]: time="2026-02-12T04:43:33-06:00" level=debug msg="completed challenge"
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013168] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013185] CoreMusicLibrary::Adding element SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio go-librespot[18544]: time="2026-02-12T04:43:33-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 04:43:33 volumio volumio[18348]: info: Creating Spotify config file
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:33 volumio sudo[18601]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 04:43:33 volumio sudo[18601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 04:43:33 volumio sudo[18601]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:33 volumio volumio[18348]: info: [squeezelite_mc] Starting proxy server...
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013550] CoreMusicLibrary::Adding element YouTube2
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013569] CoreMusicLibrary::Adding element YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013581] CoreMusicLibrary::Adding element Podcast
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Podcast
Feb 12 04:43:33 volumio volumio[18348]: info: Loading i18n strings for locale en
Feb 12 04:43:33 volumio volumio[18348]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 04:43:33 volumio volumio[18348]: Updating browse sources language
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Podcast
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Podcast
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:33 volumio volumio[18348]: info: [1770893013635] CoreMusicLibrary::Adding element Volusonic
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Podcast
Feb 12 04:43:33 volumio volumio[18348]: Cannot find translation for source Volusonic
Feb 12 04:43:33 volumio volumio[18348]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 04:43:33 volumio volumio[18348]: info: Volumio Calling Home
Feb 12 04:43:33 volumio volumio[18348]: info: [squeezelite_mc] Proxy server started on port 38705
Feb 12 04:43:33 volumio volumio[18348]: info: Preparing to generate the ALSA configuration file
Feb 12 04:43:33 volumio volumio[18348]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:43:33 volumio volumio[18348]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 04:43:33 volumio volumio[18348]: info: Reading ALSA contributions from plugins.
Feb 12 04:43:33 volumio volumio[18348]: info: MPD Permissions set
Feb 12 04:43:33 volumio volumio[18348]: info: MPD Permissions set
Feb 12 04:43:33 volumio volumio[18348]: info: Spotify config file written
Feb 12 04:43:33 volumio sudo[18611]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 04:43:34 volumio sudo[18611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio volumio[18348]: 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 04:43:34 volumio volumio[18348]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:43:34 volumio volumio[18348]: info: CoreStateMachine::pushState
Feb 12 04:43:34 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::volumioPushState
Feb 12 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Server discovery started
Feb 12 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Player finder started
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 04:43:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:34 volumio go-librespot[18615]: go-librespot daemon starting...
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: No need to fix Spotify hosts
Feb 12 04:43:34 volumio sudo[18611]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="app state loaded"
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:34 volumio volumio[18348]: 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 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 04:43:34 volumio volumio[18348]: 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 04:43:34 volumio volumio[18348]: info: Volumio called home
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-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 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-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 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-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 04:43:34 volumio volumio[18348]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 04:43:34 volumio volumio[18348]: SPOTIFY: BQCbzTBn80HrQJpMvRaac4StM2sbFoMx52RGQ252b-C6ETcfbJft0cMwf6F8RL0UUNXHmQCbX2TIOa0_M3CZmBixz5rE3FPOonySxFd9NrE_duhnu_72ZGupqK3uq6OdkAYfOEIeSUOE9t6RlB7dsyaGyGqWhi3uKdu0hi7SKtU2LflakpA03eGjmABmd9o9UUnT9yQSCcZwY1qxEO9Ud95MfdVHXIHISSxijrE
Feb 12 04:43:34 volumio volumio[18348]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 04:43:34 volumio volumio[18348]: info: New Spotify access token = BQCbzTBn80HrQJpMvRaac4StM2sbFoMx52RGQ252b-C6ETcfbJft0cMwf6F8RL0UUNXHmQCbX2TIOa0_M3CZmBixz5rE3FPOonySxFd9NrE_duhnu_72ZGupqK3uq6OdkAYfOEIeSUOE9t6RlB7dsyaGyGqWhi3uKdu0hi7SKtU2LflakpA03eGjmABmd9o9UUnT9yQSCcZwY1qxEO9Ud95MfdVHXIHISSxijrE
Feb 12 04:43:34 volumio volumio[18348]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=info msg="zeroconf server listening on port 45359"
Feb 12 04:43:34 volumio sudo[18637]:  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 04:43:34 volumio volumio[18348]: info: Starting Shairport Sync
Feb 12 04:43:34 volumio sudo[18637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio sudo[18637]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio volumio[18348]: info: Starting Shairport Sync
Feb 12 04:43:34 volumio volumio[18348]: info: Starting Shairport Sync
Feb 12 04:43:34 volumio sudo[18640]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:43:34 volumio sudo[18640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="obtained new client token: AAApdRsmtES0gU4FCYljYxrPAvzJb+S0UNPV1N2d5/FVGRa/p+5SmQ3ycCZLgcWg/2lHYc/w6N0RocJMfk+lKddxgqmrHthN2pY7b0FnJvX4OopMDyaIrKczKZdDomQ1OYcLuxEx7l6ShumnYbYLtC5KUl0SZUd2G9Ry3p/6ISCakmRryphzog8QqhEkhIxmPcd1VZWDWKII+3ymrHqTSZe3xyxw7gNHwzldlS3ylEn1y1qfREo/H2OyTg=="
Feb 12 04:43:34 volumio sudo[18644]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:43:34 volumio sudo[18644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio sudo[18642]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:43:34 volumio sudo[18642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:34 volumio volumio[18348]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 04:43:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 04:43:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 04:43:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:43:34 volumio systemd[1]: shairport-sync.service: Consumed 2.037s CPU time.
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-06:00" level=debug msg="completed challenge"
Feb 12 04:43:34 volumio volumio[18348]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 04:43:34 volumio volumio[18348]: info: Output device has changed, restarting MPD
Feb 12 04:43:34 volumio volumio[18348]: info: Output device has changed, restarting Shairport Sync
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:34 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:34 volumio sudo[18650]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 04:43:34 volumio sudo[18650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:43:34 volumio sudo[18644]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio sudo[18640]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio go-librespot[18626]: time="2026-02-12T04:43:34-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 04:43:34 volumio sudo[18657]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:43:34 volumio sudo[18657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio sudo[18653]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:43:34 volumio sudo[18653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:34 volumio sudo[18642]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:34 volumio sudo[18653]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio sudo[18650]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:34 volumio volumio[18348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:43:34 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 04:43:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 04:43:34 volumio systemd[1]: mpd.service: Consumed 1.593s CPU time.
Feb 12 04:43:34 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 04:43:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 04:43:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 04:43:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 04:43:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 04:43:35 volumio volumio[18348]: info: MPD Permissions set
Feb 12 04:43:35 volumio volumio[18348]: info: Shairport-Sync Started
Feb 12 04:43:35 volumio volumio[18348]: Error adding Membership: Error: addMembership EINVAL
Feb 12 04:43:35 volumio volumio[18348]: 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 04:43:35 volumio volumio[18348]: info: Shairport-Sync Started
Feb 12 04:43:35 volumio volumio[18348]: info: Shairport-Sync Started
Feb 12 04:43:35 volumio sudo[18686]:  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 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio sudo[18686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio sudo[18686]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::volumioGetState
Feb 12 04:43:35 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:35 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 04:43:35 volumio volumio[18348]: info: Starting Shairport Sync
Feb 12 04:43:35 volumio sudo[18694]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 04:43:35 volumio sudo[18694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:35 volumio sudo[18683]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 04:43:35 volumio volumio[18348]: 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 04:43:35 volumio sudo[18683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 04:43:35 volumio volumio[18348]: info: Spotify Successfully logged in
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:43:35 volumio volumio[18348]: info: [1770893015284] CoreMusicLibrary::Adding element Spotify
Feb 12 04:43:35 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source Bandcamp Discover
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source SoundCloud
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source YouTube2
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source YouTube Music
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source Podcast
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source Volusonic
Feb 12 04:43:35 volumio volumio[18348]: Cannot find translation for source Spotify
Feb 12 04:43:35 volumio sudo[18683]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:35 volumio sudo[18697]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:43:35 volumio sudo[18697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:35 volumio systemd[1]: Reloading.
Feb 12 04:43:35 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:43:36 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:36 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:36 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:43:36 volumio volumio[18348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:43:37 volumio volumio[18348]: info: go-librespot daemon successfully initialized
Feb 12 04:43: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 04:43: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 04:43:38 volumio sudo[18694]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124.
Feb 12 04:43:38 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:38 volumio sudo[18734]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:38 volumio sudo[18734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:38 volumio go-librespot[18735]: go-librespot daemon starting...
Feb 12 04:43:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 04:43:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 04:43:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:43:38 volumio systemd[1]: shairport-sync.service: Consumed 1.447s CPU time.
Feb 12 04:43:38 volumio go-librespot[18737]: time="2026-02-12T04:43:38-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:38 volumio go-librespot[18737]: time="2026-02-12T04:43:38-06:00" level=debug msg="app state loaded"
Feb 12 04:43:38 volumio go-librespot[18737]: time="2026-02-12T04:43:38-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:38 volumio go-librespot[18737]: time="2026-02-12T04:43:38-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:43:39 volumio sudo[18697]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:39 volumio volumio[18348]: info: Shairport-Sync Started
Feb 12 04:43:39 volumio sudo[18734]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:39 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 04:43:39 volumio sudo[18757]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 04:43:39 volumio sudo[18757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:39 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-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 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-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 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-06:00" level=info msg="zeroconf server listening on port 43481"
Feb 12 04:43:39 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 04:43:39 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 04:43:39 volumio sudo[18757]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-06:00" level=debug msg="obtained new client token: AADFjWAcrz8bed18EGnUehs3gpEgxb59n1P0hQ4mJJEMlMFoAdueIadpm4jjnACjzFeqOB9PxwD5bEa5IGzxSKQKqMbNgffZQTOrelluuiX7rPtWy6RE1awqavDRqwlm2xE359EPlts7WY+c1uRRoRbKij3nxxTh+LPAhJPC07+BF9+hWKGdPjewxfEHT/QHgU+Ec6RyXkql5T3U1N0SxeU9tpVtp+2DwiHOR6+z0A1NkdE5Of4PocfmQA=="
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-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 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43:39-06:00" level=debug msg="completed challenge"
Feb 12 04:43:39 volumio go-librespot[18737]: time="2026-02-12T04:43: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 04:43:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:39 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:39 volumio sudo[18764]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:39 volumio sudo[18764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:40 volumio sudo[18764]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio volumio[18348]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 04:43:40 volumio sudo[18768]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 04:43:40 volumio sudo[18768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:40 volumio sudo[18768]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 04:43:40 volumio sudo[18771]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 04:43:40 volumio sudo[18771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:40 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 04:43:40 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 04:43:40 volumio sudo[18771]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio mpd[18700]: 2026-02-12T04:43:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 04:43:40 volumio volumio[18348]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:40 volumio volumio[18348]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:40 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 04:43:40 volumio sudo[18657]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio sudo[18576]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio sudo[18565]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:40 volumio volumio[18348]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 04:43:40 volumio volumio[18348]:   assert.ok(self.idling)
Feb 12 04:43:40 volumio volumio[18348]: error: The expression evaluated to a falsy value:
Feb 12 04:43:40 volumio volumio[18348]:   assert.ok(self.idling)
Feb 12 04:43:40 volumio volumio[18348]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 04:43:40 volumio volumio[18348]:   assert.ok(self.idling)
Feb 12 04:43:40 volumio volumio[18348]: error: The expression evaluated to a falsy value:
Feb 12 04:43:40 volumio volumio[18348]:   assert.ok(self.idling)
Feb 12 04:43:40 volumio volumio[18348]: error: updateQueue error: null
Feb 12 04:43:40 volumio volumio[18348]: info: MPD running with PID18700
Feb 12 04:43:40 volumio volumio[18348]:  ,establishing connection
Feb 12 04:43:40 volumio volumio[18348]: error: updateQueue error: null
Feb 12 04:43:40 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:40 volumio sudo[18782]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:40 volumio sudo[18782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:40 volumio sudo[18782]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:41 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:41 volumio sudo[18785]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:41 volumio sudo[18785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:41 volumio sudo[18785]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:42 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:42 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:43:42 volumio sudo[18788]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:42 volumio sudo[18788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:42 volumio sudo[18788]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:42 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:42 volumio sudo[18792]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:42 volumio sudo[18792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125.
Feb 12 04:43:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:42 volumio go-librespot[18794]: go-librespot daemon starting...
Feb 12 04:43:42 volumio sudo[18792]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-06:00" level=debug msg="app state loaded"
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-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 04:43:42 volumio go-librespot[18795]: time="2026-02-12T04:43:42-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 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43:43-06:00" level=info msg="zeroconf server listening on port 35869"
Feb 12 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43:43-06:00" level=debug msg="obtained new client token: AAC/rpVoad/XT2AfzINov72R7oI1KsjDrMrX+4JQeHSSQ5vzNs/v52NFLaxA1yz4+w7XYJ2oK8IHLcsVJtd3cc4+fn63NabV9OOafTLTVHBb9N5eYMwQPlnRapL01CW4dfa1BbnuYe3iyh4I3fAtJPJdeMHCbkgpktmLd8+8Xf1hLh+/+Ap451K33P0XXnosCxPozCGLwpYKZz9wq25PgfkTZqOENVgjrMDGu+qsrD1nBWr9pcBAIPg="
Feb 12 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43:43-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43:43-06:00" level=debug msg="completed challenge"
Feb 12 04:43:43 volumio go-librespot[18795]: time="2026-02-12T04:43: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 04:43:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:43 volumio volumio[18348]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:43:43 volumio sudo[18803]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:43:43 volumio sudo[18803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:43 volumio sudo[18803]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:43 volumio volumio[18348]: info: Completed starting Core Plugins
Feb 12 04:43:43 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:43 volumio volumio[18348]: info: -----    MyVolumio plugins startup     ----
Feb 12 04:43:43 volumio volumio[18348]: info: -------------------------------------------
Feb 12 04:43:43 volumio volumio[18348]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 04:43:43 volumio volumio[18348]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:43 volumio volumio[18348]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:43:43 volumio sudo[18806]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:43:43 volumio sudo[18806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:43 volumio sudo[18808]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:43:43 volumio sudo[18808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:43 volumio sudo[18810]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:43:43 volumio sudo[18810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:43 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 04:43:43 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 04:43:43 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 04:43:43 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 04:43:43 volumio sudo[18810]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:43 volumio sudo[18806]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:43 volumio volumio[18348]: info: Successfully started MPD Monitor
Feb 12 04:43:43 volumio sudo[18808]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:43 volumio mpd_monitor.sh[18814]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 04:43:43 volumio volumio[18348]: info: Successfully started MPD Monitor
Feb 12 04:43:43 volumio volumio[18348]: info: Successfully started MPD Monitor
Feb 12 04:43:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126.
Feb 12 04:43:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:46 volumio go-librespot[18821]: go-librespot daemon starting...
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="app state loaded"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-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 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-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 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=info msg="zeroconf server listening on port 40913"
Feb 12 04:43:46 volumio volumio[18348]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="obtained new client token: AAD/GnrVchx4Qd7jwCxJxPVXZ4NuleLns1kcCUplmsy3is/DdpjwzPfaum7+2wD6JLcatU3+duDzduKMwDN0OUpb7guBs2eTeWUW2EvRUVkzqUUehpzyQieEZSFI/Acp/OA0wNbM5tUDUSd13KCWvsgs/8ZXiS083P8wyF4IfR5gd9GoPGzyl3kw+eO2OEKO+wXCwga5iA6mDFvxKugA6F+LPYqkRW6ea3Q7aBJ/ILG5s4nUcvLMMux0MQ=="
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="completed challenge"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=debug msg="new websocket client"
Feb 12 04:43:46 volumio go-librespot[18822]: time="2026-02-12T04:43:46-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 04:43:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:47 volumio volumio[18348]: info: Connection to go-librespot Websocket established
Feb 12 04:43:47 volumio volumio[18348]: info: Connection to go-librespot Websocket closed
Feb 12 04:43:48 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:43:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127.
Feb 12 04:43:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:50 volumio go-librespot[18845]: go-librespot daemon starting...
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="app state loaded"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:50 volumio volumio[18348]: info: Getting Spotify volume
Feb 12 04:43:50 volumio volumio[18348]: 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 04:43:50 volumio volumio[18348]: info: Initializing connection to go-librespot Websocket
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="new websocket client"
Feb 12 04:43:50 volumio volumio[18348]: info: Connection to go-librespot Websocket established
Feb 12 04:43:50 volumio volumio[18348]: info: CoreCommandRouter::volumioGetState
Feb 12 04:43:50 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:50 volumio volumio[18348]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 12 04:43:50 volumio volumio[18348]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 12 04:43:50 volumio volumio[18348]: SPOTIFY: VOLUMIO VOLUME 100
Feb 12 04:43:50 volumio volumio[18348]: info: Aligning Spotify Volume to Volumio Volume
Feb 12 04:43:50 volumio volumio[18348]: info: CoreCommandRouter::volumioGetState
Feb 12 04:43:50 volumio volumio[18348]: info: CorePlayQueue::getTrack 0
Feb 12 04:43:50 volumio volumio[18348]: info: Setting Spotify Volume from Volumio: 100
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-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 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-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 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-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 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=info msg="zeroconf server listening on port 43265"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="obtained new client token: AABxxKmmUMVbuY1PSLaevZK2BInee5fasPQXW+uBqiM8QQvWCJT77mzelPRX6+SmH4+MpmZDxK4tYVud3D/kl0WOChRgEzYYcsSxSzjsnajFdme3K1LWFplozQ6UrjHvaH4VJfUdIxtcT4TGtUGXee5REL8Gt85I4ccDOaGICHbJpeE0GJgqnZ5ILMyr9gGpHZ49ROkUro6EqncR3aCGQXjKkZq0y3qNV3fvdSPGdgEAdN7ONw4imOg7nA=="
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=debug msg="completed challenge"
Feb 12 04:43:50 volumio go-librespot[18846]: time="2026-02-12T04:43:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 04:43:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:50 volumio volumio[18348]: info: Connection to go-librespot Websocket closed
Feb 12 04:43:50 volumio volumio[18348]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:43:50 volumio volumio[18348]: Error: socket hang up
Feb 12 04:43:50 volumio volumio[18348]:     at connResetException (node:internal/errors:720:14)
Feb 12 04:43:50 volumio volumio[18348]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 12 04:43:50 volumio volumio[18348]:     at Socket.emit (node:events:526:35)
Feb 12 04:43:50 volumio volumio[18348]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 12 04:43:50 volumio volumio[18348]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 12 04:43:50 volumio volumio[18348]:   code: 'ECONNRESET',
Feb 12 04:43:50 volumio volumio[18348]:   response: undefined
Feb 12 04:43:50 volumio volumio[18348]: }
Feb 12 04:43:50 volumio volumio[18348]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:43:51 volumio sudo[18868]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 04:42'
Feb 12 04:43:51 volumio sudo[18868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:51 volumio sudo[18868]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:52 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 04:43:52 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 04:43:52 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:52 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 04:43:52 volumio systemd[1]: volumio.service: Consumed 44.204s CPU time.
Feb 12 04:43:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 04:43:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 04:43:53 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6201.
Feb 12 04:43:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 04:43:53 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 04:43:53 volumio systemd[1]: volumio.service: Consumed 44.204s CPU time.
Feb 12 04:43:53 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 04:43:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 04:43:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128.
Feb 12 04:43:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:54 volumio go-librespot[18898]: go-librespot daemon starting...
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="app state loaded"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-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 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-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 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-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 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=info msg="zeroconf server listening on port 39147"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="obtained new client token: AABc4M5X2x9WWg9WQLJI+01yX5YMSde26EiXtu1DqPtONgxvFSmxV7TLTu/QU9KBNnD/xFxRJ2Ud8v0gnnuD9YinL/54Pf/4ZKSo/aPnJu3NqaUVORgEz1wzY18pFiHRAplusGH7pXLNn06zW2YP+i+zRGKs9bo5hGoHGtYvbIuOAnXHjbmMXVIvEh+EqYQUVjuvbJuRFN1FrjajZpumIPRMEmEWqewANxBnUF71WPEYUKJzpQ+xQ0gQOA=="
Feb 12 04:43:54 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=debug msg="completed challenge"
Feb 12 04:43:54 volumio go-librespot[18899]: time="2026-02-12T04:43:54-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 04:43:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:43:55 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:43:55 volumio volumio[18883]: info: -----            Volumio3              ----
Feb 12 04:43:55 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:43:55 volumio volumio[18883]: info: -----          System startup          ----
Feb 12 04:43:55 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:43:56 volumio volumio[18883]: info: MYVOLUMIO Environment detected
Feb 12 04:43:56 volumio volumio[18883]: info: Plugin folders cleanup
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning into folder /volumio/app/plugins/
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category audio_interface
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category miscellanea
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category music_service
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category plugins.json
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category system_controller
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category user_interface
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning into folder /data/plugins/
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category audio_interface
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category music_service
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category system_controller
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category system_hardware
Feb 12 04:43:56 volumio volumio[18883]: info: Scanning category user_interface
Feb 12 04:43:56 volumio volumio[18883]: info: Plugin folders cleanup completed
Feb 12 04:43:56 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:43:56 volumio volumio[18883]: info: -----      Core plugins startup        ----
Feb 12 04:43:56 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:43:56 volumio volumio[18883]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 04:43:56 volumio volumio[18883]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 04:43:56 volumio volumio[18883]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 04:43:56 volumio volumio[18883]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 04:43:56 volumio volumio[18883]: info: Loading plugins from folder /data/plugins/
Feb 12 04:43:56 volumio volumio[18883]: info: Loading plugin "system"...
Feb 12 04:43:56 volumio volumio[18883]: info: Loading plugin "appearance"...
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "network"...
Feb 12 04:43:57 volumio volumio[18883]: info: Refreshing Cached IP Addresses
Feb 12 04:43:57 volumio sudo[18920]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 04:43:57 volumio sudo[18920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:57 volumio sudo[18922]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 04:43:57 volumio sudo[18922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:57 volumio sudo[18920]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:57 volumio sudo[18922]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "services"...
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "alsa_controller"...
Feb 12 04:43:57 volumio sudo[18931]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 04:43:57 volumio sudo[18931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:57 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "wizard"...
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "networkfs"...
Feb 12 04:43:57 volumio volumio[18883]: info: Starting Udev Watcher for removable devices
Feb 12 04:43:57 volumio volumio[18883]: info: Ignoring mount for partition: boot
Feb 12 04:43:57 volumio volumio[18883]: info: Ignoring mount for partition: volumio
Feb 12 04:43:57 volumio volumio[18883]: info: Ignoring mount for partition: volumio_data
Feb 12 04:43:57 volumio volumio[18883]: info: Mounting Device Wikipedia
Feb 12 04:43:57 volumio sudo[18959]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 04:43:57 volumio sudo[18959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:43:57 volumio sudo[18959]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:57 volumio volumio[18883]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 04:43:57 volumio volumio[18883]:        dmesg(1) may have more information after failed mount system call.
Feb 12 04:43:57 volumio volumio[18883]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 04:43:57 volumio volumio[18883]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 04:43:57 volumio volumio[18883]:        dmesg(1) may have more information after failed mount system call.
Feb 12 04:43:57 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "volumio_command_line_client"...
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "upnp"...
Feb 12 04:43:57 volumio volumio[18883]: info: [1770893037724] Starting Upmpd Daemon
Feb 12 04:43:57 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "my_music"...
Feb 12 04:43:57 volumio volumio[18883]: info: Loading plugin "mpd"...
Feb 12 04:43:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129.
Feb 12 04:43:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:43:57 volumio go-librespot[18961]: go-librespot daemon starting...
Feb 12 04:43:57 volumio go-librespot[18962]: time="2026-02-12T04:43:57-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:43:57 volumio go-librespot[18962]: time="2026-02-12T04:43:57-06:00" level=debug msg="app state loaded"
Feb 12 04:43:57 volumio go-librespot[18962]: time="2026-02-12T04:43:57-06:00" level=debug msg="stored credentials not found"
Feb 12 04:43:57 volumio go-librespot[18962]: time="2026-02-12T04:43:57-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:43:57 volumio volumio-remote-updater[2265]: [2026-02-12 04:43:57] [connect] Successful connection
Feb 12 04:43:57 volumio sudo[18931]: pam_unix(sudo:session): session closed for user root
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43: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 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43: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 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43: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 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-06:00" level=info msg="zeroconf server listening on port 38209"
Feb 12 04:43:58 volumio volumio[18883]: info: Loading plugin "upnp_browser"...
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-06:00" level=debug msg="obtained new client token: AADwQNZxs9UYnUBqwghUPWxXfN5gigDyeTEWZZX1z9OMHEiM4+o95ezR/skdR8Ez+TecBu1u21aNxqxJk+5AvX9SYdEhdQXsa0hPNIiPf5Fxs6L1lVdNWqmvP0mPTwJ7nripZEd0xS05mgMvvKL5cmbYCqp70M+4przVwcMFY7JGPVZCUWauG+X0dDPp3ZabS1v7gmyUMaw76/wfAN0t8GNUEpnVKOx4hQ94BTWk6TqF7/a9TyFIWYZ55Q=="
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-06:00" level=debug msg="completed keyexchange"
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-06:00" level=debug msg="completed challenge"
Feb 12 04:43:58 volumio go-librespot[18962]: time="2026-02-12T04:43:58-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 04:43:58 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:43:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:43:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "alarm-clock"...
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "airplay_emulation"...
Feb 12 04:44:01 volumio volumio[18883]: info: Starting Shairport Sync
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "last_100"...
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "webradio"...
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "i2s_dacs"...
Feb 12 04:44:01 volumio volumio[18883]: info: I2S DAC not set, start Auto-detection
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "volumiodiscovery"...
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** For more information see 
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:44:01 volumio volumio[18883]: *** WARNING *** For more information see 
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** For more information see 
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 04:44:01 volumio node[18883]: *** WARNING *** For more information see 
Feb 12 04:44:01 volumio volumio[18883]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 04:44:01 volumio volumio[18883]: info: Discovery: Started advertising with name: Volumio
Feb 12 04:44:01 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 04:44:01 volumio volumio[18883]: info: Loading plugin "bandcamp"...
Feb 12 04:44:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130.
Feb 12 04:44:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:01 volumio go-librespot[18973]: go-librespot daemon starting...
Feb 12 04:44:01 volumio go-librespot[18974]: time="2026-02-12T04:44:01-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:01 volumio go-librespot[18974]: time="2026-02-12T04:44:01-06:00" level=debug msg="app state loaded"
Feb 12 04:44:01 volumio go-librespot[18974]: time="2026-02-12T04:44:01-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:01 volumio go-librespot[18974]: time="2026-02-12T04:44:01-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-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 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-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 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-06:00" level=info msg="zeroconf server listening on port 45319"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-06:00" level=debug msg="obtained new client token: AAC8jd7A6iF0pkitLWUyf5qnS/KF+F2sIjq9jKWR3dT+aftnB6sjAr+6S9qm0mZ5oFoP0/DdMBMXTgYzAdbfvxtSbtIxH7XN5LOhgdBL059jCvGSloEl9MDne1AsGIbUE3ndOJuF4l5wgpMUFZKR9Tc5Tfk7hKIEd5TS97KzngTm0Ibflo8sHttzWY8c1qiSoX4fWGdP1i5+CvgKdIwYf/1qUOkERfdkli9Q42qUQd1zxryN8/R32y8="
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44:02-06:00" level=debug msg="completed challenge"
Feb 12 04:44:02 volumio go-librespot[18974]: time="2026-02-12T04:44: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 04:44:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:02 volumio volumio[18883]: info: Plugin calmradio is not enabled
Feb 12 04:44:02 volumio volumio[18883]: info: Loading plugin "soundcloud"...
Feb 12 04:44:02 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:44:03 volumio volumio[18883]: info: Loading plugin "spop"...
Feb 12 04:44:04 volumio volumio[18883]: info: Loading plugin "squeezelite_mc"...
Feb 12 04:44:04 volumio volumio[18883]: info: Loading plugin "youtube2"...
Feb 12 04:44:05 volumio volumio[18883]: info: Loading plugin "ytcr"...
Feb 12 04:44:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131.
Feb 12 04:44:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:05 volumio go-librespot[18986]: go-librespot daemon starting...
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="app state loaded"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=info msg="zeroconf server listening on port 44139"
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="obtained new client token: AADuAV4/ynZVigKmsnJnzEy/7jzoYBsDPeSnb85O1irY6NQ4MBLuafd1BpyT2eTxxS1uD9BlVp2Vnc7eQImRTdf6NpAsRF5hw9OmXUXZekH0rXFerARsIRQlBTe1BBaeWBrpfqLKabwqjyeHFAOIZklaEnGwCBFuRCIG4gid8o6D3yhm+hAB2zIbWQ64kxxPKNaZdiLHgNZpxiRyRQkTuD6Z9GkfNILlwP3dwkArDtaLRSjnNT9j+ITiKQ=="
Feb 12 04:44:05 volumio go-librespot[18987]: time="2026-02-12T04:44:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:06 volumio go-librespot[18987]: time="2026-02-12T04:44:06-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:06 volumio go-librespot[18987]: time="2026-02-12T04:44:06-06:00" level=debug msg="completed challenge"
Feb 12 04:44:06 volumio go-librespot[18987]: time="2026-02-12T04:44: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 04:44:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:06 volumio volumio[18883]: info: Loading plugin "ytmusic"...
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin now_playing is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "outputs"...
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "albumart"...
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin example_plugin is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "inputs"...
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "updater_comm"...
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin mpdemulation is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "rest_api"...
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "websocket"...
Feb 12 04:44:07 volumio volumio[18883]: info: Starting Socket.io Server version 1.7.4
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin fusiondsp is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin mpdoutput is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Plugin RoonBridge is not enabled
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "podcast"...
Feb 12 04:44:07 volumio volumio[18883]: info: ControllerPodcast::constructor
Feb 12 04:44:07 volumio volumio[18883]: info: Loading plugin "volusonic"...
Feb 12 04:44:07 volumio volumio[18995]: Forking 3 albumart workers
Feb 12 04:44:09 volumio volumio[18883]: info: Applying required configuration parameters for plugin volusonic
Feb 12 04:44:09 volumio volumio[18883]: info: Loading plugin "backup_restore"...
Feb 12 04:44:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132.
Feb 12 04:44:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:09 volumio go-librespot[19050]: go-librespot daemon starting...
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=debug msg="app state loaded"
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:09 volumio volumio[19019]: Starting albumart workers
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:09 volumio volumio[19021]: Starting albumart workers
Feb 12 04:44:09 volumio volumio[19020]: Starting albumart workers
Feb 12 04:44:09 volumio volumio[18883]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 04:44:09 volumio volumio[18883]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 04:44:09 volumio volumio[18883]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 04:44:09 volumio volumio[18883]: info: Loading plugin "scheduledrestart"...
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44: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-gew4.spotify.com:80]"
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-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 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-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 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=info msg="zeroconf server listening on port 35535"
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=debug msg="obtained new client token: AAA8i2Sz/ZbQxIJt1kg2ZOAmnhGHia24wyQc2DseRDh32itT3JhnWmxLN4y/GSwe4eBAEcCbyxW66cbwJhgyrjKlp7xInxp7rGhdmMRuqp512tijbassgRYM9jqivkYev6E46s4j0OjiAuntaQqjycTHr5mKyBLFvkiN7X5NAqzOxpgS3XiylqUwT4e+66iwCWROfFSwn9UyZw7p+D4uw67CHBmnF3O32su/MYVDyKH/kZsfRVFAqQITuA=="
Feb 12 04:44:09 volumio volumio[18883]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 04:44:09 volumio volumio[18883]: info: Plugin Bluetoothremote is not enabled
Feb 12 04:44:09 volumio volumio[18883]: info: Plugin music_services_shield is not enabled
Feb 12 04:44:09 volumio volumio[18883]: info: Loading plugin "Systeminfo"...
Feb 12 04:44:09 volumio go-librespot[19051]: time="2026-02-12T04:44:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:10 volumio go-librespot[19051]: time="2026-02-12T04:44:10-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:10 volumio go-librespot[19051]: time="2026-02-12T04:44:10-06:00" level=debug msg="completed challenge"
Feb 12 04:44:10 volumio go-librespot[19051]: time="2026-02-12T04:44: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 04:44:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:10 volumio volumio[18883]: info: Plugin peppymeterbasic is not enabled
Feb 12 04:44:10 volumio volumio[18883]: info: Loading plugin "peppyspectrum"...
Feb 12 04:44:10 volumio volumio-remote-updater[2265]: [2026-02-12 04:44:10] [connect] Successful connection
Feb 12 04:44:10 volumio volumio[18883]: info: Loading i18n strings for locale en
Feb 12 04:44:10 volumio volumio[18883]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 04:44:10 volumio volumio[18883]: Updating browse sources language
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::initPlayerControls
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:44:10 volumio volumio[18883]: Express server listening on port 3000
Feb 12 04:44:10 volumio volumio[18883]:  [Metrics]  WebUI:  16s 141.46ms 
Feb 12 04:44:10 volumio volumio[18883]: info: CoreStateMachine::resetVolumioState
Feb 12 04:44:10 volumio volumio[18883]: info: CoreStateMachine::getcurrentVolume
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:44:10 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:11 volumio sudo[19081]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 04:44:11 volumio sudo[19081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio sudo[19081]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:11 volumio sudo[19083]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 04:44:11 volumio sudo[19083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio sudo[19083]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:11 volumio volumio[18883]: info: Volumio Network Manager: Network status updated: 1
Feb 12 04:44:11 volumio volumio[18883]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::pushState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioPushState
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::updateTrackBlock
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrackBlock
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:44:11 volumio volumio-remote-updater[2265]: [2026-02-12 04:44:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770893050 101
Feb 12 04:44:11 volumio volumio[18883]: 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 04:44:11 volumio volumio[18883]: info: Reloading queue from file
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::pushState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioPushState
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::setRandom null
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::pushState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioPushState
Feb 12 04:44:11 volumio volumio[18883]: info: Setting Device type: Raspberry PI
Feb 12 04:44:11 volumio volumio[18883]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:44:11 volumio volumio[18883]: info: CoreStateMachine::pushState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioPushState
Feb 12 04:44:11 volumio volumio[18883]: info: Completed loading Core Plugins
Feb 12 04:44:11 volumio volumio[18883]: info: Preparing to generate the ALSA configuration file
Feb 12 04:44:11 volumio sudo[19096]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 04:44:11 volumio sudo[19096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio volumio[18883]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 04:44:11 volumio volumio[18883]: info: Discovery: Found device Volumio
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioGetState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 04:44:11 volumio volumio[18883]: info: Reading ALSA contributions from plugins.
Feb 12 04:44:11 volumio sudo[19096]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:11 volumio volumio[18883]: info: Upmpdcli Daemon Started
Feb 12 04:44:11 volumio volumio[18883]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 04:44:11 volumio volumio[18883]: info: Discovery: Found device Volumio
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioGetState
Feb 12 04:44:11 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:11 volumio volumio[18883]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 04:44:11 volumio volumio[18883]: info: Output device has changed, restarting MPD
Feb 12 04:44:11 volumio volumio[18883]: info: Output device has changed, restarting Shairport Sync
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:11 volumio sudo[19099]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:44:11 volumio sudo[19099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio sudo[19099]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:11 volumio sudo[19101]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:44:11 volumio sudo[19101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio volumio[18883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:44:11 volumio volumio[18883]: info: ___________ START PLUGINS ___________
Feb 12 04:44:11 volumio volumio[18883]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 04:44:11 volumio volumio[18883]: info: Creating MPD Configuration file
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:11 volumio volumio[18883]: info: [1770893051533] CoreMusicLibrary::Adding element Media Servers
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 04:44:11 volumio sudo[19110]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:44:11 volumio sudo[19110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio sudo[19110]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:11 volumio sudo[19111]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:44:11 volumio sudo[19111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:11 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 04:44:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 04:44:11 volumio systemd[1]: mpd.service: Consumed 5.680s CPU time.
Feb 12 04:44:11 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 04:44:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 04:44:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 04:44:11 volumio volumio[18883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:11 volumio volumio[18883]: info: [1770893051669] CoreMusicLibrary::Adding element Last_100
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:11 volumio volumio[18883]: info: [1770893051674] CoreMusicLibrary::Adding element Webradio
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:44:11 volumio volumio[18883]: info: Initializing BBC Radios
Feb 12 04:44:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 04:44:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:11 volumio volumio[18883]: info: [1770893051753] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:11 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:11 volumio volumio[18883]: info: [1770893051766] CoreMusicLibrary::Adding element SoundCloud
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:11 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:11 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:11 volumio volumio[18883]: info: Creating Spotify config file
Feb 12 04:44:11 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:11 volumio sudo[19131]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 04:44:11 volumio sudo[19131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 04:44:11 volumio sudo[19131]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:12 volumio volumio[18883]: info: [squeezelite_mc] Starting proxy server...
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:12 volumio volumio[18883]: info: [1770893052122] CoreMusicLibrary::Adding element YouTube2
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:12 volumio volumio[18883]: info: [1770893052141] CoreMusicLibrary::Adding element YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:12 volumio volumio[18883]: info: [1770893052153] CoreMusicLibrary::Adding element Podcast
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Podcast
Feb 12 04:44:12 volumio volumio[18883]: info: Loading i18n strings for locale en
Feb 12 04:44:12 volumio volumio[18883]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 04:44:12 volumio volumio[18883]: Updating browse sources language
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Podcast
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Podcast
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:12 volumio volumio[18883]: info: [1770893052202] CoreMusicLibrary::Adding element Volusonic
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Podcast
Feb 12 04:44:12 volumio volumio[18883]: Cannot find translation for source Volusonic
Feb 12 04:44:12 volumio volumio[18883]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 04:44:12 volumio volumio[18883]: info: Volumio Calling Home
Feb 12 04:44:12 volumio volumio[18883]: info: [squeezelite_mc] Proxy server started on port 40745
Feb 12 04:44:12 volumio volumio[18883]: info: Preparing to generate the ALSA configuration file
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 04:44:12 volumio volumio[18883]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 04:44:12 volumio volumio[18883]: info: Reading ALSA contributions from plugins.
Feb 12 04:44:12 volumio volumio[18883]: info: MPD Permissions set
Feb 12 04:44:12 volumio volumio[18883]: info: MPD Permissions set
Feb 12 04:44:12 volumio volumio[18883]: info: Spotify config file written
Feb 12 04:44:12 volumio sudo[19145]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 04:44:12 volumio sudo[19145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:12 volumio volumio[18883]: 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 04:44:12 volumio volumio[18883]: info: VolumeController:: Volume=100 Mute =false
Feb 12 04:44:12 volumio volumio[18883]: info: CoreStateMachine::pushState
Feb 12 04:44:12 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::volumioPushState
Feb 12 04:44:12 volumio volumio[18883]: info: [squeezelite_mc] Server discovery started
Feb 12 04:44:12 volumio volumio[18883]: info: [squeezelite_mc] Player finder started
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 04:44:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:12 volumio volumio[18883]: info: No need to fix Spotify hosts
Feb 12 04:44:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:12 volumio go-librespot[19149]: go-librespot daemon starting...
Feb 12 04:44:12 volumio sudo[19145]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:12 volumio go-librespot[19160]: time="2026-02-12T04:44:12-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:12 volumio go-librespot[19160]: time="2026-02-12T04:44:12-06:00" level=debug msg="app state loaded"
Feb 12 04:44:12 volumio go-librespot[19160]: time="2026-02-12T04:44:12-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:12 volumio go-librespot[19160]: time="2026-02-12T04:44:12-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:12 volumio volumio[18883]: 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 04:44:12 volumio volumio[18883]: info: Volumio called home
Feb 12 04:44:13 volumio volumio[18883]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 04:44:13 volumio volumio[18883]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 04:44:13 volumio volumio[18883]: 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 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-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 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-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 04:44:13 volumio volumio[18883]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 04:44:13 volumio volumio[18883]: SPOTIFY: BQAWrJbRL08HH08Uu4XUPOzg_CQOztl8GKW4Rs8fVpYZc1u-ovBN0mAgj50WTfCWGU3_qU3WQXg_i4KWiXVcZk-_2ZM8f7sSy40qqSTrgUfcyDdgdC6OJW2xB_qzbgHLc9FEQsCm0cwa3I6reGWGf34YMMJrZ1xvQcRQPogA7ZnWOTYMWiaNX-je_SZgMZef9oVJgJNxWu8Z-538_9aWlQyU-ZiO_RBRPeIQYDE
Feb 12 04:44:13 volumio volumio[18883]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 04:44:13 volumio volumio[18883]: info: New Spotify access token = BQAWrJbRL08HH08Uu4XUPOzg_CQOztl8GKW4Rs8fVpYZc1u-ovBN0mAgj50WTfCWGU3_qU3WQXg_i4KWiXVcZk-_2ZM8f7sSy40qqSTrgUfcyDdgdC6OJW2xB_qzbgHLc9FEQsCm0cwa3I6reGWGf34YMMJrZ1xvQcRQPogA7ZnWOTYMWiaNX-je_SZgMZef9oVJgJNxWu8Z-538_9aWlQyU-ZiO_RBRPeIQYDE
Feb 12 04:44:13 volumio volumio[18883]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-06:00" level=info msg="zeroconf server listening on port 32835"
Feb 12 04:44:13 volumio sudo[19170]:  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 04:44:13 volumio sudo[19170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio volumio[18883]: info: Starting Shairport Sync
Feb 12 04:44:13 volumio sudo[19170]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio volumio[18883]: info: Starting Shairport Sync
Feb 12 04:44:13 volumio volumio[18883]: info: Starting Shairport Sync
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-06:00" level=debug msg="obtained new client token: AAACL7yZmHq1FUVwyyQ4eGhvZA2RgEEPIl4kuA9HKNbk4ni365burbi9v80vHxZq5qJdWAecFSAcpMXMx8IY0mARS0jThrEv2H0wY4kfP73/q0DqvQ481uqAPkipXuRsREm5OqJnkoW5PSMlDiqjAjXctK/j7p2AZplsjdjXwlXRrLyDe3p3WCVo3RN7atMWtAAv7B+zcnt9pcrXeYZtxbnswHe1nElQoDJOz5M7+0+7CMQd2GWuT8U="
Feb 12 04:44:13 volumio sudo[19174]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:44:13 volumio sudo[19174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19175]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:44:13 volumio sudo[19175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19177]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:44:13 volumio sudo[19177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 04:44:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 04:44:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:44:13 volumio systemd[1]: shairport-sync.service: Consumed 1.970s CPU time.
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44:13-06:00" level=debug msg="completed challenge"
Feb 12 04:44:13 volumio volumio[18883]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 04:44:13 volumio go-librespot[19160]: time="2026-02-12T04:44: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 04:44:13 volumio volumio[18883]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 04:44:13 volumio volumio[18883]: info: Output device has changed, restarting MPD
Feb 12 04:44:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:44:13 volumio sudo[19174]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:13 volumio sudo[19175]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:13 volumio sudo[19186]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 04:44:13 volumio sudo[19186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19186]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio volumio[18883]: info: Output device has changed, restarting Shairport Sync
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:13 volumio sudo[19184]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 04:44:13 volumio sudo[19184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19190]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 04:44:13 volumio sudo[19190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19177]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio sudo[19184]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio volumio[18883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 04:44:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 04:44:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 04:44:13 volumio systemd[1]: mpd.service: Consumed 1.672s CPU time.
Feb 12 04:44:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 04:44:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 04:44:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 04:44:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 04:44:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 04:44:13 volumio volumio[18883]: info: MPD Permissions set
Feb 12 04:44:13 volumio volumio[18883]: info: Shairport-Sync Started
Feb 12 04:44:13 volumio volumio[18883]: Error adding Membership: Error: addMembership EINVAL
Feb 12 04:44:13 volumio volumio[18883]: 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 04:44:13 volumio volumio[18883]: info: Shairport-Sync Started
Feb 12 04:44:13 volumio volumio[18883]: info: Shairport-Sync Started
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 04:44:13 volumio sudo[19218]:  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 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:13 volumio sudo[19218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19218]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::volumioGetState
Feb 12 04:44:13 volumio volumio[18883]: info: CorePlayQueue::getTrack 0
Feb 12 04:44:13 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 04:44:13 volumio volumio[18883]: info: Starting Shairport Sync
Feb 12 04:44:13 volumio sudo[19215]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 04:44:13 volumio sudo[19215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 04:44:13 volumio sudo[19215]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:13 volumio sudo[19226]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 04:44:13 volumio sudo[19226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio sudo[19229]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 04:44:13 volumio sudo[19229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:13 volumio volumio[18883]: 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 04:44:13 volumio volumio[18883]: info: Spotify Successfully logged in
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 04:44:13 volumio volumio[18883]: info: [1770893053977] CoreMusicLibrary::Adding element Spotify
Feb 12 04:44:13 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source Bandcamp Discover
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source SoundCloud
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source YouTube2
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source YouTube Music
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source Podcast
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source Volusonic
Feb 12 04:44:13 volumio volumio[18883]: Cannot find translation for source Spotify
Feb 12 04:44:14 volumio systemd[1]: Reloading.
Feb 12 04:44:15 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:15 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:15 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 04:44:15 volumio volumio[18883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 04:44:15 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:44:16 volumio volumio[18883]: info: go-librespot daemon successfully initialized
Feb 12 04:44:16 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 04:44:16 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 04:44:17 volumio sudo[19226]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133.
Feb 12 04:44:17 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:17 volumio sudo[19252]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:17 volumio sudo[19252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:17 volumio go-librespot[19254]: go-librespot daemon starting...
Feb 12 04:44:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 04:44:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 04:44:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:44:17 volumio systemd[1]: shairport-sync.service: Consumed 1.507s CPU time.
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=debug msg="app state loaded"
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 04:44:17 volumio sudo[19229]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:17 volumio volumio[18883]: info: Shairport-Sync Started
Feb 12 04:44:17 volumio sudo[19252]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:17 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 04:44:17 volumio sudo[19290]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 04:44:17 volumio sudo[19290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:17 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44: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 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44: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 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44: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 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=info msg="zeroconf server listening on port 41869"
Feb 12 04:44:17 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 04:44:17 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 04:44:17 volumio go-librespot[19255]: time="2026-02-12T04:44:17-06:00" level=debug msg="obtained new client token: AABfzIEUnGhO4ctwnyBFxyfll/fcp5LDBNGwfwJfabs9Ydd+Yms/CEGaoqkEBPdT2t9B6KdLaYP5gp3S81LXev5VCYVoqe0VBzO5IIUWdeFLMYBR+5VBpY6+5Xe34y1Os9gmxcut8F/tjU3V1Xw3BYK9uIZ5hsSv1DDY4XUpxiDV8bQS/lB93h+4rZ7PL/gU+b5Qbef6sjqbCe4V3tnGjPafc9gYmCxf1N45T4zH2q0PWT5RgU+yGv+hEQ=="
Feb 12 04:44:18 volumio sudo[19290]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:18 volumio go-librespot[19255]: time="2026-02-12T04:44:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:18 volumio go-librespot[19255]: time="2026-02-12T04:44:18-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:18 volumio go-librespot[19255]: time="2026-02-12T04:44:18-06:00" level=debug msg="completed challenge"
Feb 12 04:44:18 volumio go-librespot[19255]: time="2026-02-12T04:44: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 04:44:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:18 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:18 volumio sudo[19295]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:18 volumio sudo[19295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:18 volumio sudo[19295]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:18 volumio volumio[18883]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 04:44:18 volumio sudo[19299]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 04:44:18 volumio sudo[19299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:18 volumio sudo[19299]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:18 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 04:44:18 volumio sudo[19302]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 04:44:18 volumio sudo[19302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:18 volumio mpd[19231]: 2026-02-12T04:44:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 04:44:18 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 04:44:18 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 04:44:18 volumio sudo[19302]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:19 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 04:44:19 volumio volumio[18883]: info: Initializing connection to go-librespot Websocket
Feb 12 04:44:19 volumio sudo[19111]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:19 volumio sudo[19190]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:19 volumio sudo[19101]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:19 volumio volumio[18883]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:44:19 volumio volumio[18883]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 04:44:19 volumio volumio[18883]:   assert.ok(self.idling)
Feb 12 04:44:19 volumio volumio[18883]: error: The expression evaluated to a falsy value:
Feb 12 04:44:19 volumio volumio[18883]:   assert.ok(self.idling)
Feb 12 04:44:19 volumio volumio[18883]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 04:44:19 volumio volumio[18883]:   assert.ok(self.idling)
Feb 12 04:44:19 volumio volumio[18883]: error: The expression evaluated to a falsy value:
Feb 12 04:44:19 volumio volumio[18883]:   assert.ok(self.idling)
Feb 12 04:44:19 volumio volumio[18883]: info: MPD running with PID19231
Feb 12 04:44:19 volumio volumio[18883]:  ,establishing connection
Feb 12 04:44:19 volumio volumio[18883]: error: updateQueue error: null
Feb 12 04:44:19 volumio volumio[18883]: error: updateQueue error: null
Feb 12 04:44:19 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:19 volumio sudo[19313]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:19 volumio sudo[19313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:19 volumio sudo[19313]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:19 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:20 volumio sudo[19316]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:20 volumio sudo[19316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:20 volumio sudo[19316]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:20 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:20 volumio sudo[19319]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:20 volumio sudo[19319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:20 volumio sudo[19319]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:21 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:21 volumio sudo[19322]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:21 volumio sudo[19322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134.
Feb 12 04:44:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:21 volumio go-librespot[19324]: go-librespot daemon starting...
Feb 12 04:44:21 volumio sudo[19322]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="app state loaded"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:21 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44: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 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44: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 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44: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 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=info msg="zeroconf server listening on port 35589"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="obtained new client token: AADi7Sy1G0wcngwXniWahQVF1SWyUAFk0NySHYK01pY6WN1g+o6ysYckAWBeXGoVZfa2s4D7yoJWVJJGyRVH0waD6/BKHaZgh8yTjoKnrQ+TkStqIZSUfQQatTi8jE/t8sk5ZCIo2N2JKpJ7mTrpSvStU4aFOWHDZENDuq3b++8dzdX/lFnxFNT8Gdiva8PvX0uYBB9zy/d+i7lmF+tXEjlLkdBMrqalrOXTUu6dXDsGDN9SwKiDNUi//Q=="
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44:21-06:00" level=debug msg="completed challenge"
Feb 12 04:44:21 volumio go-librespot[19325]: time="2026-02-12T04:44: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 04:44:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:21 volumio volumio[18883]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 04:44:21 volumio sudo[19334]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 04:44:21 volumio sudo[19334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:21 volumio sudo[19334]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:21 volumio volumio[18883]: info: Completed starting Core Plugins
Feb 12 04:44:21 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:44:21 volumio volumio[18883]: info: -----    MyVolumio plugins startup     ----
Feb 12 04:44:21 volumio volumio[18883]: info: -------------------------------------------
Feb 12 04:44:21 volumio volumio[18883]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 04:44:22 volumio volumio[18883]: info: Initializing connection to go-librespot Websocket
Feb 12 04:44:22 volumio volumio[18883]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:44:22 volumio sudo[19337]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:44:22 volumio sudo[19337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:22 volumio sudo[19339]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:44:22 volumio sudo[19339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:22 volumio sudo[19342]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 04:44:22 volumio sudo[19342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 04:44:22 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 04:44:22 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 04:44:22 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 04:44:22 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 04:44:22 volumio sudo[19342]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:22 volumio mpd_monitor.sh[19345]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 04:44:22 volumio sudo[19339]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:22 volumio sudo[19337]: pam_unix(sudo:session): session closed for user root
Feb 12 04:44:22 volumio volumio[18883]: info: Successfully started MPD Monitor
Feb 12 04:44:22 volumio volumio[18883]: info: Successfully started MPD Monitor
Feb 12 04:44:22 volumio volumio[18883]: info: Successfully started MPD Monitor
Feb 12 04:44:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135.
Feb 12 04:44:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:25 volumio go-librespot[19349]: go-librespot daemon starting...
Feb 12 04:44:25 volumio volumio[18883]: info: Initializing connection to go-librespot Websocket
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="app state loaded"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="new websocket client"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-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 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-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 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=info msg="zeroconf server listening on port 40579"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="obtained new client token: AAAQz2A81WvshWi/8ZJ3qZ05ldiqR4LsoQ4bmAjhdYM/n7VPacd76WknAX5IXDen7DdlIvE6pgWFgCpG8SbkEErqP7ILVEO0MZnWIGIo+kF/1uMwPxtngjh671YEkq4GDBNMijbhQnuqNNVSGBakaGXVW3FUBFX73o41kZiKBy1uhvMRrAIIZhjTllhsPGKSxBXVpkv6F+o9kJ0iuKnqGRJm+njGdBZ/nQSjHT2WrpKpxTlJhKtq8ttZpw=="
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44:25-06:00" level=debug msg="completed challenge"
Feb 12 04:44:25 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 04:44:25 volumio go-librespot[19350]: time="2026-02-12T04:44: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 04:44:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:25 volumio volumio[18883]: info: Connection to go-librespot Websocket established
Feb 12 04:44:25 volumio volumio[18883]: info: Connection to go-librespot Websocket closed
Feb 12 04:44:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136.
Feb 12 04:44:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:28 volumio volumio[18883]: info: Getting Spotify volume
Feb 12 04:44:28 volumio volumio[18883]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:44:28 volumio volumio[18883]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 04:44:28 volumio volumio[18883]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 04:44:28 volumio volumio[18883]:   errno: -111,
Feb 12 04:44:28 volumio volumio[18883]:   code: 'ECONNREFUSED',
Feb 12 04:44:28 volumio volumio[18883]:   syscall: 'connect',
Feb 12 04:44:28 volumio volumio[18883]:   address: '127.0.0.1',
Feb 12 04:44:28 volumio volumio[18883]:   port: 9879,
Feb 12 04:44:28 volumio volumio[18883]:   response: undefined
Feb 12 04:44:28 volumio volumio[18883]: }
Feb 12 04:44:28 volumio volumio[18883]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 04:44:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 04:44:28 volumio go-librespot[19375]: go-librespot daemon starting...
Feb 12 04:44:28 volumio go-librespot[19379]: time="2026-02-12T04:44:28-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 04:44:28 volumio go-librespot[19379]: time="2026-02-12T04:44:28-06:00" level=debug msg="app state loaded"
Feb 12 04:44:28 volumio go-librespot[19379]: time="2026-02-12T04:44:28-06:00" level=debug msg="stored credentials not found"
Feb 12 04:44:28 volumio go-librespot[19379]: time="2026-02-12T04:44:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=info msg="zeroconf server listening on port 40099"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="obtained new client token: AADTCxbr/XXxvJKxIvaC8G75dHwxSoo/eKG7h5vp3MZeYSbdalQB2lJTTyWno6YEK8AzFunHG9+XF5AuEtzGH28hsDnh280SC/66l0MPN6E9cxi1LlGAuLGIieonPgiFI4oDnZXnNiv3yom0COT+PvsQ7bxs+deqFa6HW7coU59W8Muj2/eCmfURqfbNIrREu2tcqpcc9wfKKl/NkmRGM3cpwu44q7CAM4RRPqelAbQmWK5PEFW4/2k="
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="completed keyexchange"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44:29-06:00" level=debug msg="completed challenge"
Feb 12 04:44:29 volumio go-librespot[19379]: time="2026-02-12T04:44: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 04:44:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 04:44:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 04:44:29 volumio sudo[19397]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 04:43'
Feb 12 04:44:29 volumio sudo[19397]: 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"