Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="app state loaded" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-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]" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-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]" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-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]" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=info msg="zeroconf server listening on port 35597" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="obtained new client token: AADXxALtPokX7MwHbwlGqNj6VxemJxy+g6qF30lzcz5Du48bKS9cYgQa/IjHl1cv6dRtfL44P8foEPDusP7ouIZzydTW1F6MCyYtIBLdsnMbEPLnoM4CvdAUDT3X6TMi/8MhSdCqJL/l65su1ZkiYHbCyEIFQ3RFH7F73S76n/L5cvzcSFtDAOJ97Mq4slSq26B3glg8UXcKPeDaBRxCjwtnPeaelCC6glDti1MUX6PNfgPKBt8wQ2lKpA==" Dec 06 15:08:00 volumio volumio[28097]: info: Updating MyVolumio device info Dec 06 15:08:00 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:00 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:00 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=debug msg="completed challenge" Dec 06 15:08:00 volumio go-librespot[28620]: time="2025-12-06T15:08:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:00 volumio volumio[28097]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 06 15:08:01 volumio volumio[28097]: info: Initializing connection to go-librespot Websocket Dec 06 15:08:01 volumio volumio[28097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:08:03 volumio volumio[28097]: info: MYVOLUMIO: Adding device Dec 06 15:08:03 volumio volumio[28097]: info: MYVOLUMIO: Evaluating Server Dec 06 15:08:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 06 15:08:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:03 volumio go-librespot[28631]: go-librespot daemon starting... Dec 06 15:08:03 volumio go-librespot[28635]: time="2025-12-06T15:08:03-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:03 volumio go-librespot[28635]: time="2025-12-06T15:08:03-06:00" level=debug msg="app state loaded" Dec 06 15:08:03 volumio go-librespot[28635]: time="2025-12-06T15:08:03-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:03 volumio go-librespot[28635]: time="2025-12-06T15:08:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-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]" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-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]" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-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]" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=info msg="zeroconf server listening on port 41831" Dec 06 15:08:04 volumio volumio[28097]: info: Setting Geolocation for MyVolumio to us4 Dec 06 15:08:04 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:04 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:04 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=debug msg="obtained new client token: AABRr4dn2kM4/GbvRnfbT++Mov5Bg/OZmrFD3+gHoBtGv9TACh61VGmuAB4Z2Nj4d8CwwbeDgVoEnsUlMpUig0LbL0pOQpBjrI8ozSD0D6ObmBHD3q41KXXd0Mz305VTyzYulxDuHaPuJslmtjzK6DL2VlScbFnxBIVxH0swSVLJFUdOzZ7XLlYKdl2amzophREpGaCfGKpaI1aC9RKAHw45DQgiNmhC0CiEIqO8111pEQY5eBIqN0g=" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=debug msg="completed challenge" Dec 06 15:08:04 volumio volumio[28097]: info: Initializing connection to go-librespot Websocket Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-06:00" level=debug msg="new websocket client" Dec 06 15:08:04 volumio volumio[28097]: info: Connection to go-librespot Websocket established Dec 06 15:08:04 volumio volumio[28097]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 06 15:08:04 volumio go-librespot[28635]: time="2025-12-06T15:08:04-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 " Dec 06 15:08:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:04 volumio volumio[28097]: info: Connection to go-librespot Websocket closed Dec 06 15:08:05 volumio volumio[28097]: info: Updating MyVolumio device info Dec 06 15:08:05 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:05 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:05 volumio volumio[28097]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:05 volumio volumio[28097]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 06 15:08:07 volumio volumio[28097]: info: Getting Spotify volume Dec 06 15:08:07 volumio volumio[28097]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:08:07 volumio volumio[28097]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:08:07 volumio volumio[28097]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 06 15:08:07 volumio volumio[28097]: errno: -111, Dec 06 15:08:07 volumio volumio[28097]: code: 'ECONNREFUSED', Dec 06 15:08:07 volumio volumio[28097]: syscall: 'connect', Dec 06 15:08:07 volumio volumio[28097]: address: '127.0.0.1', Dec 06 15:08:07 volumio volumio[28097]: port: 9879, Dec 06 15:08:07 volumio volumio[28097]: response: undefined Dec 06 15:08:07 volumio volumio[28097]: } Dec 06 15:08:07 volumio volumio[28097]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:08:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 06 15:08:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:07 volumio go-librespot[28665]: go-librespot daemon starting... Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=debug msg="app state loaded" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-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]" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-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]" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=info msg="zeroconf server listening on port 34005" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=debug msg="obtained new client token: AAAUYvVGgq7vf5e7KT9JcI0uu5w24GI1v9AtHIAn581E0nTY+ZXrIaUDPvSPeL6sxgyjDPU3dwdxAiwVaSTLm1UiysefY09JVkKx6r07Yd/3qO5mQM1cBHm/0RqLuRrYXIqCkvrj9t0TC0UeeGyIcF4K4VlC0KsFcBLLLOaUQkalNfYQPZ2Zb6ZZrMbR8u27P7waIT9rtiV0qWPlWW3PKIFu/RFDSiihJAyas4BZBnRQgrjeU1p/Vcz0Jw==" Dec 06 15:08:07 volumio go-librespot[28667]: time="2025-12-06T15:08:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:08 volumio go-librespot[28667]: time="2025-12-06T15:08:08-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:08 volumio go-librespot[28667]: time="2025-12-06T15:08:08-06:00" level=debug msg="completed challenge" Dec 06 15:08:08 volumio go-librespot[28667]: time="2025-12-06T15:08:08-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 " Dec 06 15:08:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:08 volumio sudo[28690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 15:07' Dec 06 15:08:08 volumio sudo[28690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:08 volumio sudo[28690]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:08 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 06 15:08:08 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 06 15:08:08 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:08 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 06 15:08:08 volumio systemd[1]: volumio.service: Consumed 46.664s CPU time. Dec 06 15:08:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 15:08:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 15:08:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21105. Dec 06 15:08:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 15:08:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 06 15:08:08 volumio systemd[1]: volumio.service: Consumed 46.664s CPU time. Dec 06 15:08:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 06 15:08:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 15:08:10 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:10 volumio volumio[28704]: info: ----- Volumio3 ---- Dec 06 15:08:10 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:10 volumio volumio[28704]: info: ----- System startup ---- Dec 06 15:08:10 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 06 15:08:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:11 volumio go-librespot[28728]: go-librespot daemon starting... Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="app state loaded" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:11 volumio volumio[28704]: info: MYVOLUMIO Environment detected Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=info msg="zeroconf server listening on port 44465" Dec 06 15:08:11 volumio volumio[28704]: info: Plugin folders cleanup Dec 06 15:08:11 volumio volumio[28704]: info: Scanning into folder /volumio/app/plugins/ Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category audio_interface Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category miscellanea Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category music_service Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category plugins.json Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category system_controller Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category user_interface Dec 06 15:08:11 volumio volumio[28704]: info: Scanning into folder /data/plugins/ Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category audio_interface Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category music_service Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category system_controller Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category system_hardware Dec 06 15:08:11 volumio volumio[28704]: info: Scanning category user_interface Dec 06 15:08:11 volumio volumio[28704]: info: Plugin folders cleanup completed Dec 06 15:08:11 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:11 volumio volumio[28704]: info: ----- Core plugins startup ---- Dec 06 15:08:11 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:11 volumio volumio[28704]: info: Loading plugins from folder /volumio/app/plugins/ Dec 06 15:08:11 volumio volumio[28704]: info: Adding plugin upnp to MyMusic Plugins Dec 06 15:08:11 volumio volumio[28704]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 06 15:08:11 volumio volumio[28704]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 06 15:08:11 volumio volumio[28704]: info: Loading plugins from folder /data/plugins/ Dec 06 15:08:11 volumio volumio[28704]: info: Loading plugin "system"... Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="obtained new client token: AAD9w04KcD1I5kU4y9RJfa96h8jBQV40JsPCju8JR9aybNHajkVu+vcedjAy9D4eGkh9u9v1PmHlD10mDBT7RpGJOIqANl/XJzBQillepXDT/3sXjXjToBotRCk1Pt1cxwGmo/X3VIyG+7MWpZVQoH7FsUCoxz7GbXSiOyqSOEBhQkRHUy4IMbs8KpLPybdsjV88CgzF0e/6Wu49QlvtyKlucSbEVrdu95cUiZ2WKrPmXTqp4LLshxCHmw==" Dec 06 15:08:11 volumio volumio[28704]: info: Loading plugin "appearance"... Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=debug msg="completed challenge" Dec 06 15:08:11 volumio go-librespot[28729]: time="2025-12-06T15:08:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:12 volumio volumio[28704]: info: Loading plugin "network"... Dec 06 15:08:12 volumio volumio[28704]: info: Refreshing Cached IP Addresses Dec 06 15:08:12 volumio sudo[28744]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 15:08:12 volumio sudo[28744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:12 volumio sudo[28746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 15:08:12 volumio sudo[28746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:12 volumio sudo[28744]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:12 volumio sudo[28746]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:12 volumio volumio[28704]: info: Loading plugin "services"... Dec 06 15:08:12 volumio volumio[28704]: info: Loading plugin "alsa_controller"... Dec 06 15:08:12 volumio sudo[28759]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 06 15:08:12 volumio sudo[28759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:12 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:08:12 volumio volumio[28704]: info: Loading plugin "wizard"... Dec 06 15:08:12 volumio volumio[28704]: info: Loading plugin "networkfs"... Dec 06 15:08:12 volumio volumio[28704]: info: Starting Udev Watcher for removable devices Dec 06 15:08:12 volumio volumio[28704]: info: Ignoring mount for partition: boot Dec 06 15:08:12 volumio volumio[28704]: info: Ignoring mount for partition: volumio Dec 06 15:08:12 volumio volumio[28704]: info: Ignoring mount for partition: volumio_data Dec 06 15:08:13 volumio volumio[28704]: info: Mounting Device Wikipedia Dec 06 15:08:13 volumio sudo[28783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 06 15:08:13 volumio sudo[28783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:13 volumio sudo[28783]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:13 volumio volumio[28704]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 06 15:08:13 volumio volumio[28704]: dmesg(1) may have more information after failed mount system call. Dec 06 15:08:13 volumio volumio[28704]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 06 15:08:13 volumio volumio[28704]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 06 15:08:13 volumio volumio[28704]: dmesg(1) may have more information after failed mount system call. Dec 06 15:08:13 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:13 volumio volumio[28704]: info: Loading plugin "volumio_command_line_client"... Dec 06 15:08:13 volumio volumio[28704]: info: Loading plugin "upnp"... Dec 06 15:08:13 volumio volumio[28704]: info: [1765055293073] Starting Upmpd Daemon Dec 06 15:08:13 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:13 volumio volumio[28704]: info: Loading plugin "my_music"... Dec 06 15:08:13 volumio volumio[28704]: info: Loading plugin "mpd"... Dec 06 15:08:13 volumio volumio[28704]: info: Loading plugin "upnp_browser"... Dec 06 15:08:13 volumio sudo[28759]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:13 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:13] [connect] Successful connection Dec 06 15:08:14 volumio volumio[28704]: info: Loading plugin "alarm-clock"... Dec 06 15:08:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 06 15:08:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:15 volumio go-librespot[28785]: go-librespot daemon starting... Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="app state loaded" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "airplay_emulation"... Dec 06 15:08:15 volumio volumio[28704]: info: Starting Shairport Sync Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "last_100"... Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "webradio"... Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "i2s_dacs"... Dec 06 15:08:15 volumio volumio[28704]: info: I2S DAC not set, start Auto-detection Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "volumiodiscovery"... Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:15 volumio node[28704]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:15 volumio node[28704]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** For more information see Dec 06 15:08:15 volumio node[28704]: *** WARNING *** For more information see Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:15 volumio node[28704]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:15 volumio node[28704]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:15 volumio volumio[28704]: *** WARNING *** For more information see Dec 06 15:08:15 volumio node[28704]: *** WARNING *** For more information see Dec 06 15:08:15 volumio volumio[28704]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 06 15:08:15 volumio volumio[28704]: info: Discovery: Started advertising with name: Volumio Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-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]" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-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]" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-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]" Dec 06 15:08:15 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:15 volumio volumio[28704]: info: Loading plugin "bandcamp"... Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=info msg="zeroconf server listening on port 39089" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="obtained new client token: AAAsEvp7IoDraTqZqClSHcJ6mzRa/tgauB8PdO9D+JBNdPd7bIjHItsvPWllRqjSB5PXL3rlc4hu9QhnNBYls0ntfZQOUglms8T+Caz3zfZIzzLUYnSI9Bq1T0hPGAkab9mhjXQYuPbSevq6hBiEESXbBaTHyEu518iYuVvO3LxXirIy/mhVq1KW1YLtr0uf1Rf6n/NiSpFm8vV/SCEV4jwd6uGlS7337g1P+P/sf70V9C7EqJ/PvpXFkg==" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=debug msg="completed challenge" Dec 06 15:08:15 volumio go-librespot[28786]: time="2025-12-06T15:08:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:16 volumio volumio[28704]: info: Plugin calmradio is not enabled Dec 06 15:08:16 volumio volumio[28704]: info: Loading plugin "soundcloud"... Dec 06 15:08:16 volumio volumio[28704]: info: Loading plugin "spop"... Dec 06 15:08:17 volumio volumio[28704]: info: Loading plugin "squeezelite_mc"... Dec 06 15:08:18 volumio volumio[28704]: info: Loading plugin "youtube2"... Dec 06 15:08:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 06 15:08:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:18 volumio go-librespot[28796]: go-librespot daemon starting... Dec 06 15:08:18 volumio go-librespot[28797]: time="2025-12-06T15:08:18-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:18 volumio go-librespot[28797]: time="2025-12-06T15:08:18-06:00" level=debug msg="app state loaded" Dec 06 15:08:18 volumio go-librespot[28797]: time="2025-12-06T15:08:18-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:18 volumio go-librespot[28797]: time="2025-12-06T15:08:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-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]" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-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]" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-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]" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-06:00" level=info msg="zeroconf server listening on port 39503" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-06:00" level=debug msg="obtained new client token: AAAUd2sVxOt8ndzGaXEd5/nKzww96K8aQL/8JoUPTOsYqBC6Z5MGrASQS9egbZ/QyY0qizFV8YNtLKm1IrV055FJRAhpAvgUNvwtlbMjSCOgdwGmJFEJp2qDLorqq815iCuNkO6qjpgB15kH3X6zK94ZFybMVcW3xCHXvNQ9IRaqXb2OcZtQM08RYO7XiWTxoYftbY90WUaUrOG0og3vlsaz7+k2nE317h50ymadE1grVpxexTcKfQQ=" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-06:00" level=debug msg="completed challenge" Dec 06 15:08:19 volumio volumio[28704]: info: Loading plugin "ytcr"... Dec 06 15:08:19 volumio go-librespot[28797]: time="2025-12-06T15:08:19-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 " Dec 06 15:08:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:20 volumio volumio[28704]: info: Loading plugin "ytmusic"... Dec 06 15:08:21 volumio volumio[28704]: info: Plugin now_playing is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "outputs"... Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "albumart"... Dec 06 15:08:21 volumio volumio[28704]: info: Plugin example_plugin is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "inputs"... Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "updater_comm"... Dec 06 15:08:21 volumio volumio[28704]: info: Plugin mpdemulation is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "rest_api"... Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "websocket"... Dec 06 15:08:21 volumio volumio[28704]: info: Starting Socket.io Server version 1.7.4 Dec 06 15:08:21 volumio volumio[28704]: info: Plugin fusiondsp is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Plugin mpdoutput is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Plugin RoonBridge is not enabled Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "podcast"... Dec 06 15:08:21 volumio volumio[28704]: info: ControllerPodcast::constructor Dec 06 15:08:21 volumio volumio[28704]: info: Loading plugin "volusonic"... Dec 06 15:08:21 volumio volumio[28805]: Forking 3 albumart workers Dec 06 15:08:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 06 15:08:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:22 volumio go-librespot[28845]: go-librespot daemon starting... Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=debug msg="app state loaded" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-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]" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-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]" Dec 06 15:08:22 volumio go-librespot[28846]: time="2025-12-06T15:08:22-06:00" level=info msg="zeroconf server listening on port 42605" Dec 06 15:08:23 volumio go-librespot[28846]: time="2025-12-06T15:08:23-06:00" level=debug msg="obtained new client token: AAARlgn6e77GnEf1buJA1JEuBwFbhGOqaqnIaihgjVZym3G+06smxiPWPid9Cw3LsILejpQZ9IUrI8NowDT6agPS6JONmjyQaKbtuDXO4z0IBfE6gAbtp7BCVMxe8VW/F6+Snm5uv9fQ7b07VQHl97gknmHKLyqr7VAx9MDItDoxmYGw/b5TzL0gsdSOd1cvPhQwP6LSLYB336D4FlwGcUNxMjxq57fe/enbKwsDlpcRj0ljfSd5EBc=" Dec 06 15:08:23 volumio go-librespot[28846]: time="2025-12-06T15:08:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:23 volumio go-librespot[28846]: time="2025-12-06T15:08:23-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:23 volumio go-librespot[28846]: time="2025-12-06T15:08:23-06:00" level=debug msg="completed challenge" Dec 06 15:08:23 volumio go-librespot[28846]: time="2025-12-06T15:08:23-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 " Dec 06 15:08:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:23 volumio volumio[28704]: info: Applying required configuration parameters for plugin volusonic Dec 06 15:08:23 volumio volumio[28704]: info: Loading plugin "backup_restore"... Dec 06 15:08:23 volumio volumio[28815]: Starting albumart workers Dec 06 15:08:23 volumio volumio[28817]: Starting albumart workers Dec 06 15:08:23 volumio volumio[28816]: Starting albumart workers Dec 06 15:08:23 volumio volumio[28704]: info: Applying required configuration parameters for plugin backup_restore Dec 06 15:08:23 volumio volumio[28704]: info: Plugin rpi_eeprom_config is not enabled Dec 06 15:08:23 volumio volumio[28704]: info: Plugin rpi_eeprom_updater is not enabled Dec 06 15:08:23 volumio volumio[28704]: info: Loading plugin "scheduledrestart"... Dec 06 15:08:23 volumio volumio[28704]: info: Applying required configuration parameters for plugin scheduledrestart Dec 06 15:08:23 volumio volumio[28704]: info: Plugin Bluetoothremote is not enabled Dec 06 15:08:23 volumio volumio[28704]: info: Plugin music_services_shield is not enabled Dec 06 15:08:24 volumio volumio[28704]: info: Loading plugin "Systeminfo"... Dec 06 15:08:24 volumio volumio[28704]: info: Plugin peppymeterbasic is not enabled Dec 06 15:08:24 volumio volumio[28704]: info: Loading plugin "peppyspectrum"... Dec 06 15:08:24 volumio volumio[28704]: info: Loading i18n strings for locale en Dec 06 15:08:24 volumio volumio[28704]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 06 15:08:24 volumio volumio[28704]: Updating browse sources language Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::initPlayerControls Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:24 volumio volumio[28704]: Express server listening on port 3000 Dec 06 15:08:24 volumio volumio[28704]: [Metrics] WebUI: 14s 762.84ms Dec 06 15:08:24 volumio volumio[28704]: info: CoreStateMachine::resetVolumioState Dec 06 15:08:24 volumio volumio[28704]: info: CoreStateMachine::getcurrentVolume Dec 06 15:08:24 volumio volumio[28704]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:25 volumio sudo[28891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 15:08:25 volumio sudo[28891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio sudo[28893]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 15:08:25 volumio sudo[28893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio sudo[28891]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio sudo[28893]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio volumio[28704]: info: Volumio Network Manager: Network status updated: 1 Dec 06 15:08:25 volumio volumio[28704]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::pushState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioPushState Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::updateTrackBlock Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrackBlock Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:08:25 volumio volumio[28704]: info: Reloading queue from file Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::setRepeat null single undefined Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::pushState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioPushState Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::setRandom null Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::pushState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioPushState Dec 06 15:08:25 volumio volumio[28704]: info: Setting Device type: Raspberry PI Dec 06 15:08:25 volumio volumio[28704]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:08:25 volumio volumio[28704]: info: CoreStateMachine::pushState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioPushState Dec 06 15:08:25 volumio volumio[28704]: info: Completed loading Core Plugins Dec 06 15:08:25 volumio sudo[28907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 06 15:08:25 volumio sudo[28907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio volumio[28704]: info: Preparing to generate the ALSA configuration file Dec 06 15:08:25 volumio volumio[28704]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 06 15:08:25 volumio volumio[28704]: info: Discovery: Found device Volumio Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio sudo[28907]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio volumio[28704]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 06 15:08:25 volumio volumio[28704]: info: Discovery: Found device Volumio Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:25 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:25 volumio volumio[28704]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 06 15:08:25 volumio volumio[28704]: info: Reading ALSA contributions from plugins. Dec 06 15:08:25 volumio volumio[28704]: info: Upmpdcli Daemon Started Dec 06 15:08:25 volumio volumio[28704]: info: Asound.conf file unchanged, so no further update is needed Dec 06 15:08:25 volumio volumio[28704]: info: Output device has changed, restarting MPD Dec 06 15:08:25 volumio volumio[28704]: info: Output device has changed, restarting Shairport Sync Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:25 volumio sudo[28910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:08:25 volumio sudo[28910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio sudo[28910]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio sudo[28912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:08:25 volumio sudo[28912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio volumio[28704]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:08:25 volumio volumio[28704]: info: ___________ START PLUGINS ___________ Dec 06 15:08:25 volumio volumio[28704]: info: ControllerMpd::onStart: Initializing MPD Dec 06 15:08:25 volumio volumio[28704]: info: Creating MPD Configuration file Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:25 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:25 volumio volumio[28704]: info: [1765055305538] CoreMusicLibrary::Adding element Media Servers Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:25 volumio sudo[28922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:08:25 volumio sudo[28922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio sudo[28920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:08:25 volumio sudo[28920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:25 volumio sudo[28920]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio volumio[28704]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:25 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 06 15:08:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 15:08:25 volumio systemd[1]: mpd.service: Consumed 4.112s CPU time. Dec 06 15:08:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 06 15:08:25 volumio volumio[28704]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:08:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 15:08:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:25 volumio volumio[28704]: info: [1765055305653] CoreMusicLibrary::Adding element Last_100 Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:25 volumio volumio[28704]: info: [1765055305658] CoreMusicLibrary::Adding element Webradio Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:08:25 volumio volumio[28704]: info: Initializing BBC Radios Dec 06 15:08:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 15:08:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:25 volumio volumio[28704]: info: [1765055305739] CoreMusicLibrary::Adding element Bandcamp Discover Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:25 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:25 volumio volumio[28704]: info: [1765055305750] CoreMusicLibrary::Adding element SoundCloud Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:25 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:25 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:25 volumio volumio[28704]: info: Creating Spotify config file Dec 06 15:08:25 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:25 volumio sudo[28947]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 15:08:25 volumio sudo[28947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 15:08:25 volumio sudo[28947]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:25 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:25] [connect] Successful connection Dec 06 15:08:26 volumio volumio[28704]: info: [squeezelite_mc] Starting proxy server... Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:26 volumio volumio[28704]: info: [1765055306106] CoreMusicLibrary::Adding element YouTube2 Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:26 volumio volumio[28704]: info: [1765055306124] CoreMusicLibrary::Adding element YouTube Music Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:26 volumio volumio[28704]: info: [1765055306137] CoreMusicLibrary::Adding element Podcast Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Podcast Dec 06 15:08:26 volumio volumio[28704]: info: Loading i18n strings for locale en Dec 06 15:08:26 volumio volumio[28704]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 06 15:08:26 volumio volumio[28704]: Updating browse sources language Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Podcast Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Podcast Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:26 volumio volumio[28704]: info: [1765055306185] CoreMusicLibrary::Adding element Volusonic Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Podcast Dec 06 15:08:26 volumio volumio[28704]: Cannot find translation for source Volusonic Dec 06 15:08:26 volumio volumio[28704]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 06 15:08:26 volumio volumio[28704]: info: Volumio Calling Home Dec 06 15:08:26 volumio volumio[28704]: info: [squeezelite_mc] Proxy server started on port 43597 Dec 06 15:08:26 volumio volumio[28704]: info: Preparing to generate the ALSA configuration file Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:08:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 06 15:08:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:26 volumio volumio[28704]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 06 15:08:26 volumio volumio[28704]: info: Reading ALSA contributions from plugins. Dec 06 15:08:26 volumio volumio[28704]: info: MPD Permissions set Dec 06 15:08:26 volumio volumio[28704]: info: MPD Permissions set Dec 06 15:08:26 volumio go-librespot[28955]: go-librespot daemon starting... Dec 06 15:08:26 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765055305 101 Dec 06 15:08:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:26 volumio volumio[28704]: 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 Dec 06 15:08:26 volumio volumio[28704]: info: Spotify config file written Dec 06 15:08:26 volumio go-librespot[28958]: time="2025-12-06T15:08:26-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:26 volumio go-librespot[28958]: time="2025-12-06T15:08:26-06:00" level=debug msg="app state loaded" Dec 06 15:08:26 volumio go-librespot[28958]: time="2025-12-06T15:08:26-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:26 volumio go-librespot[28958]: time="2025-12-06T15:08:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:26 volumio sudo[28965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 06 15:08:26 volumio sudo[28965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 06 15:08:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 06 15:08:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:26 volumio volumio[28704]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 06 15:08:26 volumio volumio[28704]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:08:26 volumio volumio[28704]: info: CoreStateMachine::pushState Dec 06 15:08:26 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::volumioPushState Dec 06 15:08:26 volumio volumio[28704]: info: [squeezelite_mc] Server discovery started Dec 06 15:08:26 volumio volumio[28704]: info: [squeezelite_mc] Player finder started Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 06 15:08:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio sudo[28965]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:26 volumio go-librespot[28967]: go-librespot daemon starting... Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio go-librespot[28970]: time="2025-12-06T15:08:26-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:26 volumio go-librespot[28970]: time="2025-12-06T15:08:26-06:00" level=debug msg="app state loaded" Dec 06 15:08:26 volumio go-librespot[28970]: time="2025-12-06T15:08:26-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:26 volumio go-librespot[28970]: time="2025-12-06T15:08:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:26 volumio volumio[28704]: info: No need to fix Spotify hosts Dec 06 15:08:26 volumio volumio[28704]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 06 15:08:26 volumio volumio[28704]: info: Volumio called home Dec 06 15:08:27 volumio volumio[28704]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-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]" Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-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]" Dec 06 15:08:27 volumio volumio[28704]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 06 15:08:27 volumio volumio[28704]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 06 15:08:27 volumio volumio[28704]: 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 Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=info msg="zeroconf server listening on port 34321" Dec 06 15:08:27 volumio volumio[28704]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 06 15:08:27 volumio volumio[28704]: SPOTIFY: BQBUvzolqnV7BMBiddM5H_62r76mGvwCRbDtk-2DIdmnhYv0yIE2ErBJr0BtarMLLyMkO2A_WFNTzBud_D3CIKIUFYRzmeMvinzxYe5Q7o4t88PjCIzCsyDZ5FilCMjWjfeJoJVPD2v5ElewbOV6LkDZPqKQA06ReNCWjjYb04BLpoANP-LDz_39T5NQxbC3IiGeUsaxgCigscUVTuOqE0H_HxkgOF2GptJnGaM Dec 06 15:08:27 volumio volumio[28704]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 06 15:08:27 volumio volumio[28704]: info: New Spotify access token = BQBUvzolqnV7BMBiddM5H_62r76mGvwCRbDtk-2DIdmnhYv0yIE2ErBJr0BtarMLLyMkO2A_WFNTzBud_D3CIKIUFYRzmeMvinzxYe5Q7o4t88PjCIzCsyDZ5FilCMjWjfeJoJVPD2v5ElewbOV6LkDZPqKQA06ReNCWjjYb04BLpoANP-LDz_39T5NQxbC3IiGeUsaxgCigscUVTuOqE0H_HxkgOF2GptJnGaM Dec 06 15:08:27 volumio volumio[28704]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 06 15:08:27 volumio volumio[28704]: info: Starting Shairport Sync Dec 06 15:08:27 volumio volumio[28704]: info: Starting Shairport Sync Dec 06 15:08:27 volumio volumio[28704]: info: Starting Shairport Sync Dec 06 15:08:27 volumio sudo[28991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:08:27 volumio sudo[28991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=debug msg="obtained new client token: AABwyz2mO7lJIjGAHokVdtvRIs5MUkxMshy5lmuVfLDOSV5OAhlq/saAVx5YRoVZxeDr29W2NtQQWaMxN9iWRkl4nLloZcJeAf+Jl/78+I0hsiXB4Tp9gh2OKu5jH7VYnvcPvw0v0gAYaoJ/htlnKksmkIO3ahXmLdxavWKoUeddrPKeiZ7m8a6NOAlueRceiviLuD1X2y0WElGoY8a08RWNN6CfjoBhPhJrgBlYVHJJnk4C2kTw/58=" Dec 06 15:08:27 volumio sudo[28994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:08:27 volumio sudo[28994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio sudo[28996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:08:27 volumio sudo[28996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:27 volumio sudo[28989]: 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 Dec 06 15:08:27 volumio sudo[28989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio sudo[28989]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-06:00" level=debug msg="completed challenge" Dec 06 15:08:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 15:08:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 15:08:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:08:27 volumio systemd[1]: shairport-sync.service: Consumed 2.043s CPU time. Dec 06 15:08:27 volumio volumio[28704]: info: Asound.conf file unchanged, so no further update is needed Dec 06 15:08:27 volumio volumio[28704]: info: Output device has changed, restarting MPD Dec 06 15:08:27 volumio go-librespot[28970]: time="2025-12-06T15:08:27-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 " Dec 06 15:08:27 volumio volumio[28704]: info: Output device has changed, restarting Shairport Sync Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:27 volumio sudo[29002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:08:27 volumio sudo[29002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio sudo[29004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:08:27 volumio sudo[29004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio sudo[29002]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:08:27 volumio sudo[28991]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio sudo[28996]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:27 volumio volumio[28704]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:08:27 volumio sudo[28994]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 06 15:08:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 15:08:27 volumio systemd[1]: mpd.service: Consumed 1.671s CPU time. Dec 06 15:08:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 06 15:08:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 15:08:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 15:08:27 volumio volumio[28704]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 06 15:08:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 15:08:27 volumio sudo[29031]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 06 15:08:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 15:08:27 volumio sudo[29031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio sudo[29031]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio volumio[28704]: info: MPD Permissions set Dec 06 15:08:27 volumio volumio[28704]: info: Shairport-Sync Started Dec 06 15:08:27 volumio volumio[28704]: Error adding Membership: Error: addMembership EINVAL Dec 06 15:08:27 volumio volumio[28704]: info: Shairport-Sync Started Dec 06 15:08:27 volumio volumio[28704]: info: Shairport-Sync Started Dec 06 15:08:27 volumio volumio[28704]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:27 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:27 volumio sudo[29032]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 15:08:27 volumio volumio[28704]: info: Starting Shairport Sync Dec 06 15:08:27 volumio sudo[29032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 15:08:27 volumio sudo[29032]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio sudo[29037]: 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 Dec 06 15:08:27 volumio sudo[29037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio volumio[28704]: 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"} Dec 06 15:08:27 volumio sudo[29037]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:27 volumio volumio[28704]: info: Spotify Successfully logged in Dec 06 15:08:27 volumio sudo[29045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:08:27 volumio sudo[29045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:08:27 volumio volumio[28704]: info: [1765055307956] CoreMusicLibrary::Adding element Spotify Dec 06 15:08:27 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source Bandcamp Discover Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source SoundCloud Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source YouTube2 Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source YouTube Music Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source Podcast Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source Volusonic Dec 06 15:08:27 volumio volumio[28704]: Cannot find translation for source Spotify Dec 06 15:08:28 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 06 15:08:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 15:08:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 15:08:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:08:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:08:28 volumio sudo[29050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 06 15:08:28 volumio sudo[29050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:28 volumio sudo[29045]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:28 volumio systemd[1]: Reloading. Dec 06 15:08:28 volumio volumio[28704]: info: Shairport-Sync Started Dec 06 15:08:28 volumio volumio[28704]: info: [squeezelite_mc] Notification listener started Dec 06 15:08:28 volumio volumio[28704]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 06 15:08:28 volumio volumio[28704]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 06 15:08:28 volumio volumio[28704]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 06 15:08:28 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:29 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:29 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:29 volumio volumio[28704]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:29 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:29 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:30 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. Dec 06 15:08:30 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. Dec 06 15:08:30 volumio volumio[28704]: info: go-librespot daemon successfully initialized Dec 06 15:08:30 volumio sudo[29050]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:30 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:30 volumio sudo[29085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:30 volumio sudo[29085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:30 volumio sudo[29085]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:30 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 06 15:08:30 volumio sudo[29090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 06 15:08:30 volumio sudo[29090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:30 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 06 15:08:30 volumio volumio[28704]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 06 15:08:30 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:30 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 06 15:08:30 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 06 15:08:30 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 06 15:08:30 volumio sudo[29090]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:30 volumio go-librespot[29092]: go-librespot daemon starting... Dec 06 15:08:30 volumio go-librespot[29093]: time="2025-12-06T15:08:30-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:30 volumio go-librespot[29093]: time="2025-12-06T15:08:30-06:00" level=debug msg="app state loaded" Dec 06 15:08:30 volumio go-librespot[29093]: time="2025-12-06T15:08:30-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:30 volumio go-librespot[29093]: time="2025-12-06T15:08:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-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]" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-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]" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=info msg="zeroconf server listening on port 37471" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=debug msg="obtained new client token: AAADqTzxp6qscwJ7OzfNfr1JDAXw268eMLnRonsJKnwvNFM7MC+oL7MZRNxfazILgZsbbrq27coYsCYMIfwUIL5+tdpycdbtjc/uWZdQVWY/7kma4VRyJ0cvaUmPLYPXUO6tmci46w2Dp4v1olj3l0kiPMs/5PRVq78JUtBfOwRHpoxX6vxdJSqjgGtBA8YsRzZAhqE2L7yf9AwIX8JUGG/oD3u1yYxE8A4FwlORZJk3J4cfKR/xYO4=" Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:31 volumio sudo[29101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:31 volumio sudo[29101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-06:00" level=debug msg="completed challenge" Dec 06 15:08:31 volumio sudo[29101]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 06 15:08:31 volumio go-librespot[29093]: time="2025-12-06T15:08:31-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 " Dec 06 15:08:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:31 volumio sudo[29105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 06 15:08:31 volumio sudo[29105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:31 volumio sudo[29105]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 06 15:08:31 volumio sudo[29108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 06 15:08:31 volumio sudo[29108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:31 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 06 15:08:31 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 06 15:08:31 volumio sudo[29108]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 06 15:08:31 volumio volumio[28704]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 06 15:08:31 volumio mpd[29046]: 2025-12-06T15:08:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 15:08:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 15:08:31 volumio sudo[28912]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:31 volumio sudo[29004]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:31 volumio sudo[28922]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:32 volumio volumio[28704]: error: MPD error: The expression evaluated to a falsy value: Dec 06 15:08:32 volumio volumio[28704]: assert.ok(self.idling) Dec 06 15:08:32 volumio volumio[28704]: error: The expression evaluated to a falsy value: Dec 06 15:08:32 volumio volumio[28704]: assert.ok(self.idling) Dec 06 15:08:32 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:32 volumio volumio[28704]: error: MPD error: The expression evaluated to a falsy value: Dec 06 15:08:32 volumio volumio[28704]: assert.ok(self.idling) Dec 06 15:08:32 volumio volumio[28704]: error: The expression evaluated to a falsy value: Dec 06 15:08:32 volumio volumio[28704]: assert.ok(self.idling) Dec 06 15:08:32 volumio volumio[28704]: info: MPD running with PID29046 Dec 06 15:08:32 volumio volumio[28704]: ,establishing connection Dec 06 15:08:32 volumio volumio[28704]: error: updateQueue error: null Dec 06 15:08:32 volumio volumio[28704]: error: updateQueue error: null Dec 06 15:08:32 volumio sudo[29120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:32 volumio sudo[29120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:32 volumio sudo[29120]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:32 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:32 volumio sudo[29123]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:32 volumio sudo[29123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:32 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:32 volumio sudo[29123]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:32 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:33 volumio volumio[28704]: info: Initializing connection to go-librespot Websocket Dec 06 15:08:33 volumio volumio[28704]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:08:33 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:33 volumio sudo[29140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:33 volumio sudo[29140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:33 volumio sudo[29140]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:33 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:33 volumio sudo[29143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:33 volumio sudo[29143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:33 volumio sudo[29143]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:34 volumio volumio[28704]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:08:34 volumio sudo[29146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:08:34 volumio sudo[29146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 06 15:08:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:34 volumio go-librespot[29148]: go-librespot daemon starting... Dec 06 15:08:34 volumio sudo[29146]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=debug msg="app state loaded" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:34 volumio volumio[28704]: info: Completed starting Core Plugins Dec 06 15:08:34 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:34 volumio volumio[28704]: info: ----- MyVolumio plugins startup ---- Dec 06 15:08:34 volumio volumio[28704]: info: ------------------------------------------- Dec 06 15:08:34 volumio volumio[28704]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08: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]" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08: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]" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08: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]" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=info msg="zeroconf server listening on port 41351" Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=debug msg="obtained new client token: AABUIJizwnFhna2c5YDviAhG6mYMut4xzJO0hMWhmOsJtkn201KUUxmyJD2l0ldU0dvQnfSaFpmuq850abg4hKR9rCV3eODWyJrFQNBuuGVZDDqTwPhoOZ89C0mniQjr1/+R+4f6IYLaE0MfX2FKco24QuR7EiGwalz14IauaBto4PLGmOD16QI2xsGao+ZVoBP/ERz5tQam2uNkxAph3SJf61O2NfTqZeSzEwk5UdlMahUOZJq1bcuscw==" Dec 06 15:08:34 volumio sudo[29157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:08:34 volumio sudo[29157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:34 volumio sudo[29159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:08:34 volumio sudo[29159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:34 volumio sudo[29161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:08:34 volumio sudo[29161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:34 volumio go-librespot[29149]: time="2025-12-06T15:08:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:34 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 06 15:08:34 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 06 15:08:34 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 06 15:08:35 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 06 15:08:35 volumio sudo[29157]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:35 volumio mpd_monitor.sh[29165]: MPD Monitor Service: Starting MPD Monitor Service Dec 06 15:08:35 volumio sudo[29159]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:35 volumio sudo[29161]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:35 volumio volumio[28704]: info: Successfully started MPD Monitor Dec 06 15:08:35 volumio volumio[28704]: info: Successfully started MPD Monitor Dec 06 15:08:35 volumio volumio[28704]: info: Successfully started MPD Monitor Dec 06 15:08:36 volumio volumio[28704]: info: Initializing connection to go-librespot Websocket Dec 06 15:08:36 volumio go-librespot[29149]: time="2025-12-06T15:08:36-06:00" level=debug msg="new websocket client" Dec 06 15:08:36 volumio volumio[28704]: info: Connection to go-librespot Websocket established Dec 06 15:08:39 volumio volumio[28704]: info: Getting Spotify volume Dec 06 15:08:39 volumio volumio[28704]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 06 15:08:39 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:39 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:39 volumio volumio[28704]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 06 15:08:39 volumio volumio[28704]: SPOTIFY: SPOTIFY VOLUME undefined Dec 06 15:08:39 volumio volumio[28704]: SPOTIFY: VOLUMIO VOLUME 86 Dec 06 15:08:39 volumio volumio[28704]: info: Aligning Spotify Volume to Volumio Volume Dec 06 15:08:39 volumio volumio[28704]: info: CoreCommandRouter::volumioGetState Dec 06 15:08:39 volumio volumio[28704]: info: CorePlayQueue::getTrack 0 Dec 06 15:08:39 volumio volumio[28704]: info: Setting Spotify Volume from Volumio: 86 Dec 06 15:08:41 volumio volumio[28704]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Dec 06 15:08:41 volumio volumio[28704]: info: Sending Spotify command with payload to local API: /player/volume Dec 06 15:08:41 volumio go-librespot[29149]: time="2025-12-06T15:08:41-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:41 volumio go-librespot[29149]: time="2025-12-06T15:08:41-06:00" level=debug msg="completed challenge" Dec 06 15:08:41 volumio go-librespot[29149]: time="2025-12-06T15:08:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed peeking unencrypted bytes: failed peeking uncrypted: read tcp 192.168.1.221:56294->104.154.127.247:4070: read: connection reset by peer" Dec 06 15:08:41 volumio volumio[28704]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 06 15:08:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:41 volumio volumio[28704]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:08:41 volumio volumio[28704]: Error: socket hang up Dec 06 15:08:41 volumio volumio[28704]: at connResetException (node:internal/errors:720:14) Dec 06 15:08:41 volumio volumio[28704]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 06 15:08:41 volumio volumio[28704]: at Socket.emit (node:events:526:35) Dec 06 15:08:41 volumio volumio[28704]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 06 15:08:41 volumio volumio[28704]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 06 15:08:41 volumio volumio[28704]: code: 'ECONNRESET', Dec 06 15:08:41 volumio volumio[28704]: response: undefined Dec 06 15:08:41 volumio volumio[28704]: } Dec 06 15:08:41 volumio volumio[28704]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:08:42 volumio sudo[29184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 15:07' Dec 06 15:08:42 volumio sudo[29184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:42 volumio sudo[29184]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:43 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 06 15:08:43 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 06 15:08:43 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:43 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 06 15:08:43 volumio systemd[1]: volumio.service: Consumed 42.758s CPU time. Dec 06 15:08:43 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 15:08:43 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 15:08:43 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21106. Dec 06 15:08:43 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 15:08:43 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 06 15:08:43 volumio systemd[1]: volumio.service: Consumed 42.758s CPU time. Dec 06 15:08:43 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 06 15:08:43 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 15:08:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 06 15:08:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:44 volumio go-librespot[29232]: go-librespot daemon starting... Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="app state loaded" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-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]" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-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]" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-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]" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=info msg="zeroconf server listening on port 37337" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="obtained new client token: AAB3WZaJfcU6AEF4NrBiCarEqkzIO2Vx7FzhN7IF+3ob67Fv8f2mLrOvY8qlBP6ahCidDaEVPzRPjwxU3gEmbrKj5wT6bYpoFXzQQWZesmDzCcJGSdvpWkpshGwidvNcXvdsrbz/HyT2X149fxA25c3qKqRfqV7YzcCVMttepUHDk+s9IZL1puCdN6DqS3SV0eBQvz56fp1g7t+0nvO6SQGJpDV/hSxlWJGFSpRigWy6zru9BsDnBCXehw==" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=debug msg="completed challenge" Dec 06 15:08:45 volumio go-librespot[29233]: time="2025-12-06T15:08:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:45 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:08:45 volumio volumio[29217]: info: ----- Volumio3 ---- Dec 06 15:08:45 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:08:45 volumio volumio[29217]: info: ----- System startup ---- Dec 06 15:08:45 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:08:46 volumio volumio[29217]: info: MYVOLUMIO Environment detected Dec 06 15:08:46 volumio volumio[29217]: info: Plugin folders cleanup Dec 06 15:08:46 volumio volumio[29217]: info: Scanning into folder /volumio/app/plugins/ Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category audio_interface Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category miscellanea Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category music_service Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category plugins.json Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category system_controller Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category user_interface Dec 06 15:08:46 volumio volumio[29217]: info: Scanning into folder /data/plugins/ Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category audio_interface Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category music_service Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category system_controller Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category system_hardware Dec 06 15:08:46 volumio volumio[29217]: info: Scanning category user_interface Dec 06 15:08:46 volumio volumio[29217]: info: Plugin folders cleanup completed Dec 06 15:08:46 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:08:46 volumio volumio[29217]: info: ----- Core plugins startup ---- Dec 06 15:08:46 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:08:46 volumio volumio[29217]: info: Loading plugins from folder /volumio/app/plugins/ Dec 06 15:08:46 volumio volumio[29217]: info: Adding plugin upnp to MyMusic Plugins Dec 06 15:08:46 volumio volumio[29217]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 06 15:08:46 volumio volumio[29217]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 06 15:08:46 volumio volumio[29217]: info: Loading plugins from folder /data/plugins/ Dec 06 15:08:46 volumio volumio[29217]: info: Loading plugin "system"... Dec 06 15:08:46 volumio volumio[29217]: info: Loading plugin "appearance"... Dec 06 15:08:47 volumio volumio[29217]: info: Loading plugin "network"... Dec 06 15:08:47 volumio volumio[29217]: info: Refreshing Cached IP Addresses Dec 06 15:08:47 volumio sudo[29253]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 15:08:47 volumio sudo[29253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:47 volumio sudo[29255]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 15:08:47 volumio sudo[29255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:47 volumio volumio[29217]: info: Loading plugin "services"... Dec 06 15:08:47 volumio sudo[29255]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:47 volumio volumio[29217]: info: Loading plugin "alsa_controller"... Dec 06 15:08:47 volumio sudo[29253]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:47 volumio sudo[29262]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 06 15:08:47 volumio sudo[29262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:48 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "wizard"... Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "networkfs"... Dec 06 15:08:48 volumio volumio[29217]: info: Starting Udev Watcher for removable devices Dec 06 15:08:48 volumio volumio[29217]: info: Ignoring mount for partition: boot Dec 06 15:08:48 volumio volumio[29217]: info: Ignoring mount for partition: volumio Dec 06 15:08:48 volumio volumio[29217]: info: Ignoring mount for partition: volumio_data Dec 06 15:08:48 volumio volumio[29217]: info: Mounting Device Wikipedia Dec 06 15:08:48 volumio sudo[29292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 06 15:08:48 volumio sudo[29292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:48 volumio sudo[29292]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:48 volumio volumio[29217]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 06 15:08:48 volumio volumio[29217]: dmesg(1) may have more information after failed mount system call. Dec 06 15:08:48 volumio volumio[29217]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 06 15:08:48 volumio volumio[29217]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 06 15:08:48 volumio volumio[29217]: dmesg(1) may have more information after failed mount system call. Dec 06 15:08:48 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "volumio_command_line_client"... Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "upnp"... Dec 06 15:08:48 volumio volumio[29217]: info: [1765055328192] Starting Upmpd Daemon Dec 06 15:08:48 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "my_music"... Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "mpd"... Dec 06 15:08:48 volumio sudo[29262]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:48 volumio volumio[29217]: info: Loading plugin "upnp_browser"... Dec 06 15:08:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 06 15:08:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:48 volumio go-librespot[29294]: go-librespot daemon starting... Dec 06 15:08:48 volumio go-librespot[29295]: time="2025-12-06T15:08:48-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:48 volumio go-librespot[29295]: time="2025-12-06T15:08:48-06:00" level=debug msg="app state loaded" Dec 06 15:08:48 volumio go-librespot[29295]: time="2025-12-06T15:08:48-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:48 volumio go-librespot[29295]: time="2025-12-06T15:08:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:48 volumio volumio-remote-updater[2353]: [2025-12-06 15:08:48] [connect] Successful connection Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-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]" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-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]" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=info msg="zeroconf server listening on port 40081" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=debug msg="obtained new client token: AADLeK/lgMkY6SY1nq9EcJnhRbwpuE4etfTE5kDvklr+eE6Q4IWPtDfET6shreb84DiOjl+pt1nG5oUvlJZ54eKcQXY22EU4OW/zIWINgoFOMXHc2t9LWYSgV0XPNoYcoYrs5bOmM5ZB3g77kIJd52EVk7xTsQ0Y2JHrJsKiEZQBwQUt5xMSvqYAmpJBpozbUbBW6+4IWh+rPHPTZR69SPCKQBQfJu+YVuKy+GBeepAWhf5WYQKhEDg=" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=debug msg="completed challenge" Dec 06 15:08:49 volumio go-librespot[29295]: time="2025-12-06T15:08:49-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "alarm-clock"... Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "airplay_emulation"... Dec 06 15:08:50 volumio volumio[29217]: info: Starting Shairport Sync Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "last_100"... Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "webradio"... Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "i2s_dacs"... Dec 06 15:08:50 volumio volumio[29217]: info: I2S DAC not set, start Auto-detection Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "volumiodiscovery"... Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:50 volumio node[29217]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:50 volumio node[29217]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** For more information see Dec 06 15:08:50 volumio node[29217]: *** WARNING *** For more information see Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:50 volumio node[29217]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:50 volumio node[29217]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 15:08:50 volumio volumio[29217]: *** WARNING *** For more information see Dec 06 15:08:50 volumio node[29217]: *** WARNING *** For more information see Dec 06 15:08:50 volumio volumio[29217]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 06 15:08:50 volumio volumio[29217]: info: Discovery: Started advertising with name: Volumio Dec 06 15:08:50 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 15:08:50 volumio volumio[29217]: info: Loading plugin "bandcamp"... Dec 06 15:08:51 volumio volumio[29217]: info: Plugin calmradio is not enabled Dec 06 15:08:51 volumio volumio[29217]: info: Loading plugin "soundcloud"... Dec 06 15:08:52 volumio volumio[29217]: info: Loading plugin "spop"... Dec 06 15:08:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 06 15:08:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:52 volumio go-librespot[29304]: go-librespot daemon starting... Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=debug msg="app state loaded" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-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]" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-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]" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=info msg="zeroconf server listening on port 41499" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=debug msg="obtained new client token: AADBjajftcNtR6ZKa3zx6BT45ESrG13v+TkiW39VK0EdrP1MbdDzrVrriEIEyRUrsmwN3DFITATpmV/2Nf1ReALRmvRTm4OZFwkuAbdRAMNgfKMpBMWvjRmfOzK1kEliDq3qSYzJPLybzwYQpuNhjOycHzW6I7PNHUePLQ0uN1ycemNP5SfRplMiD/gecKj8DbqSL/Kqdbh79UhFVja9aOq0Hgizp+fZh5SAXtYyXURHMFiaQUKRX7cy/g==" Dec 06 15:08:52 volumio go-librespot[29305]: time="2025-12-06T15:08:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:53 volumio go-librespot[29305]: time="2025-12-06T15:08:53-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:53 volumio go-librespot[29305]: time="2025-12-06T15:08:53-06:00" level=debug msg="completed challenge" Dec 06 15:08:53 volumio volumio[29217]: info: Loading plugin "squeezelite_mc"... Dec 06 15:08:53 volumio go-librespot[29305]: time="2025-12-06T15:08:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:08:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:53 volumio volumio[29217]: info: Loading plugin "youtube2"... Dec 06 15:08:54 volumio volumio[29217]: info: Loading plugin "ytcr"... Dec 06 15:08:55 volumio volumio[29217]: info: Loading plugin "ytmusic"... Dec 06 15:08:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 06 15:08:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:56 volumio volumio[29217]: info: Plugin now_playing is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "outputs"... Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "albumart"... Dec 06 15:08:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:08:56 volumio go-librespot[29315]: go-librespot daemon starting... Dec 06 15:08:56 volumio volumio[29217]: info: Plugin example_plugin is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "inputs"... Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "updater_comm"... Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="app state loaded" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="stored credentials not found" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:08:56 volumio volumio[29217]: info: Plugin mpdemulation is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "rest_api"... Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "websocket"... Dec 06 15:08:56 volumio volumio[29217]: info: Starting Socket.io Server version 1.7.4 Dec 06 15:08:56 volumio volumio[29217]: info: Plugin fusiondsp is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Plugin mpdoutput is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Plugin RoonBridge is not enabled Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "podcast"... Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-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]" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-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]" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-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]" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=info msg="zeroconf server listening on port 34891" Dec 06 15:08:56 volumio volumio[29217]: info: ControllerPodcast::constructor Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="obtained new client token: AAD/VsULoDWf8bynsxNbbMiTiJ7SbiC+YFMbV2rhLwwoFIdkP2NvQ01JsF2efooQJEBFse7GUszAFYspSV5WZpnrq7gCwDjF1Y1LW98jhaJvy4yGIS3v9AHy+FKJRn4yOFlTMwmk+O5glueBLuYqGpLw/gkG4e5+FBPYSEHzcam6OI7wmUC8R7O/Y/DwWTi0KZAY/IjlzZM6xHuoX6wgxWmTCCEvh+JQzUtNMKkli1yWKiMDS66ntFRtYA==" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:08:56 volumio volumio[29217]: info: Loading plugin "volusonic"... Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="completed keyexchange" Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-06:00" level=debug msg="completed challenge" Dec 06 15:08:56 volumio volumio[29316]: Forking 3 albumart workers Dec 06 15:08:56 volumio go-librespot[29317]: time="2025-12-06T15:08:56-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 " Dec 06 15:08:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:08:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:08:58 volumio volumio[29217]: info: Applying required configuration parameters for plugin volusonic Dec 06 15:08:58 volumio volumio[29217]: info: Loading plugin "backup_restore"... Dec 06 15:08:58 volumio volumio[29334]: Starting albumart workers Dec 06 15:08:58 volumio volumio[29336]: Starting albumart workers Dec 06 15:08:58 volumio volumio[29217]: info: Applying required configuration parameters for plugin backup_restore Dec 06 15:08:58 volumio volumio[29217]: info: Plugin rpi_eeprom_config is not enabled Dec 06 15:08:58 volumio volumio[29217]: info: Plugin rpi_eeprom_updater is not enabled Dec 06 15:08:58 volumio volumio[29217]: info: Loading plugin "scheduledrestart"... Dec 06 15:08:58 volumio volumio[29335]: Starting albumart workers Dec 06 15:08:58 volumio volumio[29217]: info: Applying required configuration parameters for plugin scheduledrestart Dec 06 15:08:58 volumio volumio[29217]: info: Plugin Bluetoothremote is not enabled Dec 06 15:08:58 volumio volumio[29217]: info: Plugin music_services_shield is not enabled Dec 06 15:08:58 volumio volumio[29217]: info: Loading plugin "Systeminfo"... Dec 06 15:08:59 volumio volumio[29217]: info: Plugin peppymeterbasic is not enabled Dec 06 15:08:59 volumio volumio[29217]: info: Loading plugin "peppyspectrum"... Dec 06 15:08:59 volumio volumio[29217]: info: Loading i18n strings for locale en Dec 06 15:08:59 volumio volumio[29217]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 06 15:08:59 volumio volumio[29217]: Updating browse sources language Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::initPlayerControls Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:08:59 volumio volumio[29217]: Express server listening on port 3000 Dec 06 15:08:59 volumio volumio[29217]: [Metrics] WebUI: 14s 365.04ms Dec 06 15:08:59 volumio volumio[29217]: info: CoreStateMachine::resetVolumioState Dec 06 15:08:59 volumio volumio[29217]: info: CoreStateMachine::getcurrentVolume Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:08:59 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:08:59 volumio sudo[29402]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 15:08:59 volumio sudo[29402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:59 volumio sudo[29402]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:59 volumio sudo[29404]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 15:08:59 volumio sudo[29404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:08:59 volumio sudo[29404]: pam_unix(sudo:session): session closed for user root Dec 06 15:08:59 volumio volumio[29217]: info: Volumio Network Manager: Network status updated: 1 Dec 06 15:08:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 06 15:08:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:00 volumio go-librespot[29409]: go-librespot daemon starting... Dec 06 15:09:00 volumio volumio[29217]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::pushState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="app state loaded" Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="stored credentials not found" Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioPushState Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::updateTrackBlock Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrackBlock Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:09:00 volumio volumio[29217]: info: Reloading queue from file Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::setRepeat null single undefined Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::pushState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioPushState Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::setRandom null Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::pushState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioPushState Dec 06 15:09:00 volumio volumio[29217]: info: Setting Device type: Raspberry PI Dec 06 15:09:00 volumio volumio[29217]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:09:00 volumio volumio[29217]: info: CoreStateMachine::pushState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioPushState Dec 06 15:09:00 volumio sudo[29425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 06 15:09:00 volumio sudo[29425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:00 volumio volumio[29217]: info: Completed loading Core Plugins Dec 06 15:09:00 volumio volumio[29217]: info: Preparing to generate the ALSA configuration file Dec 06 15:09:00 volumio sudo[29425]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:00 volumio volumio[29217]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 06 15:09:00 volumio volumio[29217]: info: Discovery: Found device Volumio Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio volumio[29217]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 06 15:09:00 volumio volumio[29217]: info: Discovery: Found device Volumio Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:00 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:00 volumio volumio[29217]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 06 15:09:00 volumio volumio[29217]: info: Reading ALSA contributions from plugins. Dec 06 15:09:00 volumio volumio[29217]: info: Upmpdcli Daemon Started Dec 06 15:09:00 volumio volumio[29217]: info: Asound.conf file unchanged, so no further update is needed Dec 06 15:09:00 volumio volumio[29217]: info: Output device has changed, restarting MPD Dec 06 15:09:00 volumio volumio[29217]: info: Output device has changed, restarting Shairport Sync Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:00 volumio sudo[29430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:09:00 volumio sudo[29430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-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]" Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-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]" Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-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]" Dec 06 15:09:00 volumio sudo[29432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:09:00 volumio sudo[29432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:00 volumio sudo[29430]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=info msg="zeroconf server listening on port 33221" Dec 06 15:09:00 volumio volumio[29217]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:09:00 volumio volumio[29217]: info: ___________ START PLUGINS ___________ Dec 06 15:09:00 volumio volumio[29217]: info: ControllerMpd::onStart: Initializing MPD Dec 06 15:09:00 volumio volumio[29217]: info: Creating MPD Configuration file Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:00 volumio volumio[29217]: info: [1765055340400] CoreMusicLibrary::Adding element Media Servers Dec 06 15:09:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:00 volumio sudo[29440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:09:00 volumio sudo[29440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:00 volumio sudo[29440]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:00 volumio sudo[29442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:09:00 volumio sudo[29442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="obtained new client token: AAD9lD/QJ82S/XQgwREy2x0GWIoToWT5RnoNb0xR1i7c2YPbnhtIQzHDfqFPp+N/2dCvGowYMc5n/MC0zqEeoCwOQESkPo8rO48EueSAJwY4Nr0bvYfTMsY/KhiMyUBZukZnA+1LZbgOzyqGZ3I/TxKPOcZLu/mUYNM4N3kbAHlL8Inj67lLMy2sJcsunkfUyRVZ3lyMagzBXboNbIncN60WTZ/LLN5/fHqE2oqEeo3ZjSZgqNLwEYfGaw==" Dec 06 15:09:00 volumio volumio[29217]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:00 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 06 15:09:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 15:09:00 volumio systemd[1]: mpd.service: Consumed 4.542s CPU time. Dec 06 15:09:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 06 15:09:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 15:09:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 15:09:00 volumio volumio[29217]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:00 volumio volumio[29217]: info: [1765055340536] CoreMusicLibrary::Adding element Last_100 Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:00 volumio volumio[29217]: info: [1765055340540] CoreMusicLibrary::Adding element Webradio Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:09:00 volumio volumio[29217]: info: Initializing BBC Radios Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:09:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 15:09:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="completed keyexchange" Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=debug msg="completed challenge" Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:00 volumio volumio[29217]: info: [1765055340634] CoreMusicLibrary::Adding element Bandcamp Discover Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:00 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:00 volumio volumio[29217]: info: [1765055340645] CoreMusicLibrary::Adding element SoundCloud Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:00 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:00 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:00 volumio go-librespot[29410]: time="2025-12-06T15:09:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:09:00 volumio volumio[29217]: info: Creating Spotify config file Dec 06 15:09:00 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:09:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:09:00 volumio sudo[29463]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 15:09:00 volumio sudo[29463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 15:09:00 volumio sudo[29463]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Starting proxy server... Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:01 volumio volumio[29217]: info: [1765055341028] CoreMusicLibrary::Adding element YouTube2 Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:01 volumio volumio[29217]: info: [1765055341046] CoreMusicLibrary::Adding element YouTube Music Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:01 volumio volumio[29217]: info: [1765055341059] CoreMusicLibrary::Adding element Podcast Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Podcast Dec 06 15:09:01 volumio volumio[29217]: info: Loading i18n strings for locale en Dec 06 15:09:01 volumio volumio[29217]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 06 15:09:01 volumio volumio[29217]: Updating browse sources language Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Podcast Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Podcast Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:01 volumio volumio[29217]: info: [1765055341107] CoreMusicLibrary::Adding element Volusonic Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Podcast Dec 06 15:09:01 volumio volumio[29217]: Cannot find translation for source Volusonic Dec 06 15:09:01 volumio volumio[29217]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 06 15:09:01 volumio volumio[29217]: info: Volumio Calling Home Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Proxy server started on port 33781 Dec 06 15:09:01 volumio volumio[29217]: info: Preparing to generate the ALSA configuration file Dec 06 15:09:01 volumio volumio-remote-updater[2353]: [2025-12-06 15:09:01] [connect] Successful connection Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 15:09:01 volumio volumio[29217]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 06 15:09:01 volumio volumio[29217]: info: Reading ALSA contributions from plugins. Dec 06 15:09:01 volumio volumio[29217]: info: MPD Permissions set Dec 06 15:09:01 volumio volumio[29217]: info: MPD Permissions set Dec 06 15:09:01 volumio volumio-remote-updater[2353]: [2025-12-06 15:09:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765055341 101 Dec 06 15:09:01 volumio volumio[29217]: 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 Dec 06 15:09:01 volumio volumio[29217]: info: Spotify config file written Dec 06 15:09:01 volumio sudo[29477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 06 15:09:01 volumio sudo[29477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:01 volumio volumio[29217]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 06 15:09:01 volumio volumio[29217]: info: VolumeController:: Volume=86 Mute =false Dec 06 15:09:01 volumio volumio[29217]: info: CoreStateMachine::pushState Dec 06 15:09:01 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::volumioPushState Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Server discovery started Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Player finder started Dec 06 15:09:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio go-librespot[29479]: go-librespot daemon starting... Dec 06 15:09:01 volumio sudo[29477]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=debug msg="app state loaded" Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=debug msg="stored credentials not found" Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:01 volumio volumio[29217]: info: No need to fix Spotify hosts Dec 06 15:09:01 volumio volumio[29217]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 06 15:09:01 volumio volumio[29217]: info: Volumio called home Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-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]" Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-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]" Dec 06 15:09:01 volumio volumio[29217]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 06 15:09:01 volumio volumio[29217]: SPOTIFY: BQAkDymyPFUYuenx1fnJEtipfI7Al8sc8uLPHlF5seavY0gVTxQB5vakRAI6LR9I3kCDemM51JrT0irIiOCbevjy1kLFn2wPfHj2KozBpszXFUJE74gzsRtN9qcYx_U1cJLYruKsum8OI3wUP2Bsnw7cvP66rstjWbC7FWZ5KseX3uh2qHVS7T6mxNn3zLVEcl7utOKLvao67gUbsAdLrmkuZFdxj_YA9x3S-dg Dec 06 15:09:01 volumio volumio[29217]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 06 15:09:01 volumio volumio[29217]: info: New Spotify access token = BQAkDymyPFUYuenx1fnJEtipfI7Al8sc8uLPHlF5seavY0gVTxQB5vakRAI6LR9I3kCDemM51JrT0irIiOCbevjy1kLFn2wPfHj2KozBpszXFUJE74gzsRtN9qcYx_U1cJLYruKsum8OI3wUP2Bsnw7cvP66rstjWbC7FWZ5KseX3uh2qHVS7T6mxNn3zLVEcl7utOKLvao67gUbsAdLrmkuZFdxj_YA9x3S-dg Dec 06 15:09:01 volumio volumio[29217]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 06 15:09:01 volumio go-librespot[29480]: time="2025-12-06T15:09:01-06:00" level=info msg="zeroconf server listening on port 38415" Dec 06 15:09:01 volumio volumio[29217]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 06 15:09:02 volumio volumio[29217]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 06 15:09:02 volumio volumio[29217]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 06 15:09:02 volumio volumio[29217]: 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 Dec 06 15:09:02 volumio go-librespot[29480]: time="2025-12-06T15:09:02-06:00" level=debug msg="obtained new client token: AABINNrYTHipNekLrvnCtV4zTVMfX8wTa7SaT8IuaArmDoYmsj6bbclVrGSmmJP1UIMAMfORyk3MaMScle5kfXrazmlbvJeXrfitzqoVdyDy8aSs9XsldygjFq4Ia6gr9NVIPEEZ2tn5Gx/4o7bkyZ4XGeQEo18lfZAYN9lelNJ9qGTlOk04PdCbO0vZsuEfhB2KYV6sgfkpAuDXtH6JHJx8/dW+fya78i8n/KvxDxK2l8Eej7eqW74=" Dec 06 15:09:02 volumio volumio[29217]: info: Starting Shairport Sync Dec 06 15:09:02 volumio volumio[29217]: info: Starting Shairport Sync Dec 06 15:09:02 volumio volumio[29217]: info: Starting Shairport Sync Dec 06 15:09:02 volumio sudo[29506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:09:02 volumio sudo[29506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio go-librespot[29480]: time="2025-12-06T15:09:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:09:02 volumio sudo[29511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:09:02 volumio sudo[29511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 15:09:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 15:09:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio systemd[1]: shairport-sync.service: Consumed 1.734s CPU time. Dec 06 15:09:02 volumio go-librespot[29480]: time="2025-12-06T15:09:02-06:00" level=debug msg="completed keyexchange" Dec 06 15:09:02 volumio go-librespot[29480]: time="2025-12-06T15:09:02-06:00" level=debug msg="completed challenge" Dec 06 15:09:02 volumio sudo[29508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:09:02 volumio sudo[29508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio go-librespot[29480]: time="2025-12-06T15:09:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:09:02 volumio volumio[29217]: info: Asound.conf file unchanged, so no further update is needed Dec 06 15:09:02 volumio volumio[29217]: info: Output device has changed, restarting MPD Dec 06 15:09:02 volumio volumio[29217]: info: Output device has changed, restarting Shairport Sync Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:02 volumio sudo[29503]: 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 Dec 06 15:09:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:09:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:09:02 volumio sudo[29506]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio sudo[29503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio sudo[29520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 15:09:02 volumio sudo[29520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio sudo[29516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 15:09:02 volumio sudo[29516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio sudo[29516]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio sudo[29503]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio volumio[29217]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 15:09:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 15:09:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 15:09:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio sudo[29511]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio sudo[29508]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 06 15:09:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 15:09:02 volumio systemd[1]: mpd.service: Consumed 1.651s CPU time. Dec 06 15:09:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 06 15:09:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 15:09:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 15:09:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 15:09:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 15:09:02 volumio volumio[29217]: info: MPD Permissions set Dec 06 15:09:02 volumio volumio[29217]: info: Shairport-Sync Started Dec 06 15:09:02 volumio volumio[29217]: Error adding Membership: Error: addMembership EINVAL Dec 06 15:09:02 volumio volumio[29217]: info: Shairport-Sync Started Dec 06 15:09:02 volumio volumio[29217]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 06 15:09:02 volumio volumio[29217]: info: Shairport-Sync Started Dec 06 15:09:02 volumio sudo[29559]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 06 15:09:02 volumio sudo[29559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio sudo[29559]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio volumio[29217]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:02 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:02 volumio volumio[29217]: info: Starting Shairport Sync Dec 06 15:09:02 volumio sudo[29555]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 15:09:02 volumio sudo[29555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 15:09:02 volumio sudo[29555]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio sudo[29565]: 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 Dec 06 15:09:02 volumio sudo[29565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio sudo[29573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 15:09:02 volumio sudo[29565]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:02 volumio sudo[29573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 06 15:09:02 volumio volumio[29217]: 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"} Dec 06 15:09:02 volumio volumio[29217]: info: Spotify Successfully logged in Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 15:09:02 volumio volumio[29217]: info: [1765055342905] CoreMusicLibrary::Adding element Spotify Dec 06 15:09:02 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source Bandcamp Discover Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source SoundCloud Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source YouTube2 Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source YouTube Music Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source Podcast Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source Volusonic Dec 06 15:09:02 volumio volumio[29217]: Cannot find translation for source Spotify Dec 06 15:09:02 volumio sudo[29578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 06 15:09:02 volumio sudo[29578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 15:09:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 15:09:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 15:09:02 volumio sudo[29573]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:03 volumio volumio[29217]: info: Shairport-Sync Started Dec 06 15:09:03 volumio systemd[1]: Reloading. Dec 06 15:09:03 volumio volumio[29217]: info: [squeezelite_mc] Notification listener started Dec 06 15:09:03 volumio volumio[29217]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 06 15:09:03 volumio volumio[29217]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 06 15:09:03 volumio volumio[29217]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 06 15:09:03 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:03 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:03 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 15:09:03 volumio volumio[29217]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 15:09:04 volumio volumio[29217]: info: go-librespot daemon successfully initialized Dec 06 15:09:04 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:04 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:05 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. Dec 06 15:09:05 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. Dec 06 15:09:05 volumio sudo[29578]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:05 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:05 volumio sudo[29613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:05 volumio sudo[29613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 06 15:09:05 volumio sudo[29613]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:05 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 06 15:09:05 volumio sudo[29617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 06 15:09:05 volumio sudo[29617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:05 volumio go-librespot[29615]: go-librespot daemon starting... Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="app state loaded" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="stored credentials not found" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:09:05 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 06 15:09:05 volumio volumio[29217]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 06 15:09:05 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:05 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09: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]" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09: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]" Dec 06 15:09:05 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 06 15:09:05 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=info msg="zeroconf server listening on port 36979" Dec 06 15:09:05 volumio sudo[29617]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="obtained new client token: AADYogSFLvrrH+H1jNHfM2JcRRS1Oh7sEM1ZqJjybESInRo9EsNmuJFs5Yec8MqCNBg0d7hGaHzJN3DfRKO9ai9gIFhK5zcEsb7YqFq0iWPrg6IhnoRYavKeqf3SorDKJJ+nAuOq3nDxQNIvidkkRL/WzeB45/vRNwT4vAS7TCiJ4DGqrgLYCocdCWxoRtFTMC9NTMIBduitkloB4R3coi4BHPWIb6LYxWdZdttJjC+buLQhL3G5ipfHpA==" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="completed keyexchange" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=debug msg="completed challenge" Dec 06 15:09:05 volumio go-librespot[29619]: time="2025-12-06T15:09:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:06 volumio sudo[29628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:06 volumio sudo[29628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:06 volumio sudo[29628]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 06 15:09:06 volumio sudo[29632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 06 15:09:06 volumio sudo[29632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:06 volumio sudo[29632]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 06 15:09:06 volumio sudo[29635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 06 15:09:06 volumio sudo[29635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:06 volumio mpd[29574]: 2025-12-06T15:09:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 15:09:06 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 06 15:09:06 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 06 15:09:06 volumio sudo[29635]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 06 15:09:06 volumio volumio[29217]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 06 15:09:06 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 15:09:06 volumio sudo[29520]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio sudo[29442]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio sudo[29432]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:06 volumio volumio[29217]: error: MPD error: The expression evaluated to a falsy value: Dec 06 15:09:06 volumio volumio[29217]: assert.ok(self.idling) Dec 06 15:09:06 volumio volumio[29217]: error: The expression evaluated to a falsy value: Dec 06 15:09:06 volumio volumio[29217]: assert.ok(self.idling) Dec 06 15:09:06 volumio volumio[29217]: error: MPD error: The expression evaluated to a falsy value: Dec 06 15:09:06 volumio volumio[29217]: assert.ok(self.idling) Dec 06 15:09:06 volumio volumio[29217]: error: The expression evaluated to a falsy value: Dec 06 15:09:06 volumio volumio[29217]: assert.ok(self.idling) Dec 06 15:09:06 volumio volumio[29217]: info: MPD running with PID29574 Dec 06 15:09:06 volumio volumio[29217]: ,establishing connection Dec 06 15:09:06 volumio volumio[29217]: error: updateQueue error: null Dec 06 15:09:06 volumio volumio[29217]: error: updateQueue error: null Dec 06 15:09:07 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:07 volumio sudo[29646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:07 volumio sudo[29646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:07 volumio sudo[29646]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:07 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:07 volumio sudo[29649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:07 volumio sudo[29649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:07 volumio sudo[29649]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:07 volumio volumio[29217]: info: CoreCommandRouter::volumioGetState Dec 06 15:09:07 volumio volumio[29217]: info: CorePlayQueue::getTrack 0 Dec 06 15:09:07 volumio volumio[29217]: info: Initializing connection to go-librespot Websocket Dec 06 15:09:07 volumio volumio[29217]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:09:08 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:08 volumio sudo[29666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:08 volumio sudo[29666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:08 volumio sudo[29666]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:08 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:08 volumio sudo[29669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:08 volumio sudo[29669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 06 15:09:08 volumio sudo[29669]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:09 volumio go-librespot[29671]: go-librespot daemon starting... Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=debug msg="app state loaded" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=debug msg="stored credentials not found" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-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]" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-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]" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=info msg="zeroconf server listening on port 46447" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=debug msg="obtained new client token: AACQoukfU7SS/FwEJyseDZRLl7AKJt/6EpMdfxM//RzNf9GeaxF3DBuHOHHz/GB3tTuRU1nrtiJY/2yf+Sp6or0lSYoktoXGG5vj0o0+0tIZXqYhw8DRZ+BqjFMO1Y+Y9pUJnzCGEFrkPDLiK6aN9axrzeQ23a4HkvuRqL1Rop3q0jx0DPQnTAt8E30ausVOeAokOfG7D279T3QuLjw0GCOXlRvlWezA/UgRejKbJSFCdzHmEXlkuSapFA==" Dec 06 15:09:09 volumio go-librespot[29672]: time="2025-12-06T15:09:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:09:09 volumio volumio[29217]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 06 15:09:09 volumio sudo[29680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 06 15:09:09 volumio sudo[29680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:09 volumio sudo[29680]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:09 volumio volumio[29217]: info: Completed starting Core Plugins Dec 06 15:09:09 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:09:09 volumio volumio[29217]: info: ----- MyVolumio plugins startup ---- Dec 06 15:09:09 volumio volumio[29217]: info: ------------------------------------------- Dec 06 15:09:09 volumio volumio[29217]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 06 15:09:09 volumio sudo[29683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:09:09 volumio sudo[29683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:09 volumio sudo[29685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:09:09 volumio sudo[29685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:09 volumio sudo[29688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 15:09:09 volumio sudo[29688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 15:09:09 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 06 15:09:09 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 06 15:09:09 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 06 15:09:09 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 06 15:09:09 volumio sudo[29688]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:09 volumio mpd_monitor.sh[29691]: MPD Monitor Service: Starting MPD Monitor Service Dec 06 15:09:09 volumio sudo[29683]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:09 volumio sudo[29685]: pam_unix(sudo:session): session closed for user root Dec 06 15:09:09 volumio volumio[29217]: info: Successfully started MPD Monitor Dec 06 15:09:09 volumio volumio[29217]: info: Successfully started MPD Monitor Dec 06 15:09:09 volumio volumio[29217]: info: Successfully started MPD Monitor Dec 06 15:09:10 volumio go-librespot[29672]: time="2025-12-06T15:09:10-06:00" level=debug msg="completed keyexchange" Dec 06 15:09:10 volumio go-librespot[29672]: time="2025-12-06T15:09:10-06:00" level=debug msg="completed challenge" Dec 06 15:09:10 volumio go-librespot[29672]: time="2025-12-06T15:09: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 " Dec 06 15:09:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:09:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:09:10 volumio volumio[29217]: info: Initializing connection to go-librespot Websocket Dec 06 15:09:10 volumio volumio[29217]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:09:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 06 15:09:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 15:09:14 volumio go-librespot[29695]: go-librespot daemon starting... Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=info msg="running go-librespot 0.4.0" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="app state loaded" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="stored credentials not found" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-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]" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-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]" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=info msg="zeroconf server listening on port 36367" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="obtained new client token: AACgG3KE7wQteLHoLmXyOqeV4rgT/5V0s6i5b8HtURM8nZ2LM7dP82sCGcrk0yZFGnu8SQ/856M9sJCd50zPlt3WxCs59bWZe1NAkVAYEHylXNOn0isvmH6fOXO9ijjzd5SKpJEzpPCGKFQxbkq9zpn6UO2oBOHZLfdNE1IsMBuokNqm4bo96yM6dMK7gfwCkydIxvnhfAt935ZYHPoWjFrCU4MKBbtMgV8biYKWtwyHSNdgr9URAj6RMw==" Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 06 15:09:14 volumio volumio[29217]: info: Initializing connection to go-librespot Websocket Dec 06 15:09:14 volumio go-librespot[29696]: time="2025-12-06T15:09:14-06:00" level=debug msg="new websocket client" Dec 06 15:09:14 volumio volumio[29217]: info: Connection to go-librespot Websocket established Dec 06 15:09:15 volumio go-librespot[29696]: time="2025-12-06T15:09:15-06:00" level=debug msg="completed keyexchange" Dec 06 15:09:15 volumio go-librespot[29696]: time="2025-12-06T15:09:15-06:00" level=debug msg="completed challenge" Dec 06 15:09:15 volumio go-librespot[29696]: time="2025-12-06T15:09:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 15:09:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 15:09:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 15:09:15 volumio volumio[29217]: info: Connection to go-librespot Websocket closed Dec 06 15:09:17 volumio volumio[29217]: info: Getting Spotify volume Dec 06 15:09:17 volumio volumio[29217]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:09:17 volumio volumio[29217]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 15:09:17 volumio volumio[29217]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 06 15:09:17 volumio volumio[29217]: errno: -111, Dec 06 15:09:17 volumio volumio[29217]: code: 'ECONNREFUSED', Dec 06 15:09:17 volumio volumio[29217]: syscall: 'connect', Dec 06 15:09:17 volumio volumio[29217]: address: '127.0.0.1', Dec 06 15:09:17 volumio volumio[29217]: port: 9879, Dec 06 15:09:17 volumio volumio[29217]: response: undefined Dec 06 15:09:17 volumio volumio[29217]: } Dec 06 15:09:17 volumio volumio[29217]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 15:09:18 volumio sudo[29733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 15:08' Dec 06 15:09:18 volumio sudo[29733]: 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"