Dec 06 10:13:00 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:00 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: TidalConnect service started!
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: [Metrics] CommandRouter: 29s 414.06ms
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::Close All Modals sent
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::Close All Modals sent
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 06 10:13:01 gbvpi-bedroom volumio[14945]: 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 10:13:01 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:02 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 06 10:13:02 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 06 10:13:02 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 06 10:13:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Dec 06 10:13:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15511]: go-librespot daemon starting...
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="app state loaded"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=info msg="zeroconf server listening on port 41791"
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="obtained new client token: AABvp+Hw4JbQ6WLzwU1qFOsPGNa8eTVYsPD9fSaPjQUbPGb15XX64lHk9VK4H4CXw/RnYFaCrzE2wuJ9tvgaVWKqTEilozhkvb0iqe3qTeaLtIMxXIonBiVJj9Rk1+6jERXTdwYeL92eh3i63c6B4DuH85U+GEi+6YCdHMBp99bqP/wNVxSkbsF4MlOwp7snK826X0oBf2w+onWESTw4B7Ge/u/HB7BDmYnUCsLN+hCixool30bPnfKdjg=="
Dec 06 10:13:02 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:03 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:03-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:03 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:03-05:00" level=debug msg="completed challenge"
Dec 06 10:13:03 gbvpi-bedroom go-librespot[15512]: time="2025-12-06T10:13:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:03 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:03 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:03 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:03 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 06 10:13:06 gbvpi-bedroom volumio-remote-updater[11354]: Test mode enabled
Dec 06 10:13:06 gbvpi-bedroom volumio-remote-updater[11354]: Alpha mode disabled
Dec 06 10:13:06 gbvpi-bedroom volumio-remote-updater[11354]: Alpha legacy test mode disabled
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 06 10:13:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Dec 06 10:13:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15537]: go-librespot daemon starting...
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="app state loaded"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=info msg="zeroconf server listening on port 41783"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="obtained new client token: AABQ3X6peIhjBx+hknbbpWNQXH2d2Clk+DESYRi5CJ1lvYK456BWt+MfztiHnu+Ot9CYpEzuI8d3y/e8oT9GgZdAtnIpE2ypWu8wehYCtbOrjFGxxghZARBLmqhz+pxqWLagujPxj3LpC7Emk2m4aHTYai13eJQlXmSdzhyajkG1rTnQj+TWH4oZ/KPnh900MyO8EkwnY14CvjH6ePRETc9cJd2OgCsbda0xOo+KgB575QwLzL3YJlDGhQ=="
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=debug msg="completed challenge"
Dec 06 10:13:06 gbvpi-bedroom go-librespot[15538]: time="2025-12-06T10:13:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:06 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:08 gbvpi-bedroom volumio[14945]: info: BOOT COMPLETED
Dec 06 10:13:09 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:09 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 06 10:13:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:10 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15546]: go-librespot daemon starting...
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="app state loaded"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=info msg="zeroconf server listening on port 39581"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="obtained new client token: AACMaZt6Gd60NI24pTReUK94RlxdMorDvoW6pj2YiFRZbjECfqWClrYCwx0InnQ/yDQg0fZMBeNRyf/+6t2i/P1MmnlQB7twSre9pRhOogE2FX9Uen5y1FJVz5yEt+ReZ7PqoeWiWQgYXmwMFKPEjhZZxR0jLthqu8U9TXrGWgHIW+VRt2yBWb2vtbjJDStxICSOHqTmiLaHuO8xgu6ZT5XFl3+YrllFnQ1Wh3zxObt2yZxCM9m2CsjiUw=="
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=debug msg="completed challenge"
Dec 06 10:13:10 gbvpi-bedroom go-librespot[15547]: time="2025-12-06T10:13:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:12 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:12 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: Listing playlists
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: Listing playlists
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: Listing playlists
Dec 06 10:13:13 gbvpi-bedroom volumio[14945]: info: Listing playlists
Dec 06 10:13:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Dec 06 10:13:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:13 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:13 gbvpi-bedroom go-librespot[15568]: go-librespot daemon starting...
Dec 06 10:13:13 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:13-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:13 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:13-05:00" level=debug msg="app state loaded"
Dec 06 10:13:13 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:13-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=info msg="zeroconf server listening on port 38689"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="obtained new client token: AAAe9nGQ0Agwh2EdTnsVqu2fKsNxuYk2aks2136cewZrQAtNxH0R601gWIuWTQKUu/C3ZJDShU/geScxPyLta/wg03PvZsptxxR0+6PkR8YRQFDPLbn7sMaVTDdhvRh2lSLD25+f4tiYaiRKQpyoBNePNHO1aonY4EisXRcqb+gA0tg3dKA4/joI0s/UHj42HTJ4IWUk9JgPFOmyF7WrOvBNNX4JvFnoqgC3kDEIMOqTepwm6kX+SnU="
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=debug msg="completed challenge"
Dec 06 10:13:14 gbvpi-bedroom go-librespot[15569]: time="2025-12-06T10:13:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:15 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:15 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Dec 06 10:13:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15576]: go-librespot daemon starting...
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="app state loaded"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=info msg="zeroconf server listening on port 45651"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="obtained new client token: AADrplOeTKxGa8JF8IO5fwnPRu7e+59683dEyjvrjp52IGUCq3y71r6m35ok85QVIDOztqnTc9PN5NSIQK2qHKEznxFwDRp1t0OMsPMs7shHaR8lyf4/y+20xDlbHO0uMEqAeVNFm+ZgcqspBzI8nvKxxg1lNeFZo8pKNfWmmV0AgMpU8FDLxDiz4IOScLYJRIXvYJHpKvBFiYvfpCX4wkgJWsn0ltT+P01pq39tSzDsyPR5qngBKJyIYg=="
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:17 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:17-05:00" level=debug msg="completed challenge"
Dec 06 10:13:18 gbvpi-bedroom go-librespot[15577]: time="2025-12-06T10:13:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:18 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:19 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Dec 06 10:13:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15587]: go-librespot daemon starting...
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="app state loaded"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=info msg="zeroconf server listening on port 41021"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="obtained new client token: AAAvfcr+qBSUqV57WNtdvGubrfIpvZpbgQ8YquELE4CbsIHk2yLoq9gnWSvYBdNCRXSyyksjrpW9y8aHjC2t+xbW9SZRHEtnX+u6BQdRiMGuudl7aooyRzpEManPldaFuVBs9F59QHRiuD9f9UyhsBdybxuEfq6/B3P2eKWlsN7Eklt1Wb8U2f/Ql1Xbm9KZpKO95dJB7G3NetYt6pUMDoAcbBUT8m+k/JN3OtFSM91LmXp6cNJA98Klqg=="
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=debug msg="completed challenge"
Dec 06 10:13:21 gbvpi-bedroom go-librespot[15588]: time="2025-12-06T10:13:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:22 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:22 gbvpi-bedroom volumio[14945]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:23 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:23 gbvpi-bedroom volumio[14945]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Dec 06 10:13:24 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:24 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:24 gbvpi-bedroom go-librespot[15609]: go-librespot daemon starting...
Dec 06 10:13:24 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:24-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:24 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:24-05:00" level=debug msg="app state loaded"
Dec 06 10:13:24 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:24-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:25 gbvpi-bedroom volumio[14945]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="new websocket client"
Dec 06 10:13:25 gbvpi-bedroom volumio[14945]: info: Connection to go-librespot Websocket established
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=info msg="zeroconf server listening on port 41431"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="obtained new client token: AADveixun8LadWOCuXbzayL/Y9ZSCYozQgsqUiGVy8To1G05KARtxkezEjNRkYbV1yNop1/44spG+YgrKc8w6ynWjwd3h260JQsg75r9p6PrKJNHaQRKnWHjO1WHJ5QDDO+Th4Xt/jYBhZaz7KaTA2qkFYijQcDCbGIM/ym2ML3gS2gEB3T2ilWMoPqEo1LUVuAbiSEnLEBMpNeEoYSb2auk9z2X9wEBrZzGrEA+Igzezv5qjcqHr7E="
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=debug msg="completed challenge"
Dec 06 10:13:25 gbvpi-bedroom go-librespot[15610]: time="2025-12-06T10:13:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:25 gbvpi-bedroom volumio[14945]: info: Connection to go-librespot Websocket closed
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: info: Getting Spotify volume
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: errno: -111,
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: code: 'ECONNREFUSED',
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: syscall: 'connect',
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: address: '127.0.0.1',
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: port: 9879,
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: response: undefined
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: }
Dec 06 10:13:28 gbvpi-bedroom volumio[14945]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:13:28 gbvpi-bedroom sudo[15632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 10:12'
Dec 06 10:13:28 gbvpi-bedroom sudo[15632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:28 gbvpi-bedroom sudo[15632]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Dec 06 10:13:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15640]: go-librespot daemon starting...
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=debug msg="app state loaded"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=info msg="zeroconf server listening on port 40357"
Dec 06 10:13:28 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:28-05:00" level=debug msg="obtained new client token: AAA9obIc8+XrFqH1Gi3qjb5jlQhkmLqNN4WURlm7GFUhZ3k3s+ePgCvyhbJhCKrLP4QjgrQUTDSRxu2J3ay1oRwLZwDjSVqek0O2Nnm/CJ+rV9yxM/2QE+IXD96F71kge7BjunIzXFscFuFn0INcUBDzOmwUjy5g0Tw0IkiuH/nxCY6NcGlql1PFyvDsUehgAKQTTgJQyLH4CWhonEfkr2vPTPdYl59pfCb/rfvhYE7lvwOpYgz//qMEEQ=="
Dec 06 10:13:29 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:29 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:29-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:29 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:29-05:00" level=debug msg="completed challenge"
Dec 06 10:13:29 gbvpi-bedroom go-librespot[15641]: time="2025-12-06T10:13:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:29 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:13:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Dec 06 10:13:29 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:13:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Dec 06 10:13:29 gbvpi-bedroom vtcs[15479]: [2025-12-06 10:13:29.150] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected
Dec 06 10:13:29 gbvpi-bedroom qobuz-connect[15458]: 20251206 10:13:29.150 [15458.15458] INFO SampleApp: Socket closed
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.126s CPU time.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1405.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.126s CPU time.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 10:13:29 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: ----- Volumio3 ----
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: ----- System startup ----
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: MYVOLUMIO Environment detected
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Plugin folders cleanup
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning into folder /volumio/app/plugins/
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category audio_interface
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category miscellanea
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category music_service
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category plugins.json
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category system_controller
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category user_interface
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning into folder /data/plugins/
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Scanning category music_service
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Plugin folders cleanup completed
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: ----- Core plugins startup ----
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Loading plugins from folder /data/plugins/
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Loading plugin "system"...
Dec 06 10:13:30 gbvpi-bedroom volumio[15655]: info: Loading plugin "appearance"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "network"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Refreshing Cached IP Addresses
Dec 06 10:13:31 gbvpi-bedroom sudo[15683]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 10:13:31 gbvpi-bedroom sudo[15683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:31 gbvpi-bedroom sudo[15685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 10:13:31 gbvpi-bedroom sudo[15683]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:31 gbvpi-bedroom sudo[15685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "services"...
Dec 06 10:13:31 gbvpi-bedroom sudo[15685]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "alsa_controller"...
Dec 06 10:13:31 gbvpi-bedroom sudo[15698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 10:13:31 gbvpi-bedroom sudo[15698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "wizard"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "networkfs"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Starting Udev Watcher for removable devices
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Ignoring mount for partition: boot
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Ignoring mount for partition: volumio
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Ignoring mount for partition: volumio_data
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "volumio_command_line_client"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "upnp"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: [1765034011604] Starting Upmpd Daemon
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "my_music"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "mpd"...
Dec 06 10:13:31 gbvpi-bedroom volumio[15655]: info: Loading plugin "upnp_browser"...
Dec 06 10:13:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Dec 06 10:13:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15716]: go-librespot daemon starting...
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=debug msg="app state loaded"
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "alarm-clock"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "airplay_emulation"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Starting Shairport Sync
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "last_100"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "webradio"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "i2s_dacs"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: I2S DAC not set, start Auto-detection
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "volumiodiscovery"...
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** For more information see
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: *** WARNING *** For more information see
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** For more information see
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:13:32 gbvpi-bedroom node[15655]: *** WARNING *** For more information see
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Discovery: Started advertising with name: GBVPi-Bedroom
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:13:32 gbvpi-bedroom volumio[15655]: info: Loading plugin "jellyfin"...
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 10:13:32 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:32-05:00" level=info msg="zeroconf server listening on port 37711"
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "spop"...
Dec 06 10:13:33 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:33-05:00" level=debug msg="obtained new client token: AADXDVraGlOEge2RcIwByI1j4veXDantSd2ysJDr3r+GSLovRJMMZF5LlW+JFaQeceaFb/wvSmh1KV4Hj+XMUe2tA4Vqv0sWHLLEoCKgx2AJqFxLcOMKQyMeQZ8t1L9NdRN2DEwcWKsDK+Edo+LElaBLK+zuQLR1M7DbV61x7TV/YUKJZJZPBAYHn1Dxk89CVu1Fd/cvHN7NKHRiRqNhHwxf/KwCawYjyX7G2SdCf6+nsgBCQ6m2KhM="
Dec 06 10:13:33 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:33 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:33-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:33 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:33-05:00" level=debug msg="completed challenge"
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "outputs"...
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "albumart"...
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Plugin example_plugin is not enabled
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "inputs"...
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "updater_comm"...
Dec 06 10:13:33 gbvpi-bedroom go-librespot[15717]: time="2025-12-06T10:13:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Plugin mpdemulation is not enabled
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "rest_api"...
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading plugin "websocket"...
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Starting Socket.io Server version 1.7.4
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Loading i18n strings for locale en
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: Updating browse sources language
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::initPlayerControls
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: Express server listening on port 3000
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: [Metrics] WebUI: 3s 721.68ms
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::resetVolumioState
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::getcurrentVolume
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: Volumio Network Manager: Network status updated: 2
Dec 06 10:13:33 gbvpi-bedroom volumio[15726]: Forking 3 albumart workers
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: VolumeController:: Volume=91 Mute =false
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::pushState
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioPushState
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::updateTrackBlock
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrackBlock
Dec 06 10:13:33 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Reloading queue from file
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::pushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioPushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::setRandom null
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::pushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioPushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Setting Device type: Raspberry PI
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: VolumeController:: Volume=91 Mute =false
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreStateMachine::pushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioPushState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Completed loading Core Plugins
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Preparing to generate the ALSA configuration file
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Asound.conf file written
Dec 06 10:13:34 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:13:34] [connect] Successful connection
Dec 06 10:13:34 gbvpi-bedroom sudo[15783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 06 10:13:34 gbvpi-bedroom sudo[15783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:34 gbvpi-bedroom sudo[15783]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Output device has changed, restarting MPD
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Output device has changed, restarting Shairport Sync
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom sudo[15791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 10:13:34 gbvpi-bedroom sudo[15789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: ___________ START PLUGINS ___________
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Creating MPD Configuration file
Dec 06 10:13:34 gbvpi-bedroom sudo[15789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:34 gbvpi-bedroom sudo[15791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:34 gbvpi-bedroom sudo[15789]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: [1765034014282] CoreMusicLibrary::Adding element Media Servers
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 10:13:34 gbvpi-bedroom sudo[15799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 10:13:34 gbvpi-bedroom sudo[15799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom sudo[15799]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:34 gbvpi-bedroom sudo[15801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 10:13:34 gbvpi-bedroom sudo[15801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.285s CPU time.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: [1765034014376] CoreMusicLibrary::Adding element Last_100
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: [1765034014379] CoreMusicLibrary::Adding element Webradio
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Initializing BBC Radios
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Discovery: Getting this device information
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: [1765034014482] CoreMusicLibrary::Adding element Jellyfin
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: Cannot find translation for source Jellyfin
Dec 06 10:13:34 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"}
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Creating Spotify config file
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:34 gbvpi-bedroom sudo[15828]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 10:13:34 gbvpi-bedroom sudo[15828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 10:13:34 gbvpi-bedroom sudo[15828]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:34 gbvpi-bedroom volumio[15655]: info: Volumio Calling Home
Dec 06 10:13:34 gbvpi-bedroom volumio[15743]: Starting albumart workers
Dec 06 10:13:35 gbvpi-bedroom volumio[15749]: Starting albumart workers
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 10:13:35 gbvpi-bedroom volumio[15747]: Starting albumart workers
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: MPD Permissions set
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: MPD Permissions set
Dec 06 10:13:35 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:13:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765034014 101
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: 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 10:13:35 gbvpi-bedroom volumio[15655]: info: Spotify config file written
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: 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 10:13:35 gbvpi-bedroom sudo[15835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 10:13:35 gbvpi-bedroom sudo[15835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15838]: go-librespot daemon starting...
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom sudo[15835]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=debug msg="app state loaded"
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: No need to fix Spotify hosts
Dec 06 10:13:35 gbvpi-bedroom sudo[15698]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Volumio called home
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:35 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:35-05:00" level=info msg="zeroconf server listening on port 46091"
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Starting Shairport Sync
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Starting Shairport Sync
Dec 06 10:13:35 gbvpi-bedroom volumio[15655]: info: Starting Shairport Sync
Dec 06 10:13:35 gbvpi-bedroom sudo[15875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:13:35 gbvpi-bedroom sudo[15875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:35 gbvpi-bedroom sudo[15877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:13:35 gbvpi-bedroom sudo[15877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:35 gbvpi-bedroom sudo[15879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:13:35 gbvpi-bedroom sudo[15879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:36 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:36-05:00" level=debug msg="obtained new client token: AADhdQIyliTNjkiph4jvmxXbh94j76IWa2ofx8rpJaC5Un2+Sni97gxjyAGqnhT+/BniF4k71Vm5kni+PaiLkFM8CONXtDCIeXwqQYKQ4SVPy1XnLDldnEzY9+CFN9Gp0xM4gUBaPc+w72pRPaGNMGm3mieOtxxixayCRGRTz5yb12XVwLzWt04Xve4OxnqIbZ6kTf0WZyntuWKsiJbfSwW64aVea9bxyZqaLqR0vZUAJQURcLRGAntXoQ=="
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.692s CPU time.
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Dec 06 10:13:36 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:13:36 gbvpi-bedroom sudo[15875]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:36 gbvpi-bedroom sudo[15877]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: Shairport-Sync Started
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: Error adding Membership: Error: addMembership EINVAL
Dec 06 10:13:36 gbvpi-bedroom sudo[15879]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: Shairport-Sync Started
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: Shairport-Sync Started
Dec 06 10:13:36 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:36-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:36 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:36-05:00" level=debug msg="completed challenge"
Dec 06 10:13:36 gbvpi-bedroom go-librespot[15843]: time="2025-12-06T10:13:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:36 gbvpi-bedroom mpd[15830]: 2025-12-06T10:13:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 10:13:36 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 10:13:36 gbvpi-bedroom sudo[15801]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:36 gbvpi-bedroom sudo[15791]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: Completed starting Core Plugins
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: ----- MyVolumio plugins startup ----
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: -------------------------------------------
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: assert.ok(self.idling)
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: error: The expression evaluated to a falsy value:
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: assert.ok(self.idling)
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: error: updateQueue error: null
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: info: MPD running with PID15830
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: ,establishing connection
Dec 06 10:13:36 gbvpi-bedroom volumio[15655]: error: updateQueue error: null
Dec 06 10:13:38 gbvpi-bedroom volumio[15655]: info: go-librespot daemon successfully initialized
Dec 06 10:13:38 gbvpi-bedroom volumio[15655]: info: Discovery: Browse raised the following error Error: dns service error: unknown
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:39 gbvpi-bedroom go-librespot[15908]: go-librespot daemon starting...
Dec 06 10:13:39 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:39-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:39 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:39-05:00" level=debug msg="app state loaded"
Dec 06 10:13:39 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:39-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:13:39 gbvpi-bedroom sudo[15916]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 10:13:39 gbvpi-bedroom sudo[15916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:39 gbvpi-bedroom sudo[15918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 10:13:39 gbvpi-bedroom sudo[15918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 10:13:39 gbvpi-bedroom sudo[15916]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:39 gbvpi-bedroom mpd_monitor.sh[15921]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 10:13:39 gbvpi-bedroom volumio[15655]: info: Successfully started MPD Monitor
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 10:13:39 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 10:13:39 gbvpi-bedroom sudo[15918]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:39 gbvpi-bedroom volumio[15655]: info: Successfully started MPD Monitor
Dec 06 10:13:39 gbvpi-bedroom mpd_monitor.sh[15923]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 10:13:41 gbvpi-bedroom sudo[15942]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 10:13:41 gbvpi-bedroom sudo[15942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:41 gbvpi-bedroom sudo[15944]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 10:13:41 gbvpi-bedroom sudo[15944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:41 gbvpi-bedroom volumio[15655]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Dec 06 10:13:41 gbvpi-bedroom sudo[15942]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:41 gbvpi-bedroom sudo[15944]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:41 gbvpi-bedroom sudo[15946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 10:13:41 gbvpi-bedroom sudo[15946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:41 gbvpi-bedroom sudo[15946]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:41 gbvpi-bedroom volumio[15655]: info: Upmpdcli Daemon Started
Dec 06 10:13:41 gbvpi-bedroom volumio[15655]: info: Initializing connection to go-librespot Websocket
Dec 06 10:13:41 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:41-05:00" level=debug msg="new websocket client"
Dec 06 10:13:41 gbvpi-bedroom volumio[15655]: info: Connection to go-librespot Websocket established
Dec 06 10:13:43 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:43 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:43 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:43 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:44 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:13:44 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:13:44 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:13:44 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:44-05:00" level=info msg="zeroconf server listening on port 41781"
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: Getting Spotify volume
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: 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 10:13:44 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: SPOTIFY: SPOTIFY VOLUME undefined
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: SPOTIFY: VOLUMIO VOLUME 91
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: Aligning Spotify Volume to Volumio Volume
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:44 gbvpi-bedroom volumio[15655]: info: Setting Spotify Volume from Volumio: 91
Dec 06 10:13:46 gbvpi-bedroom volumio[15655]: SPOTIFY: SETTING SPOTIFY VOLUME 91
Dec 06 10:13:46 gbvpi-bedroom volumio[15655]: info: Sending Spotify command with payload to local API: /player/volume
Dec 06 10:13:49 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:49-05:00" level=debug msg="obtained new client token: AACal/6jNEpsVzj61JKYSp5V7EASoWMjAJddZQp/hJfepGV8KqdSCUSnkQVC1VCfBn4XnZQ1Bz0399b2Vf8VxH1Mvl07y9bsodKex9QECywl0xg2EAcfANVT+xaZ3YlTCBjuwtXIzVXfYLeTHCQIC1nixYMMJCauBTe2BbwfBP3L/wsjmVR0Ghy71YVktR8gHBB366WsYCOyKH0JAayZ3ghoOGOfqWFWDk8NWFnd9SwfGPionTl3asxsYw=="
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: MyVolumio login type: Token
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 10:13:50 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: info: Streaming services startup
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: info: Starting Streaming Daemon
Dec 06 10:13:51 gbvpi-bedroom sudo[15952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 10:13:51 gbvpi-bedroom sudo[15952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 10:13:51 gbvpi-bedroom sudo[15952]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: error: Cannot start Volumio Streaming Daemon
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 10:13:51 gbvpi-bedroom volumio[15655]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: CoreCommandRouter::volumioGetState
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: CorePlayQueue::getTrack 0
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:53 gbvpi-bedroom volumio[15655]: info: Listing playlists
Dec 06 10:13:54 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:13:54 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:54-05:00" level=debug msg="completed keyexchange"
Dec 06 10:13:54 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:54-05:00" level=debug msg="completed challenge"
Dec 06 10:13:54 gbvpi-bedroom go-librespot[15909]: time="2025-12-06T10:13:54-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:13:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:13:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: Error: socket hang up
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: at connResetException (node:internal/errors:720:14)
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: at Socket.socketOnEnd (node:_http_client:519:23)
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: at Socket.emit (node:events:526:35)
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: at endReadableNT (node:internal/streams/readable:1376:12)
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: code: 'ECONNRESET',
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: response: undefined
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: }
Dec 06 10:13:54 gbvpi-bedroom volumio[15655]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:13:55 gbvpi-bedroom sudo[15986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 10:12'
Dec 06 10:13:55 gbvpi-bedroom sudo[15986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:13:55 gbvpi-bedroom sudo[15986]: pam_unix(sudo:session): session closed for user root
Dec 06 10:13:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Dec 06 10:13:58 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:58 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:13:58 gbvpi-bedroom go-librespot[15994]: go-librespot daemon starting...
Dec 06 10:13:58 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:13:58-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:13:58 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:13:58-05:00" level=debug msg="app state loaded"
Dec 06 10:13:58 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:13:58-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:14:01 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:14:01] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Dec 06 10:14:01 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:14:01] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: volumio.service: Consumed 15.549s CPU time.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1406.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: volumio.service: Consumed 15.549s CPU time.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 10:14:01 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 10:14:02 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:02 gbvpi-bedroom volumio[16013]: info: ----- Volumio3 ----
Dec 06 10:14:02 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:02 gbvpi-bedroom volumio[16013]: info: ----- System startup ----
Dec 06 10:14:02 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: MYVOLUMIO Environment detected
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Plugin folders cleanup
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning into folder /volumio/app/plugins/
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category audio_interface
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category miscellanea
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category music_service
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category plugins.json
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category system_controller
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category user_interface
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning into folder /data/plugins/
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Scanning category music_service
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Plugin folders cleanup completed
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: ----- Core plugins startup ----
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugins from folder /data/plugins/
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "system"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "appearance"...
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=info msg="zeroconf server listening on port 41715"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="obtained new client token: AAAY8R/4WDiO2NsS6bosWqOotSnXvLnPLHEV/lLNJ8/TXWhaYXZVtmoXzbeElOrRDI866/+mNg9UA9UA7zx49JK/kytIV3S9I8ZSqPug7Z8tkrlM8Q/HZlX+UGJOUAwKyuR/0pJjJOnGJIIj1VFM3Ighl4ZlYp1eemEaTGKbsGpyJRAiAPvANTRq+OB0QUaMAg0f8QVXUfb+Wk7qEy9gFD6Lri+W1aT/BmBoBhoMj/QxvK1GYQKpr4IHjg=="
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="completed keyexchange"
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=debug msg="completed challenge"
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "network"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Refreshing Cached IP Addresses
Dec 06 10:14:03 gbvpi-bedroom go-librespot[15995]: time="2025-12-06T10:14:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:14:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:14:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:14:03 gbvpi-bedroom sudo[16041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 10:14:03 gbvpi-bedroom sudo[16043]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 10:14:03 gbvpi-bedroom sudo[16041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:03 gbvpi-bedroom sudo[16043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "services"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "alsa_controller"...
Dec 06 10:14:03 gbvpi-bedroom sudo[16041]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:03 gbvpi-bedroom sudo[16043]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:03 gbvpi-bedroom sudo[16050]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 10:14:03 gbvpi-bedroom sudo[16050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "wizard"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "networkfs"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Starting Udev Watcher for removable devices
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Ignoring mount for partition: boot
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Ignoring mount for partition: volumio
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Ignoring mount for partition: volumio_data
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "volumio_command_line_client"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "upnp"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: [1765034043879] Starting Upmpd Daemon
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "my_music"...
Dec 06 10:14:03 gbvpi-bedroom volumio[16013]: info: Loading plugin "mpd"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "upnp_browser"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "alarm-clock"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "airplay_emulation"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Starting Shairport Sync
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "last_100"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "webradio"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "i2s_dacs"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: I2S DAC not set, start Auto-detection
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "volumiodiscovery"...
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** For more information see
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: *** WARNING *** For more information see
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** For more information see
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 10:14:04 gbvpi-bedroom node[16013]: *** WARNING *** For more information see
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Discovery: Started advertising with name: GBVPi-Bedroom
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:14:04 gbvpi-bedroom volumio[16013]: info: Loading plugin "jellyfin"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "spop"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "outputs"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "albumart"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Plugin example_plugin is not enabled
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "inputs"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "updater_comm"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Plugin mpdemulation is not enabled
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "rest_api"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading plugin "websocket"...
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Starting Socket.io Server version 1.7.4
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: Loading i18n strings for locale en
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: Updating browse sources language
Dec 06 10:14:05 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::initPlayerControls
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: Express server listening on port 3000
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: [Metrics] WebUI: 3s 712.88ms
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::resetVolumioState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::getcurrentVolume
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Volumio Network Manager: Network status updated: 2
Dec 06 10:14:06 gbvpi-bedroom volumio[16076]: Forking 3 albumart workers
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: VolumeController:: Volume=91 Mute =false
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::pushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioPushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::updateTrackBlock
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrackBlock
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Reloading queue from file
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::pushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioPushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::setRandom null
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::pushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioPushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Setting Device type: Raspberry PI
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
Dec 06 10:14:06 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:14:06] [connect] Successful connection
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: VolumeController:: Volume=91 Mute =false
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreStateMachine::pushState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioPushState
Dec 06 10:14:06 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 10:14:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765034046 101
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: 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 10:14:06 gbvpi-bedroom volumio[16013]: info: Completed loading Core Plugins
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Preparing to generate the ALSA configuration file
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Output device has changed, restarting MPD
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Output device has changed, restarting Shairport Sync
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom sudo[16131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:14:06 gbvpi-bedroom sudo[16131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:06 gbvpi-bedroom sudo[16133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: ___________ START PLUGINS ___________
Dec 06 10:14:06 gbvpi-bedroom sudo[16133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:06 gbvpi-bedroom sudo[16131]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Creating MPD Configuration file
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: [1765034046503] CoreMusicLibrary::Adding element Media Servers
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 10:14:06 gbvpi-bedroom sudo[16142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom sudo[16142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:06 gbvpi-bedroom sudo[16144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 10:14:06 gbvpi-bedroom sudo[16144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:06 gbvpi-bedroom sudo[16142]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.895s CPU time.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: [1765034046600] CoreMusicLibrary::Adding element Last_100
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: [1765034046613] CoreMusicLibrary::Adding element Webradio
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Initializing BBC Radios
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Discovery: Getting this device information
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: [1765034046760] CoreMusicLibrary::Adding element Jellyfin
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: Cannot find translation for source Jellyfin
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"}
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: Creating Spotify config file
Dec 06 10:14:06 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:06 gbvpi-bedroom go-librespot[16172]: go-librespot daemon starting...
Dec 06 10:14:06 gbvpi-bedroom sudo[16171]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 10:14:06 gbvpi-bedroom sudo[16171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 10:14:06 gbvpi-bedroom sudo[16171]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:06 gbvpi-bedroom go-librespot[16173]: time="2025-12-06T10:14:06-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Volumio Calling Home
Dec 06 10:14:07 gbvpi-bedroom volumio[16091]: Starting albumart workers
Dec 06 10:14:07 gbvpi-bedroom volumio[16092]: Starting albumart workers
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: MPD Permissions set
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: MPD Permissions set
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: 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 10:14:07 gbvpi-bedroom volumio[16013]: info: Spotify config file written
Dec 06 10:14:07 gbvpi-bedroom volumio[16093]: Starting albumart workers
Dec 06 10:14:07 gbvpi-bedroom sudo[16186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 10:14:07 gbvpi-bedroom sudo[16186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:07 gbvpi-bedroom go-librespot[16173]: time="2025-12-06T10:14:07-05:00" level=info msg="zeroconf server listening on port 43541"
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:07 gbvpi-bedroom go-librespot[16193]: go-librespot daemon starting...
Dec 06 10:14:07 gbvpi-bedroom sudo[16186]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: No need to fix Spotify hosts
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Volumio called home
Dec 06 10:14:07 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:07-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:14:07 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:07-05:00" level=debug msg="app state loaded"
Dec 06 10:14:07 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:07-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Starting Shairport Sync
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Starting Shairport Sync
Dec 06 10:14:07 gbvpi-bedroom volumio[16013]: info: Starting Shairport Sync
Dec 06 10:14:07 gbvpi-bedroom sudo[16206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:14:07 gbvpi-bedroom sudo[16206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:07 gbvpi-bedroom sudo[16210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:14:07 gbvpi-bedroom sudo[16208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 10:14:07 gbvpi-bedroom sudo[16208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:07 gbvpi-bedroom sudo[16210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:14:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.683s CPU time.
Dec 06 10:14:07 gbvpi-bedroom sudo[16050]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:14:08 gbvpi-bedroom sudo[16210]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 10:14:08 gbvpi-bedroom sudo[16208]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=info msg="zeroconf server listening on port 45983"
Dec 06 10:14:08 gbvpi-bedroom sudo[16206]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="obtained new client token: AACamx99K7zPt/h/gUZD1gaVvtpw7Tn/hoLVWqoFaSL3+XGmMcudeLhwCM6WJAzYhYHaZzYROR4Qo3iivSRJDreU9PnGX4LBwqHfCutSEr1T/G2v9vgCY8fMMqy5EV5tQ2lIOoV0ASy7ajUdxtiViFZZ2kAbg822VZ/Tbk8U4jrxnLaDRSQhKmHJ+mVi+gZ4XG6Bi2zEa0IynwhCZFXtT4td/sdNtbvmGX/rW8yOvdTUhrcBln4P//w="
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="completed keyexchange"
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=debug msg="completed challenge"
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: Shairport-Sync Started
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: Error adding Membership: Error: addMembership EINVAL
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: Shairport-Sync Started
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: Shairport-Sync Started
Dec 06 10:14:08 gbvpi-bedroom go-librespot[16196]: time="2025-12-06T10:14:08-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Dec 06 10:14:08 gbvpi-bedroom mpd[16180]: 2025-12-06T10:14:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 10:14:08 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 10:14:08 gbvpi-bedroom sudo[16144]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom sudo[16133]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: Completed starting Core Plugins
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: ----- MyVolumio plugins startup ----
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: -------------------------------------------
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: assert.ok(self.idling)
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: error: The expression evaluated to a falsy value:
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: assert.ok(self.idling)
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: info: MPD running with PID16180
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: ,establishing connection
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: error: updateQueue error: null
Dec 06 10:14:08 gbvpi-bedroom volumio[16013]: error: updateQueue error: null
Dec 06 10:14:10 gbvpi-bedroom volumio[16013]: info: go-librespot daemon successfully initialized
Dec 06 10:14:11 gbvpi-bedroom volumio[16013]: info: Discovery: Browse raised the following error Error: dns service error: unknown
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 10:14:11 gbvpi-bedroom go-librespot[16254]: go-librespot daemon starting...
Dec 06 10:14:11 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:11-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 10:14:11 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:11-05:00" level=debug msg="app state loaded"
Dec 06 10:14:11 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:11-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 10:14:11 gbvpi-bedroom sudo[16262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 10:14:11 gbvpi-bedroom sudo[16262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:11 gbvpi-bedroom sudo[16265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 10:14:11 gbvpi-bedroom sudo[16265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 10:14:11 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 10:14:12 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 10:14:12 gbvpi-bedroom sudo[16262]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:12 gbvpi-bedroom volumio[16013]: info: Successfully started MPD Monitor
Dec 06 10:14:12 gbvpi-bedroom mpd_monitor.sh[16267]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 10:14:12 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 10:14:12 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 10:14:12 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 10:14:12 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 10:14:12 gbvpi-bedroom sudo[16265]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:12 gbvpi-bedroom volumio[16013]: info: Successfully started MPD Monitor
Dec 06 10:14:12 gbvpi-bedroom mpd_monitor.sh[16270]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: CoreCommandRouter::volumioGetState
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: CorePlayQueue::getTrack 0
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Listing playlists
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Listing playlists
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Listing playlists
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Listing playlists
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Initializing connection to go-librespot Websocket
Dec 06 10:14:13 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:13-05:00" level=debug msg="new websocket client"
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Connection to go-librespot Websocket established
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Dec 06 10:14:13 gbvpi-bedroom sudo[16289]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 10:14:13 gbvpi-bedroom sudo[16289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:13 gbvpi-bedroom sudo[16291]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 10:14:13 gbvpi-bedroom sudo[16291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:13 gbvpi-bedroom sudo[16289]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:13 gbvpi-bedroom sudo[16291]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:13 gbvpi-bedroom sudo[16295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 10:14:13 gbvpi-bedroom sudo[16295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 10:14:13 gbvpi-bedroom sudo[16295]: pam_unix(sudo:session): session closed for user root
Dec 06 10:14:13 gbvpi-bedroom volumio[16013]: info: Upmpdcli Daemon Started
Dec 06 10:14:14 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 10:14:14 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 10:14:14 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 10:14:14 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:14-05:00" level=info msg="zeroconf server listening on port 44503"
Dec 06 10:14:15 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:15-05:00" level=debug msg="obtained new client token: AAAyM6mf/KrmczzGM1idPctBU5jVeXZ3p1rJmAc8+DTb4ORHtj5FDdneR2PN5Z4IcZ+S10he8NpC20umHIge0CsyzpKqK96XW+C4sFoFE8ShOrlo0GpD6fLKXMKvAYl3QQKqj+PEbQqidL8cthVFHH+Iy3lnd9+A3KtxsztxSP7vRFLcercXJZSJgbmNVySNSbA3EJE8x23C2ULPnNa9Nv9Aj8ldvTbK8nOFuVLYvpJKorD9GTZW3Dg="
Dec 06 10:14:15 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 10:14:15 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:15-05:00" level=debug msg="completed keyexchange"
Dec 06 10:14:15 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:15-05:00" level=debug msg="completed challenge"
Dec 06 10:14:15 gbvpi-bedroom go-librespot[16255]: time="2025-12-06T10:14:15-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 10:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 10:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 10:14:15 gbvpi-bedroom volumio[16013]: info: Connection to go-librespot Websocket closed
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: info: Getting Spotify volume
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: errno: -111,
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: code: 'ECONNREFUSED',
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: syscall: 'connect',
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: address: '127.0.0.1',
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: port: 9879,
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: response: undefined
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: }
Dec 06 10:14:16 gbvpi-bedroom volumio[16013]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 10:14:17 gbvpi-bedroom sudo[16312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 10:13'
Dec 06 10:14:17 gbvpi-bedroom sudo[16312]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025"
VOLUMIO_VERSION="4.072"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"