Feb 10 18:23:00 volumio go-librespot[30568]: time="2026-02-10T18:23:00+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:00 volumio go-librespot[30568]: time="2026-02-10T18:23:00+07:00" level=debug msg="completed challenge"
Feb 10 18:23:00 volumio go-librespot[30568]: time="2026-02-10T18:23:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:01 volumio volumio[30231]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 10 18:23:01 volumio volumio[30231]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 10 18:23:01 volumio volumio[30231]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:01 volumio volumio[30231]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:01 volumio volumio[30231]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 10 18:23:01 volumio volumio[30231]: info: MyVolumio login type: Token
Feb 10 18:23:01 volumio volumio[30231]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 10 18:23:01 volumio volumio[30231]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 10 18:23:03 volumio volumio[30231]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 10 18:23:03 volumio volumio[30231]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 10 18:23:03 volumio volumio[30231]: info: Streaming services startup
Feb 10 18:23:03 volumio volumio[30231]: info: Starting Streaming Daemon
Feb 10 18:23:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28.
Feb 10 18:23:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:03 volumio sudo[30590]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 10 18:23:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:03 volumio sudo[30590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:03 volumio go-librespot[30591]: go-librespot daemon starting...
Feb 10 18:23:03 volumio volumio[30231]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 10 18:23:03 volumio go-librespot[30596]: time="2026-02-10T18:23:03+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:03 volumio go-librespot[30596]: time="2026-02-10T18:23:03+07:00" level=debug msg="app state loaded"
Feb 10 18:23:03 volumio go-librespot[30596]: time="2026-02-10T18:23:03+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:03 volumio sudo[30590]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:03 volumio volumio[30231]: info: Getting Spotify volume
Feb 10 18:23:03 volumio volumio[30231]: info: Connection to go-librespot Websocket closed
Feb 10 18:23:03 volumio volumio[30231]: error: Cannot start Volumio Streaming Daemon
Feb 10 18:23:03 volumio volumio[30231]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 10 18:23:03 volumio volumio[30231]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 10 18:23:03 volumio volumio[30231]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 10 18:23:03 volumio volumio[30231]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:03 volumio volumio[30231]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:03 volumio volumio[30231]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 10 18:23:03 volumio volumio[30231]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 10 18:23:03 volumio volumio[30231]: SPOTIFY: VOLUMIO VOLUME 100
Feb 10 18:23:03 volumio volumio[30231]: info: Aligning Spotify Volume to Volumio Volume
Feb 10 18:23:03 volumio volumio[30231]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:03 volumio volumio[30231]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:03 volumio volumio[30231]: info: Setting Spotify Volume from Volumio: 100
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=info msg="zeroconf server listening on port 35187"
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=debug msg="obtained new client token: AABYeTmi6YBAoX28VDjMkeA5ghC1PeM/gtilmhDQ6DVPyaqKtnVnjwK+T7SLBbHTZ2ih2ahjCQzQAAsIuauzs3uqi8tCVjcoHu3nzNVlHsMT4fMlRPh+VWBNz4gTDkbuebmhT4G1hVVSUjiGO8LVlCf/+Rveia0dpFos8Td2mUsy0uRniokTmitiaMMy5rRuGQQxfhUkhdFOuutgTgCvxji4Vf0LtAvz+qnUjFu+WfieOvktMkn2vXQ="
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:04 volumio go-librespot[30596]: time="2026-02-10T18:23:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:23:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:04 volumio volumio[30231]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:23:04 volumio volumio[30231]: Error: socket hang up
Feb 10 18:23:04 volumio volumio[30231]:     at connResetException (node:internal/errors:720:14)
Feb 10 18:23:04 volumio volumio[30231]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 10 18:23:04 volumio volumio[30231]:     at Socket.emit (node:events:526:35)
Feb 10 18:23:04 volumio volumio[30231]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 10 18:23:04 volumio volumio[30231]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 10 18:23:04 volumio volumio[30231]:   code: 'ECONNRESET',
Feb 10 18:23:04 volumio volumio[30231]:   response: undefined
Feb 10 18:23:04 volumio volumio[30231]: }
Feb 10 18:23:04 volumio volumio[30231]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:23:05 volumio sudo[30620]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 18:22'
Feb 10 18:23:05 volumio sudo[30620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:06 volumio sudo[30620]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Feb 10 18:23:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:07 volumio volumio-remote-updater[643]: [2026-02-10 18:23:07] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 10 18:23:07 volumio volumio-remote-updater[643]: [2026-02-10 18:23:07] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 10 18:23:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:07 volumio go-librespot[30628]: go-librespot daemon starting...
Feb 10 18:23:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 10 18:23:07 volumio systemd[1]: volumio.service: Consumed 55.677s CPU time.
Feb 10 18:23:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 10 18:23:07 volumio go-librespot[30629]: time="2026-02-10T18:23:07+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:07 volumio go-librespot[30629]: time="2026-02-10T18:23:07+07:00" level=debug msg="app state loaded"
Feb 10 18:23:07 volumio go-librespot[30629]: time="2026-02-10T18:23:07+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 10 18:23:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10586.
Feb 10 18:23:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 10 18:23:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 10 18:23:08 volumio systemd[1]: volumio.service: Consumed 55.677s CPU time.
Feb 10 18:23:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 10 18:23:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=info msg="zeroconf server listening on port 41751"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="obtained new client token: AAC7plzc2qQk0A/3mpwQ05R6OIWNnCc5mXjgaZZST9MHpgTzF3SK92s4c6rQkOnJaalB1KeuvBsLuDx9EuemJDY4SW6tec7nqeHOBKp9XYqZXxqYK0Rq69DoNkR63CXSSr+htVzfJClAvupfjql3cJeabYezmzEM+dLqBM1zPMq9EPPxKzrvjvbdYMVBbUo0Zl/de7v2FTNLZc39CZ/stly3qcSN20fWkUyA7kvk1BBVqf8R34pOGMT55w=="
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=debug msg="completed challenge"
Feb 10 18:23:08 volumio go-librespot[30629]: time="2026-02-10T18:23:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:11 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:11 volumio volumio[30643]: info: -----            Volumio3              ----
Feb 10 18:23:11 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:11 volumio volumio[30643]: info: -----          System startup          ----
Feb 10 18:23:11 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Feb 10 18:23:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:11 volumio go-librespot[30664]: go-librespot daemon starting...
Feb 10 18:23:11 volumio go-librespot[30665]: time="2026-02-10T18:23:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:11 volumio go-librespot[30665]: time="2026-02-10T18:23:11+07:00" level=debug msg="app state loaded"
Feb 10 18:23:11 volumio go-librespot[30665]: time="2026-02-10T18:23:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=info msg="zeroconf server listening on port 40599"
Feb 10 18:23:12 volumio volumio-remote-updater[643]: [2026-02-10 18:23:12] [connect] Successful connection
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=debug msg="obtained new client token: AAAAR6FcN/U/ykbIN/vbDdjIPlq+kVCO47K7siKnrj2gNdKk0OherNns3E9PiNipDbQR6diliJ9Bn4vihQvFjSM/KhPdnUMPWw2EKT4bZNB9E1zCSYW4B2v8EjgAovvLBS2MLhMDvF4ZWX3/9/ejaMg9aMZr9GaeZdYgO5yesEYGyiWbcxBOz3iTWB0CMebTz4jp+Mc1rAhrvbl6KaAgzKl3B6fGLGFhKkqkylB5sg+nhzyFAkboILB28w=="
Feb 10 18:23:12 volumio go-librespot[30665]: time="2026-02-10T18:23:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:13 volumio volumio[30643]: info: MYVOLUMIO Environment detected
Feb 10 18:23:13 volumio go-librespot[30665]: time="2026-02-10T18:23:13+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:13 volumio go-librespot[30665]: time="2026-02-10T18:23:13+07:00" level=debug msg="completed challenge"
Feb 10 18:23:13 volumio go-librespot[30665]: time="2026-02-10T18:23:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:13 volumio volumio[30643]: info: Plugin folders cleanup
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning into folder /volumio/app/plugins/
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category audio_interface
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category miscellanea
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category music_service
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category plugins.json
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category system_controller
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category user_interface
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning into folder /data/plugins/
Feb 10 18:23:13 volumio volumio[30643]: info: Scanning category music_service
Feb 10 18:23:13 volumio volumio[30643]: info: Plugin folders cleanup completed
Feb 10 18:23:13 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:13 volumio volumio[30643]: info: -----      Core plugins startup        ----
Feb 10 18:23:13 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:13 volumio volumio[30643]: info: Loading plugins from folder /volumio/app/plugins/
Feb 10 18:23:13 volumio volumio[30643]: info: Adding plugin upnp to MyMusic Plugins
Feb 10 18:23:13 volumio volumio[30643]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 10 18:23:13 volumio volumio[30643]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 10 18:23:13 volumio volumio[30643]: info: Loading plugins from folder /data/plugins/
Feb 10 18:23:13 volumio volumio[30643]: info: Loading plugin "system"...
Feb 10 18:23:13 volumio volumio[30643]: info: Loading plugin "appearance"...
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "network"...
Feb 10 18:23:15 volumio volumio[30643]: info: Refreshing Cached IP Addresses
Feb 10 18:23:15 volumio sudo[30680]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 10 18:23:15 volumio sudo[30680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:15 volumio sudo[30682]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 10 18:23:15 volumio sudo[30682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:15 volumio sudo[30680]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:15 volumio sudo[30682]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "services"...
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "alsa_controller"...
Feb 10 18:23:15 volumio sudo[30690]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 10 18:23:15 volumio sudo[30690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:15 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "wizard"...
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "networkfs"...
Feb 10 18:23:15 volumio volumio[30643]: info: Starting Udev Watcher for removable devices
Feb 10 18:23:15 volumio volumio[30643]: info: Ignoring mount for partition: boot
Feb 10 18:23:15 volumio volumio[30643]: info: Ignoring mount for partition: volumio
Feb 10 18:23:15 volumio volumio[30643]: info: Ignoring mount for partition: volumio_data
Feb 10 18:23:15 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "volumio_command_line_client"...
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "upnp"...
Feb 10 18:23:15 volumio volumio[30643]: info: [1770722595630] Starting Upmpd Daemon
Feb 10 18:23:15 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "my_music"...
Feb 10 18:23:15 volumio volumio[30643]: info: Loading plugin "mpd"...
Feb 10 18:23:16 volumio volumio[30643]: info: Loading plugin "upnp_browser"...
Feb 10 18:23:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Feb 10 18:23:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:16 volumio go-librespot[30713]: go-librespot daemon starting...
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=debug msg="app state loaded"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:23:16 volumio go-librespot[30714]: time="2026-02-10T18:23:16+07:00" level=info msg="zeroconf server listening on port 33259"
Feb 10 18:23:17 volumio go-librespot[30714]: time="2026-02-10T18:23:17+07:00" level=debug msg="obtained new client token: AAD3VLhYdeyiL6mypFdnJS9dkJRZEWaX2ivTc6XleTMqkO7Px5X5PpKXmhB6qkQOk/Wl1VFLVGdd5otBA7oJNYxCU7W/Jy/5EXu/VJ7PhOsGeMTjC1E0wQFfyms7osmcw8GrgFqJQulKViou89a4pN/JAhZx9VPtV+W4pcF82bGp3TAfSoeeZWPb+vGvKcF4TEInWBJ5xBgTyq7YhkStKO52had3EbsrAd1VrmrEFWboYHhCLWcQ1uY="
Feb 10 18:23:17 volumio go-librespot[30714]: time="2026-02-10T18:23:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:17 volumio go-librespot[30714]: time="2026-02-10T18:23:17+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:17 volumio go-librespot[30714]: time="2026-02-10T18:23:17+07:00" level=debug msg="completed challenge"
Feb 10 18:23:17 volumio go-librespot[30714]: time="2026-02-10T18:23:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:18 volumio sudo[30690]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:19 volumio volumio[30643]: info: Starting UPNP Browser
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "alarm-clock"...
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "airplay_emulation"...
Feb 10 18:23:19 volumio volumio[30643]: info: Starting Shairport Sync
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "last_100"...
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "webradio"...
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "i2s_dacs"...
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "volumiodiscovery"...
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** For more information see 
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:23:19 volumio volumio[30643]: *** WARNING *** For more information see 
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** For more information see 
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:23:19 volumio node[30643]: *** WARNING *** For more information see 
Feb 10 18:23:19 volumio volumio[30643]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 10 18:23:19 volumio volumio[30643]: info: Discovery: Started advertising with name: Volumio
Feb 10 18:23:19 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:23:19 volumio volumio[30643]: info: Loading plugin "spop"...
Feb 10 18:23:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Feb 10 18:23:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:20 volumio go-librespot[30723]: go-librespot daemon starting...
Feb 10 18:23:20 volumio go-librespot[30724]: time="2026-02-10T18:23:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:20 volumio go-librespot[30724]: time="2026-02-10T18:23:20+07:00" level=debug msg="app state loaded"
Feb 10 18:23:20 volumio go-librespot[30724]: time="2026-02-10T18:23:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=info msg="zeroconf server listening on port 44007"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="obtained new client token: AACABlfcyBfFCaTI3W2zh/9kd7QiKH7JwYxaqMKkGKtvqa95fpw7q+Gw+zoIsvliAfSOgeYXO6o7D3n5KAa1LnSONiZo4628Jr45uRJs70tXjyFOr47ZJvULNBBWqOKeme9pslcmRaJRfnn1QmMiu5iNW4h/Z21x6eoMQ2Zv5yC4Qw2poo9J+Qsj7F/LyLCc0v/Ew9LGuHPmh/c/DrevCwAGfYNpCx/Wt27kEqx6FH7axgOMOi/pTGLE9g=="
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=debug msg="completed challenge"
Feb 10 18:23:21 volumio go-librespot[30724]: time="2026-02-10T18:23:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:21 volumio volumio[30643]: info: Loading plugin "ytcr"...
Feb 10 18:23:24 volumio volumio[30643]: info: Loading plugin "ytmusic"...
Feb 10 18:23:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Feb 10 18:23:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:24 volumio go-librespot[30731]: go-librespot daemon starting...
Feb 10 18:23:24 volumio go-librespot[30732]: time="2026-02-10T18:23:24+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:24 volumio go-librespot[30732]: time="2026-02-10T18:23:24+07:00" level=debug msg="app state loaded"
Feb 10 18:23:24 volumio go-librespot[30732]: time="2026-02-10T18:23:24+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:25 volumio volumio-remote-updater[643]: [2026-02-10 18:23:25] [connect] Successful connection
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=info msg="zeroconf server listening on port 36315"
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "outputs"...
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "albumart"...
Feb 10 18:23:25 volumio volumio[30643]: info: Plugin example_plugin is not enabled
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "inputs"...
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "updater_comm"...
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=debug msg="obtained new client token: AAC5ho00bH/PjQxlfiihIYdDJy6bXR+7Z69B/HYAbh+PIomy3ms5tYwv8EhKS0R+FM5Z2mB5EED7j4YKQUYGvUl8b4AmzhWUjPrjPsRNf79Oza+mrWxEEvfxEw3pCYkC0QsFLebPZcDdQYwGoqBgBVdYy57qxbHHfJHnLqksoyNwnxy3N0VkMO1qREJhqhkg+lWtXR2dA2Mo/l/qvgxZczMOPKb5RtgdqGE3T+XayZJ/Z5iUeboEPQcu7g=="
Feb 10 18:23:25 volumio volumio[30643]: info: Plugin mpdemulation is not enabled
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "rest_api"...
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "websocket"...
Feb 10 18:23:25 volumio volumio[30643]: info: Starting Socket.io Server version 1.7.4
Feb 10 18:23:25 volumio volumio[30643]: info: Loading plugin "RoonBridge"...
Feb 10 18:23:25 volumio go-librespot[30732]: time="2026-02-10T18:23:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 10 18:23:26 volumio go-librespot[30732]: time="2026-02-10T18:23:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:23:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:26 volumio volumio[30643]: info: Applying required configuration parameters for plugin RoonBridge
Feb 10 18:23:26 volumio volumio[30643]: info: Loading i18n strings for locale en
Feb 10 18:23:26 volumio volumio[30643]: Updating browse sources language
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::initPlayerControls
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:23:26 volumio volumio[30643]: Express server listening on port 3000
Feb 10 18:23:26 volumio volumio[30643]:  [Metrics]  WebUI:  16s 4.15ms 
Feb 10 18:23:26 volumio volumio[30753]: Forking 3 albumart workers
Feb 10 18:23:26 volumio volumio[30643]: info: CoreStateMachine::resetVolumioState
Feb 10 18:23:26 volumio volumio[30643]: info: CoreStateMachine::getcurrentVolume
Feb 10 18:23:26 volumio volumio[30643]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:23:27 volumio sudo[30786]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 10 18:23:27 volumio sudo[30796]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 10 18:23:27 volumio sudo[30786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:27 volumio sudo[30796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:27 volumio sudo[30786]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:27 volumio volumio[30643]: info: Volumio Network Manager: Network status updated: 1
Feb 10 18:23:27 volumio sudo[30796]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:27 volumio volumio[30643]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::pushState
Feb 10 18:23:27 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::volumioPushState
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::updateTrackBlock
Feb 10 18:23:27 volumio volumio[30643]: info: CorePlayQueue::getTrackBlock
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:23:27 volumio volumio-remote-updater[643]: [2026-02-10 18:23:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770722605 101
Feb 10 18:23:27 volumio volumio[30643]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:27 volumio volumio[30643]: info: Reloading queue from file
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::setRepeat null single undefined
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::pushState
Feb 10 18:23:27 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::volumioPushState
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::setRandom null
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::pushState
Feb 10 18:23:27 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::volumioPushState
Feb 10 18:23:27 volumio volumio[30643]: info: Setting Device type: Raspberry PI
Feb 10 18:23:27 volumio volumio[30643]: info: Completed loading Core Plugins
Feb 10 18:23:27 volumio volumio[30643]: info: Preparing to generate the ALSA configuration file
Feb 10 18:23:27 volumio volumio[30643]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:23:27 volumio volumio[30643]: info: CoreStateMachine::pushState
Feb 10 18:23:27 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::volumioPushState
Feb 10 18:23:27 volumio volumio[30643]: info: Asound.conf file unchanged, so no further update is needed
Feb 10 18:23:27 volumio volumio[30643]: info: Output device has changed, restarting MPD
Feb 10 18:23:27 volumio sudo[30813]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 10 18:23:27 volumio sudo[30813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:27 volumio volumio[30643]: info: Output device has changed, restarting Shairport Sync
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:27 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:27 volumio sudo[30815]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 10 18:23:27 volumio sudo[30815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:28 volumio sudo[30813]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:28 volumio sudo[30815]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:28 volumio sudo[30818]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 10 18:23:28 volumio sudo[30818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:28 volumio volumio[30643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:23:28 volumio volumio[30643]: info: ___________ START PLUGINS ___________
Feb 10 18:23:28 volumio volumio[30643]: info: ControllerMpd::onStart: Initializing MPD
Feb 10 18:23:28 volumio volumio[30643]: info: Creating MPD Configuration file
Feb 10 18:23:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:23:28 volumio volumio[30643]: info: [1770722608180] CoreMusicLibrary::Adding element Media Servers
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:28 volumio sudo[30827]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 10 18:23:28 volumio sudo[30827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:28 volumio sudo[30827]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:28 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 10 18:23:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 10 18:23:28 volumio systemd[1]: mpd.service: Consumed 7.162s CPU time.
Feb 10 18:23:28 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 10 18:23:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 10 18:23:28 volumio sudo[30828]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 10 18:23:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 10 18:23:28 volumio sudo[30828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:28 volumio volumio[30643]: info: UPNP Browser: Client initialized successfully
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 10 18:23:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 10 18:23:28 volumio volumio[30643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:28 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 10 18:23:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 10 18:23:28 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 10 18:23:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 10 18:23:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 10 18:23:28 volumio volumio[30643]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:23:28 volumio volumio[30643]: info: [1770722608555] CoreMusicLibrary::Adding element Last_100
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:23:28 volumio volumio[30643]: info: [1770722608564] CoreMusicLibrary::Adding element Webradio
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:23:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 10 18:23:28 volumio volumio[30643]: info: Initializing BBC Radios
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:28 volumio volumio[30643]: info: Creating Spotify config file
Feb 10 18:23:28 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:29 volumio sudo[30842]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 10 18:23:29 volumio sudo[30842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 10 18:23:29 volumio sudo[30842]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Feb 10 18:23:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:29 volumio go-librespot[30858]: go-librespot daemon starting...
Feb 10 18:23:29 volumio go-librespot[30859]: time="2026-02-10T18:23:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:29 volumio volumio[30769]: Starting albumart workers
Feb 10 18:23:30 volumio volumio[30766]: Starting albumart workers
Feb 10 18:23:30 volumio go-librespot[30859]: time="2026-02-10T18:23:30+07:00" level=info msg="zeroconf server listening on port 40449"
Feb 10 18:23:30 volumio volumio[30643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:23:30 volumio volumio[30643]: info: [1770722610437] CoreMusicLibrary::Adding element YouTube Music
Feb 10 18:23:30 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:30 volumio volumio[30643]: Cannot find translation for source YouTube Music
Feb 10 18:23:30 volumio volumio[30643]: info: Volumio Calling Home
Feb 10 18:23:30 volumio volumio[30768]: Starting albumart workers
Feb 10 18:23:30 volumio sudo[30868]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 10 18:23:30 volumio sudo[30868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:30 volumio sudo[30868]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:31 volumio volumio[30643]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 10 18:23:31 volumio volumio[30643]: info: Discovery: Found device Volumio
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:31 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:31 volumio volumio[30643]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 10 18:23:31 volumio volumio[30643]: info: Discovery: Found device Volumio
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:31 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:31 volumio volumio[30643]: info: MPD Permissions set
Feb 10 18:23:31 volumio volumio[30643]: info: MPD Permissions set
Feb 10 18:23:31 volumio volumio[30643]: info: Upmpdcli Daemon Started
Feb 10 18:23:31 volumio volumio[30643]: info: Volumio called home
Feb 10 18:23:31 volumio volumio[30643]: info: Spotify config file written
Feb 10 18:23:31 volumio volumio[30643]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 10 18:23:31 volumio sudo[30876]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 10 18:23:31 volumio sudo[30876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 10 18:23:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:31 volumio go-librespot[30884]: go-librespot daemon starting...
Feb 10 18:23:31 volumio sudo[30876]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:23:31 volumio volumio[30643]: info: No need to fix Spotify hosts
Feb 10 18:23:31 volumio go-librespot[30889]: time="2026-02-10T18:23:31+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:31 volumio go-librespot[30889]: time="2026-02-10T18:23:31+07:00" level=debug msg="app state loaded"
Feb 10 18:23:31 volumio go-librespot[30889]: time="2026-02-10T18:23:31+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:32 volumio go-librespot[30889]: time="2026-02-10T18:23:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:23:32 volumio go-librespot[30889]: time="2026-02-10T18:23:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:23:32 volumio go-librespot[30889]: time="2026-02-10T18:23:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:23:32 volumio go-librespot[30889]: time="2026-02-10T18:23:32+07:00" level=info msg="zeroconf server listening on port 40677"
Feb 10 18:23:32 volumio go-librespot[30889]: time="2026-02-10T18:23:32+07:00" level=debug msg="obtained new client token: AACYUGz7rzlY0Aygcxg+mVogEIpeIVybqc4WWw+ZDB+MyZIuaUHRELKkFbaXJOCjkt5ddQeo5riFv8XCeGkzjQzW9v8VwnXtMmMWpYz2X4gXt43WUqn+V6UbRATPlKADVcYxbtJz3Eavlw4QkXK+si7nYjxrPYBK7z6JpNFkWRCWAnXt6Z+ds4HWasfDBArKuVgNHOpcgELqs18akZparU5QOzY5DSQvTrtwPauP7ubftc18BN5NWT7F+w=="
Feb 10 18:23:33 volumio volumio[30643]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 10 18:23:33 volumio volumio[30643]: SPOTIFY: BQDyBKrKvAUVCCiwgIqj4Rf0RLb2Za7geFYUZr1wqGBLQKtSYcjMMQQrLCokl233xAE1dMSPaYizzi1lZuefTJw4WF039bzLAEVVclPF5b61vZiesMAHmspRNR6x9bpnMBT5yAWZV0hOVG8XJq4jFbmp80x5zUZYFFlaQto_67O9ZfEg7BduFUkcH0ioNKKw0pkVMkuHrc_wgdqGmshwxjLPPtnuqbyYV9tqbqDaN6SPU71BRBTmdM_SDbFWY_lU5-y4XQ1zCbo3NgCmo2Z7JuCMvdJYEYxb7FUg1XLiCM1KPeTpQrEzweFQ
Feb 10 18:23:33 volumio volumio[30643]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 10 18:23:33 volumio volumio[30643]: info: New Spotify access token = BQDyBKrKvAUVCCiwgIqj4Rf0RLb2Za7geFYUZr1wqGBLQKtSYcjMMQQrLCokl233xAE1dMSPaYizzi1lZuefTJw4WF039bzLAEVVclPF5b61vZiesMAHmspRNR6x9bpnMBT5yAWZV0hOVG8XJq4jFbmp80x5zUZYFFlaQto_67O9ZfEg7BduFUkcH0ioNKKw0pkVMkuHrc_wgdqGmshwxjLPPtnuqbyYV9tqbqDaN6SPU71BRBTmdM_SDbFWY_lU5-y4XQ1zCbo3NgCmo2Z7JuCMvdJYEYxb7FUg1XLiCM1KPeTpQrEzweFQ
Feb 10 18:23:33 volumio volumio[30643]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 10 18:23:33 volumio go-librespot[30889]: time="2026-02-10T18:23:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:33 volumio volumio[30643]: info: Starting Shairport Sync
Feb 10 18:23:33 volumio volumio[30643]: info: Starting Shairport Sync
Feb 10 18:23:33 volumio go-librespot[30889]: time="2026-02-10T18:23:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:23:33 volumio volumio[30643]: info: Starting Shairport Sync
Feb 10 18:23:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:33 volumio sudo[30915]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:23:33 volumio sudo[30917]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:23:33 volumio sudo[30917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:33 volumio sudo[30915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:33 volumio sudo[30919]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:23:33 volumio sudo[30919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 10 18:23:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 10 18:23:33 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:33 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 10 18:23:33 volumio systemd[1]: shairport-sync.service: Consumed 2.336s CPU time.
Feb 10 18:23:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 10 18:23:33 volumio sudo[30915]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:33 volumio sudo[30919]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:33 volumio sudo[30917]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:33 volumio volumio[30643]: info: Shairport-Sync Started
Feb 10 18:23:33 volumio volumio[30643]: Error adding Membership: Error: addMembership EINVAL
Feb 10 18:23:33 volumio volumio[30643]: info: Shairport-Sync Started
Feb 10 18:23:33 volumio volumio[30643]: info: Shairport-Sync Started
Feb 10 18:23:33 volumio volumio[30643]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 10 18:23:33 volumio volumio[30643]: info: Spotify Successfully logged in
Feb 10 18:23:33 volumio volumio[30643]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:23:33 volumio volumio[30643]: info: [1770722613753] CoreMusicLibrary::Adding element Spotify
Feb 10 18:23:33 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:23:33 volumio volumio[30643]: Cannot find translation for source YouTube Music
Feb 10 18:23:33 volumio volumio[30643]: Cannot find translation for source Spotify
Feb 10 18:23:34 volumio volumio[30643]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 10 18:23:34 volumio volumio[30643]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:23:34 volumio volumio[30643]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:23:34 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:34 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:34 volumio volumio[30643]: info: CoreStateMachine::pushState
Feb 10 18:23:34 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:34 volumio volumio[30643]: info: CoreCommandRouter::volumioPushState
Feb 10 18:23:35 volumio volumio[30643]: info: go-librespot daemon successfully initialized
Feb 10 18:23:36 volumio mpd[30857]: 2026-02-10T18:23:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 10 18:23:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 10 18:23:36 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 10 18:23:36 volumio sudo[30818]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:36 volumio sudo[30828]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:36 volumio go-librespot[30958]: go-librespot daemon starting...
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=debug msg="app state loaded"
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:36 volumio volumio[30643]: error: MPD error: The expression evaluated to a falsy value:
Feb 10 18:23:36 volumio volumio[30643]:   assert.ok(self.idling)
Feb 10 18:23:36 volumio volumio[30643]: error: The expression evaluated to a falsy value:
Feb 10 18:23:36 volumio volumio[30643]:   assert.ok(self.idling)
Feb 10 18:23:36 volumio volumio[30643]: info: MPD running with PID30857
Feb 10 18:23:36 volumio volumio[30643]:  ,establishing connection
Feb 10 18:23:36 volumio volumio[30643]: error: updateQueue error: null
Feb 10 18:23:36 volumio volumio[30643]: info: Completed starting Core Plugins
Feb 10 18:23:36 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:36 volumio volumio[30643]: info: -----    MyVolumio plugins startup     ----
Feb 10 18:23:36 volumio volumio[30643]: info: -------------------------------------------
Feb 10 18:23:36 volumio volumio[30643]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 10 18:23:36 volumio volumio[30643]: error: updateQueue error: null
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:36 volumio go-librespot[30961]: time="2026-02-10T18:23:36+07:00" level=info msg="zeroconf server listening on port 36805"
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=debug msg="obtained new client token: AAAfmFUKyLJ93QjqyOTqZtlr7x071sb6YzMRUYAvqBOUl3ppHT4O+A6YzAFNVuCmrTjjQuHFcyN/Js9GQZBvjkGOECBm68tS18vf5ASwlOlR9oFvAKcXctmIPEs8UdOaipvgEYXU5XdLzbIYEasaF59D0GBQOA2vJij/atqJzCO5n8zei7QxDhwXyKt0eigIceKNuPss8scIAwvu4Ps+JZZ8iD9Jnl44mEOUKo7k0+rK13fv1B8RyAo="
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=debug msg="completed challenge"
Feb 10 18:23:37 volumio go-librespot[30961]: time="2026-02-10T18:23:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:38 volumio volumio[30643]: info: Initializing connection to go-librespot Websocket
Feb 10 18:23:39 volumio volumio[30643]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:23:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 10 18:23:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:40 volumio go-librespot[30968]: go-librespot daemon starting...
Feb 10 18:23:40 volumio go-librespot[30969]: time="2026-02-10T18:23:40+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:40 volumio go-librespot[30969]: time="2026-02-10T18:23:40+07:00" level=debug msg="app state loaded"
Feb 10 18:23:40 volumio go-librespot[30969]: time="2026-02-10T18:23:40+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=info msg="zeroconf server listening on port 45181"
Feb 10 18:23:41 volumio volumio[30643]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=debug msg="obtained new client token: AAC4rnYnhuuQvZrdQX7WTL429L6VUXqvNwdt3Va6Il1NI/eyQeoXekrMkTYZEZW1ehjTaeu2XLv89+TdQgmRzjwgU90u+CgGwDUV1cTj9x7xSDNHTLuuK/afAW5fkvtRjcalk0f61gFtgVe8exBw3hNg+Gda+kSBExbn05b6XnI3vYe4RCgUG8bSLlk2o1fH3JvNIaOtD6EeFxpjgpd7SSaZN9IM+ZhtEhcGW6jPhUAluv+EWKqGt4QuZA=="
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:41 volumio go-librespot[30969]: time="2026-02-10T18:23:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:23:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:42 volumio volumio[30643]: info: Initializing connection to go-librespot Websocket
Feb 10 18:23:42 volumio volumio[30643]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:23:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 10 18:23:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:44 volumio go-librespot[30977]: go-librespot daemon starting...
Feb 10 18:23:44 volumio go-librespot[30978]: time="2026-02-10T18:23:44+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:44 volumio go-librespot[30978]: time="2026-02-10T18:23:44+07:00" level=debug msg="app state loaded"
Feb 10 18:23:44 volumio go-librespot[30978]: time="2026-02-10T18:23:44+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:45 volumio volumio[30643]: info: Initializing connection to go-librespot Websocket
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="new websocket client"
Feb 10 18:23:45 volumio volumio[30643]: info: Connection to go-librespot Websocket established
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=info msg="zeroconf server listening on port 42003"
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin multiroom to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 10 18:23:45 volumio volumio[30643]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="obtained new client token: AACN52tdu59OO8qt3x11lAbLPc/ndwRT99tmyQtujq2M4GzNPDVSk+tBRCeCuuC87qCF+DmF/myAiWZyCXzjYuOjd9zr1W/1p3Di5Blyvj/CQsnL+RDVxBTI5uk/eFHU5vP24g6sd0hAO6Jl/ptsjsAGqGQHGwNdYPAyv9lpKi0qn6q0mzwyGgyfzOJlnwT/00HyFqFcOO9ZgrGkc1ANehrf/nbk4AhAracQuoROqW3ylNDs/Rk3PGXwvA=="
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=debug msg="completed challenge"
Feb 10 18:23:45 volumio go-librespot[30978]: time="2026-02-10T18:23:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:47 volumio volumio[30643]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 10 18:23:47 volumio volumio[30643]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 10 18:23:47 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:47 volumio volumio[30643]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:23:47 volumio volumio[30643]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 10 18:23:47 volumio volumio[30643]: info: MyVolumio login type: Token
Feb 10 18:23:47 volumio volumio[30643]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 10 18:23:47 volumio volumio[30643]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 10 18:23:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 10 18:23:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:48 volumio go-librespot[30999]: go-librespot daemon starting...
Feb 10 18:23:48 volumio volumio[30643]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 10 18:23:48 volumio volumio[30643]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 10 18:23:48 volumio volumio[30643]: info: Streaming services startup
Feb 10 18:23:48 volumio go-librespot[31000]: time="2026-02-10T18:23:48+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:48 volumio volumio[30643]: info: Starting Streaming Daemon
Feb 10 18:23:48 volumio go-librespot[31000]: time="2026-02-10T18:23:48+07:00" level=debug msg="app state loaded"
Feb 10 18:23:48 volumio go-librespot[31000]: time="2026-02-10T18:23:48+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:49 volumio sudo[31007]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 10 18:23:49 volumio sudo[31007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:49 volumio volumio[30643]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 10 18:23:49 volumio sudo[31007]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:49 volumio volumio[30643]: info: Getting Spotify volume
Feb 10 18:23:49 volumio volumio[30643]: info: Connection to go-librespot Websocket closed
Feb 10 18:23:49 volumio volumio[30643]: error: Cannot start Volumio Streaming Daemon
Feb 10 18:23:49 volumio volumio[30643]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 10 18:23:49 volumio volumio[30643]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 10 18:23:49 volumio volumio[30643]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 10 18:23:49 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:49 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:49 volumio volumio[30643]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 10 18:23:49 volumio volumio[30643]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 10 18:23:49 volumio volumio[30643]: SPOTIFY: VOLUMIO VOLUME 100
Feb 10 18:23:49 volumio volumio[30643]: info: Aligning Spotify Volume to Volumio Volume
Feb 10 18:23:49 volumio volumio[30643]: info: CoreCommandRouter::volumioGetState
Feb 10 18:23:49 volumio volumio[30643]: info: CorePlayQueue::getTrack 0
Feb 10 18:23:49 volumio volumio[30643]: info: Setting Spotify Volume from Volumio: 100
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=info msg="zeroconf server listening on port 35563"
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=debug msg="obtained new client token: AAAy786SNp3Yv4Dq65ylYZM7FbSs5Zr5pI+gxf0EGLp0GPIbmFRC/N/+0Hg4QJbpn81afbFSpQQQ/y2V2ErIX8Oq/a3wbratIgM/4ATdG6h+Mby8papaqdiNGbKB0TA8Tot7JI5GrZD0LgN6DGXv8p7FE5i/oQmifHvfpY/MmnLX3C+YtoJFoPID/nIoFJxXKBmQVc8PXDV3vQBnfnTblchChatD9iAIPqTPVHDjtK6cewOQGP555RGq1w=="
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:49 volumio go-librespot[31000]: time="2026-02-10T18:23:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:23:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:49 volumio volumio[30643]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:23:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:49 volumio volumio[30643]: Error: socket hang up
Feb 10 18:23:49 volumio volumio[30643]:     at connResetException (node:internal/errors:720:14)
Feb 10 18:23:49 volumio volumio[30643]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 10 18:23:49 volumio volumio[30643]:     at Socket.emit (node:events:526:35)
Feb 10 18:23:49 volumio volumio[30643]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 10 18:23:49 volumio volumio[30643]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 10 18:23:49 volumio volumio[30643]:   code: 'ECONNRESET',
Feb 10 18:23:49 volumio volumio[30643]:   response: undefined
Feb 10 18:23:49 volumio volumio[30643]: }
Feb 10 18:23:49 volumio volumio[30643]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:23:51 volumio sudo[31028]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 18:22'
Feb 10 18:23:51 volumio sudo[31028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:51 volumio sudo[31028]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:51 volumio volumio-remote-updater[643]: [2026-02-10 18:23:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 10 18:23:51 volumio volumio-remote-updater[643]: [2026-02-10 18:23:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 10 18:23:51 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:51 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 10 18:23:51 volumio systemd[1]: volumio.service: Consumed 55.450s CPU time.
Feb 10 18:23:52 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 10 18:23:52 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 10 18:23:52 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10587.
Feb 10 18:23:52 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 10 18:23:52 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 10 18:23:52 volumio systemd[1]: volumio.service: Consumed 55.450s CPU time.
Feb 10 18:23:52 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 10 18:23:52 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 10 18:23:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 10 18:23:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:53 volumio go-librespot[31059]: go-librespot daemon starting...
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=debug msg="app state loaded"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:23:53 volumio go-librespot[31060]: time="2026-02-10T18:23:53+07:00" level=info msg="zeroconf server listening on port 37197"
Feb 10 18:23:54 volumio go-librespot[31060]: time="2026-02-10T18:23:54+07:00" level=debug msg="obtained new client token: AACU252W/+ZCU42xH9BgTQq5bCkJtbQhPP9pl92ZUt6bO9G9jI8huS11+1HaYhvABUQodvXQZ1xnPl9sVHN8KXK8mYQ6H2hCEKtquBvw0aGduK9O2Hv/3Y27Xh/yCYMeDBB0Few5WmCgdBW6z7lIrxe+czajGn2qeafN+UZpRec1YhKYSFz3YaOz86QjdPcoCwiXZlv9nXb4aGRpryb6IBErnx44tl6fkpWLxwMau3MOE8EZrvy5CY+jEA=="
Feb 10 18:23:54 volumio go-librespot[31060]: time="2026-02-10T18:23:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:54 volumio go-librespot[31060]: time="2026-02-10T18:23:54+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:54 volumio go-librespot[31060]: time="2026-02-10T18:23:54+07:00" level=debug msg="completed challenge"
Feb 10 18:23:54 volumio go-librespot[31060]: time="2026-02-10T18:23:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:55 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:23:55 volumio volumio[31044]: info: -----            Volumio3              ----
Feb 10 18:23:55 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:23:55 volumio volumio[31044]: info: -----          System startup          ----
Feb 10 18:23:55 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:23:56 volumio volumio-remote-updater[643]: [2026-02-10 18:23:56] [connect] Successful connection
Feb 10 18:23:57 volumio volumio[31044]: info: MYVOLUMIO Environment detected
Feb 10 18:23:57 volumio volumio[31044]: info: Plugin folders cleanup
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning into folder /volumio/app/plugins/
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category audio_interface
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category miscellanea
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category music_service
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category plugins.json
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category system_controller
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category user_interface
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning into folder /data/plugins/
Feb 10 18:23:57 volumio volumio[31044]: info: Scanning category music_service
Feb 10 18:23:57 volumio volumio[31044]: info: Plugin folders cleanup completed
Feb 10 18:23:57 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:23:57 volumio volumio[31044]: info: -----      Core plugins startup        ----
Feb 10 18:23:57 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:23:57 volumio volumio[31044]: info: Loading plugins from folder /volumio/app/plugins/
Feb 10 18:23:57 volumio volumio[31044]: info: Adding plugin upnp to MyMusic Plugins
Feb 10 18:23:57 volumio volumio[31044]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 10 18:23:57 volumio volumio[31044]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 10 18:23:57 volumio volumio[31044]: info: Loading plugins from folder /data/plugins/
Feb 10 18:23:57 volumio volumio[31044]: info: Loading plugin "system"...
Feb 10 18:23:57 volumio volumio[31044]: info: Loading plugin "appearance"...
Feb 10 18:23:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 10 18:23:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:23:57 volumio go-librespot[31080]: go-librespot daemon starting...
Feb 10 18:23:57 volumio go-librespot[31081]: time="2026-02-10T18:23:57+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:23:57 volumio go-librespot[31081]: time="2026-02-10T18:23:57+07:00" level=debug msg="app state loaded"
Feb 10 18:23:57 volumio go-librespot[31081]: time="2026-02-10T18:23:57+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=info msg="zeroconf server listening on port 44955"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="obtained new client token: AADaa7M7hON63OqS89l5XfDUdgvJCSrWbD/loTOlIYNtLEb1g1iyE+9K+O35I40dYqCHJcpzsKFbCAGIYr3xUYelif3ZFof5mKi5DTAiaTKPJEEbEk7Vs99Y2yN0hgNpS2/fvjovyuwWDJjLCS4207bB8HTgb3WpDJ6qw+OfBnTWlp1fQVltlZlN5iurgeB/YJNSsMOJlt5iNU0/9GWvQoEOvlZQHgSrGhALfqzz1Lmx907SjPiS8kGkLQ=="
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="completed keyexchange"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=debug msg="completed challenge"
Feb 10 18:23:58 volumio go-librespot[31081]: time="2026-02-10T18:23:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:23:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:23:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "network"...
Feb 10 18:23:59 volumio volumio[31044]: info: Refreshing Cached IP Addresses
Feb 10 18:23:59 volumio sudo[31090]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 10 18:23:59 volumio sudo[31090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:59 volumio sudo[31092]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 10 18:23:59 volumio sudo[31092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "services"...
Feb 10 18:23:59 volumio sudo[31090]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "alsa_controller"...
Feb 10 18:23:59 volumio sudo[31092]: pam_unix(sudo:session): session closed for user root
Feb 10 18:23:59 volumio sudo[31099]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 10 18:23:59 volumio sudo[31099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:23:59 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "wizard"...
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "networkfs"...
Feb 10 18:23:59 volumio volumio[31044]: info: Starting Udev Watcher for removable devices
Feb 10 18:23:59 volumio volumio[31044]: info: Ignoring mount for partition: boot
Feb 10 18:23:59 volumio volumio[31044]: info: Ignoring mount for partition: volumio
Feb 10 18:23:59 volumio volumio[31044]: info: Ignoring mount for partition: volumio_data
Feb 10 18:23:59 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "volumio_command_line_client"...
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "upnp"...
Feb 10 18:23:59 volumio volumio[31044]: info: [1770722639766] Starting Upmpd Daemon
Feb 10 18:23:59 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "my_music"...
Feb 10 18:23:59 volumio volumio[31044]: info: Loading plugin "mpd"...
Feb 10 18:24:00 volumio volumio[31044]: info: Loading plugin "upnp_browser"...
Feb 10 18:24:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 10 18:24:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:01 volumio go-librespot[31125]: go-librespot daemon starting...
Feb 10 18:24:01 volumio go-librespot[31126]: time="2026-02-10T18:24:01+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:01 volumio go-librespot[31126]: time="2026-02-10T18:24:01+07:00" level=debug msg="app state loaded"
Feb 10 18:24:01 volumio go-librespot[31126]: time="2026-02-10T18:24:01+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:02 volumio sudo[31099]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=info msg="zeroconf server listening on port 41007"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="obtained new client token: AAAOdyR1oDBS/y4XKTg72q2siAajyqhfYJ4NmiKJBlExZW4Awpb9PwZMp/IVDH1PEFVOcdiJVpcszLux0nYCK1AL9aLWHONsQqm5LSCjYRmCV+gdIXbgEMAP+/QaF3mvHuSaynZqCWDgEVJO6fp5SW8fnnfdOy3d2EZSdWtkDhTcjhmbStBOui6TBiid8wqqXItCniuEG9EnJqpIoyGX4TvUlhL0ATzkFxtkm9SyTaEA1ykQF+r6BoLuYw=="
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:02 volumio go-librespot[31126]: time="2026-02-10T18:24:02+07:00" level=debug msg="completed challenge"
Feb 10 18:24:03 volumio go-librespot[31126]: time="2026-02-10T18:24:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:03 volumio volumio[31044]: info: Starting UPNP Browser
Feb 10 18:24:03 volumio volumio[31044]: info: Loading plugin "alarm-clock"...
Feb 10 18:24:03 volumio volumio[31044]: info: Loading plugin "airplay_emulation"...
Feb 10 18:24:03 volumio volumio[31044]: info: Starting Shairport Sync
Feb 10 18:24:03 volumio volumio[31044]: info: Loading plugin "last_100"...
Feb 10 18:24:03 volumio volumio[31044]: info: Loading plugin "webradio"...
Feb 10 18:24:04 volumio volumio[31044]: info: Loading plugin "i2s_dacs"...
Feb 10 18:24:04 volumio volumio[31044]: info: Loading plugin "volumiodiscovery"...
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** For more information see 
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:24:04 volumio volumio[31044]: *** WARNING *** For more information see 
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** For more information see 
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 10 18:24:04 volumio node[31044]: *** WARNING *** For more information see 
Feb 10 18:24:04 volumio volumio[31044]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 10 18:24:04 volumio volumio[31044]: info: Discovery: Started advertising with name: Volumio
Feb 10 18:24:04 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 10 18:24:04 volumio volumio[31044]: info: Loading plugin "spop"...
Feb 10 18:24:05 volumio volumio[31044]: info: Loading plugin "ytcr"...
Feb 10 18:24:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 10 18:24:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:06 volumio go-librespot[31137]: go-librespot daemon starting...
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=debug msg="app state loaded"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:24:06 volumio go-librespot[31138]: time="2026-02-10T18:24:06+07:00" level=info msg="zeroconf server listening on port 40729"
Feb 10 18:24:07 volumio go-librespot[31138]: time="2026-02-10T18:24:07+07:00" level=debug msg="obtained new client token: AAC+hTJTCvHbC0aGhrvFHKKWSSALXa1dgSKr7NYBc0lZvZ9Tb4AOtDM032IhJPubm4fWNr+Wnbz8L0sxJNj5EaFPQNag8rRFQffItstjqLL9g0ZnjJ5qCmEYBS4X1hJQ7I2HXrE2mUdUrHAgPmLQQYm+mHRLUyNoUN6ojETsG6cJvafP+fXcr6jPRKaZzb6pmXxHmBQd8iAV3lIvjm2yiNFOI3sKPnIZ0vD6j9/HOceDmlzjU74w65I="
Feb 10 18:24:07 volumio go-librespot[31138]: time="2026-02-10T18:24:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:07 volumio go-librespot[31138]: time="2026-02-10T18:24:07+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:07 volumio go-librespot[31138]: time="2026-02-10T18:24:07+07:00" level=debug msg="completed challenge"
Feb 10 18:24:07 volumio go-librespot[31138]: time="2026-02-10T18:24:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:08 volumio volumio[31044]: info: Loading plugin "ytmusic"...
Feb 10 18:24:09 volumio volumio-remote-updater[643]: [2026-02-10 18:24:09] [connect] Successful connection
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "outputs"...
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "albumart"...
Feb 10 18:24:09 volumio volumio[31044]: info: Plugin example_plugin is not enabled
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "inputs"...
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "updater_comm"...
Feb 10 18:24:09 volumio volumio[31044]: info: Plugin mpdemulation is not enabled
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "rest_api"...
Feb 10 18:24:09 volumio volumio[31044]: info: Loading plugin "websocket"...
Feb 10 18:24:10 volumio volumio[31044]: info: Starting Socket.io Server version 1.7.4
Feb 10 18:24:10 volumio volumio[31044]: info: Loading plugin "RoonBridge"...
Feb 10 18:24:10 volumio volumio[31044]: info: Applying required configuration parameters for plugin RoonBridge
Feb 10 18:24:10 volumio volumio[31044]: info: Loading i18n strings for locale en
Feb 10 18:24:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 10 18:24:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:10 volumio volumio[31044]: Updating browse sources language
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:10 volumio go-librespot[31170]: go-librespot daemon starting...
Feb 10 18:24:10 volumio go-librespot[31171]: time="2026-02-10T18:24:10+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:10 volumio go-librespot[31171]: time="2026-02-10T18:24:10+07:00" level=debug msg="app state loaded"
Feb 10 18:24:10 volumio go-librespot[31171]: time="2026-02-10T18:24:10+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::initPlayerControls
Feb 10 18:24:10 volumio volumio[31160]: Forking 3 albumart workers
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:24:10 volumio volumio[31044]: Express server listening on port 3000
Feb 10 18:24:10 volumio volumio[31044]:  [Metrics]  WebUI:  16s 54.45ms 
Feb 10 18:24:10 volumio volumio[31044]: info: CoreStateMachine::resetVolumioState
Feb 10 18:24:10 volumio volumio[31044]: info: CoreStateMachine::getcurrentVolume
Feb 10 18:24:10 volumio volumio[31044]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:24:11 volumio sudo[31210]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 10 18:24:11 volumio sudo[31210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:11 volumio sudo[31212]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 10 18:24:11 volumio sudo[31212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:11 volumio sudo[31212]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:11 volumio sudo[31210]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:11 volumio volumio[31044]: info: Volumio Network Manager: Network status updated: 1
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=info msg="zeroconf server listening on port 38045"
Feb 10 18:24:11 volumio volumio[31044]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::pushState
Feb 10 18:24:11 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::volumioPushState
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::updateTrackBlock
Feb 10 18:24:11 volumio volumio[31044]: info: CorePlayQueue::getTrackBlock
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="obtained new client token: AAANaiPGN7IOK/kLGxvvr3+mAdwXbAZb2203ysZPikCZdPSRuNHSeEsrCPZeG1hGM3wsM8GUXD1OtNq5lop26PmnZ1z/lrMHpQLIzKWIXl5+mDVmwP7VRezF0LOMKySVVllroT/I43lPc+DpYxBaykUVWOdsT2abt2xdT6hYXACx5wjwnqfKshguJWkIAOPvxEF9LuLE4ZWAQi2UbxY3derVQ8vf0aRsUDrObVdl7807Z75CQeezp82rJg=="
Feb 10 18:24:11 volumio volumio-remote-updater[643]: [2026-02-10 18:24:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770722649 101
Feb 10 18:24:11 volumio volumio[31044]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:11 volumio volumio[31044]: info: Reloading queue from file
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::setRepeat null single undefined
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::pushState
Feb 10 18:24:11 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::volumioPushState
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::setRandom null
Feb 10 18:24:11 volumio volumio[31044]: info: CoreStateMachine::pushState
Feb 10 18:24:11 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:11 volumio volumio[31044]: info: CoreCommandRouter::volumioPushState
Feb 10 18:24:11 volumio volumio[31044]: info: Setting Device type: Raspberry PI
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:11 volumio go-librespot[31171]: time="2026-02-10T18:24:11+07:00" level=debug msg="completed challenge"
Feb 10 18:24:11 volumio volumio[31044]: info: Completed loading Core Plugins
Feb 10 18:24:11 volumio volumio[31044]: info: Preparing to generate the ALSA configuration file
Feb 10 18:24:12 volumio go-librespot[31171]: time="2026-02-10T18:24:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:12 volumio volumio[31044]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:24:12 volumio volumio[31044]: info: CoreStateMachine::pushState
Feb 10 18:24:12 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::volumioPushState
Feb 10 18:24:12 volumio volumio[31044]: info: Asound.conf file unchanged, so no further update is needed
Feb 10 18:24:12 volumio volumio[31044]: info: Output device has changed, restarting MPD
Feb 10 18:24:12 volumio sudo[31232]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 10 18:24:12 volumio sudo[31232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:12 volumio volumio[31044]: info: Output device has changed, restarting Shairport Sync
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:12 volumio sudo[31235]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 10 18:24:12 volumio sudo[31235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:12 volumio sudo[31235]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:12 volumio sudo[31232]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:12 volumio sudo[31237]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 10 18:24:12 volumio sudo[31237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:12 volumio volumio[31044]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:24:12 volumio volumio[31044]: info: ___________ START PLUGINS ___________
Feb 10 18:24:12 volumio volumio[31044]: info: ControllerMpd::onStart: Initializing MPD
Feb 10 18:24:12 volumio volumio[31044]: info: Creating MPD Configuration file
Feb 10 18:24:12 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 10 18:24:12 volumio sudo[31245]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 10 18:24:12 volumio sudo[31245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 10 18:24:12 volumio sudo[31245]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:24:12 volumio volumio[31044]: info: [1770722652500] CoreMusicLibrary::Adding element Media Servers
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:12 volumio sudo[31247]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 10 18:24:12 volumio sudo[31247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:12 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 10 18:24:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 10 18:24:12 volumio systemd[1]: mpd.service: Consumed 7.207s CPU time.
Feb 10 18:24:12 volumio volumio[31044]: info: UPNP Browser: Client initialized successfully
Feb 10 18:24:12 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 10 18:24:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 10 18:24:12 volumio volumio[31044]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 10 18:24:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 10 18:24:12 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 10 18:24:12 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 10 18:24:12 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 10 18:24:12 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 10 18:24:12 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 10 18:24:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 10 18:24:12 volumio volumio[31044]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:24:12 volumio volumio[31044]: info: [1770722652865] CoreMusicLibrary::Adding element Last_100
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:24:12 volumio volumio[31044]: info: [1770722652888] CoreMusicLibrary::Adding element Webradio
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:12 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:24:12 volumio volumio[31044]: info: Initializing BBC Radios
Feb 10 18:24:13 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:24:13 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:13 volumio volumio[31044]: info: Creating Spotify config file
Feb 10 18:24:13 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:13 volumio sudo[31261]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 10 18:24:13 volumio sudo[31261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 10 18:24:13 volumio sudo[31261]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:14 volumio volumio[31178]: Starting albumart workers
Feb 10 18:24:14 volumio volumio[31177]: Starting albumart workers
Feb 10 18:24:14 volumio volumio[31180]: Starting albumart workers
Feb 10 18:24:14 volumio volumio[31044]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:24:14 volumio volumio[31044]: info: [1770722654383] CoreMusicLibrary::Adding element YouTube Music
Feb 10 18:24:14 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:14 volumio volumio[31044]: Cannot find translation for source YouTube Music
Feb 10 18:24:14 volumio volumio[31044]: info: Volumio Calling Home
Feb 10 18:24:14 volumio sudo[31278]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 10 18:24:14 volumio sudo[31278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:14 volumio sudo[31278]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 10 18:24:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:15 volumio go-librespot[31283]: go-librespot daemon starting...
Feb 10 18:24:15 volumio volumio[31044]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 10 18:24:15 volumio volumio[31044]: info: Discovery: Found device Volumio
Feb 10 18:24:15 volumio volumio[31044]: info: CoreCommandRouter::volumioGetState
Feb 10 18:24:15 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:15 volumio volumio[31044]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 10 18:24:15 volumio go-librespot[31284]: time="2026-02-10T18:24:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:15 volumio go-librespot[31284]: time="2026-02-10T18:24:15+07:00" level=debug msg="app state loaded"
Feb 10 18:24:15 volumio go-librespot[31284]: time="2026-02-10T18:24:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:15 volumio volumio[31044]: info: Discovery: Found device Volumio
Feb 10 18:24:15 volumio volumio[31044]: info: CoreCommandRouter::volumioGetState
Feb 10 18:24:15 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:15 volumio volumio[31044]: info: MPD Permissions set
Feb 10 18:24:15 volumio volumio[31044]: info: MPD Permissions set
Feb 10 18:24:15 volumio volumio[31044]: info: Upmpdcli Daemon Started
Feb 10 18:24:15 volumio volumio[31044]: info: Spotify config file written
Feb 10 18:24:16 volumio sudo[31292]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 10 18:24:16 volumio sudo[31292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 10 18:24:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 10 18:24:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:16 volumio go-librespot[31300]: go-librespot daemon starting...
Feb 10 18:24:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:16 volumio volumio[31044]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 10 18:24:16 volumio sudo[31292]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio go-librespot[31302]: time="2026-02-10T18:24:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:16 volumio go-librespot[31302]: time="2026-02-10T18:24:16+07:00" level=debug msg="app state loaded"
Feb 10 18:24:16 volumio go-librespot[31302]: time="2026-02-10T18:24:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 10 18:24:16 volumio volumio[31044]: info: No need to fix Spotify hosts
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=info msg="zeroconf server listening on port 40865"
Feb 10 18:24:17 volumio volumio[31044]: info: Volumio called home
Feb 10 18:24:17 volumio volumio[31044]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 10 18:24:17 volumio volumio[31044]: SPOTIFY: BQA657MR9dtmnDOBUdk0beCKRy3OoncP1vdXD2JL80MAJ6-zCnzbXzxpLXhYPaC4kv7ykh18fEGlyem2x6ehc_xxGvTqqTffOeUNiGpIzZaF7fpCFujdNTsjjXPw3_FW9nrIrA7yANBOVRMQfHNPpYCof3__C54zXfj1l1YCQjB7tPiyK_IWVJNeGgMSRQtIp-kToRYoq0Zy3Btkydn6H9hkA-wzRbNeKXINcqVntrKvmEltZLaOe2JKFHbVsEtikq4L7Q7uDRi8xbb-FJvlAf-xi9439yp-NcH2NEug3vJx5tqjxzOFUgyj
Feb 10 18:24:17 volumio volumio[31044]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 10 18:24:17 volumio volumio[31044]: info: New Spotify access token = BQA657MR9dtmnDOBUdk0beCKRy3OoncP1vdXD2JL80MAJ6-zCnzbXzxpLXhYPaC4kv7ykh18fEGlyem2x6ehc_xxGvTqqTffOeUNiGpIzZaF7fpCFujdNTsjjXPw3_FW9nrIrA7yANBOVRMQfHNPpYCof3__C54zXfj1l1YCQjB7tPiyK_IWVJNeGgMSRQtIp-kToRYoq0Zy3Btkydn6H9hkA-wzRbNeKXINcqVntrKvmEltZLaOe2JKFHbVsEtikq4L7Q7uDRi8xbb-FJvlAf-xi9439yp-NcH2NEug3vJx5tqjxzOFUgyj
Feb 10 18:24:17 volumio volumio[31044]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 10 18:24:17 volumio volumio[31044]: info: Starting Shairport Sync
Feb 10 18:24:17 volumio volumio[31044]: info: Starting Shairport Sync
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="obtained new client token: AAA6esmzt+75UWewvm0j15swTPoHIpdDZy74FafQke3w8LRyxIWD8lA9nY4cHjL+KBDdGGC5eUSsDNzdrsnIFKicArH7IXgKtxDPLGQdM/WbBzGGYdcNb6AwNqo9sfA36lZmqrgDIM7gTxpGtmBjrXOh+NkE39YQsqnjnIAwWO1ckG1/vJhGPMbJ6QraxAEj1p5IPJxV9nAGabM3nE8OUyp8+e+ZPOIfMGwV8iScy21f5LDNPlaW4QpcJA=="
Feb 10 18:24:17 volumio volumio[31044]: info: Starting Shairport Sync
Feb 10 18:24:17 volumio sudo[31336]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:24:17 volumio sudo[31336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:17 volumio sudo[31335]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:24:17 volumio sudo[31333]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 10 18:24:17 volumio sudo[31335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:17 volumio sudo[31333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=debug msg="completed challenge"
Feb 10 18:24:17 volumio go-librespot[31302]: time="2026-02-10T18:24:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 10 18:24:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 10 18:24:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 10 18:24:17 volumio systemd[1]: shairport-sync.service: Consumed 2.246s CPU time.
Feb 10 18:24:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 10 18:24:17 volumio sudo[31333]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:17 volumio sudo[31336]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:17 volumio volumio[31044]: info: CoreCommandRouter::volumioGetState
Feb 10 18:24:17 volumio sudo[31335]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:17 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:17 volumio volumio[31044]: info: Shairport-Sync Started
Feb 10 18:24:17 volumio volumio[31044]: Error adding Membership: Error: addMembership EINVAL
Feb 10 18:24:18 volumio volumio[31044]: info: Shairport-Sync Started
Feb 10 18:24:18 volumio volumio[31044]: info: Shairport-Sync Started
Feb 10 18:24:18 volumio volumio[31044]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 10 18:24:18 volumio volumio[31044]: info: Spotify Successfully logged in
Feb 10 18:24:18 volumio volumio[31044]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 10 18:24:18 volumio volumio[31044]: info: [1770722658143] CoreMusicLibrary::Adding element Spotify
Feb 10 18:24:18 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 10 18:24:18 volumio volumio[31044]: Cannot find translation for source YouTube Music
Feb 10 18:24:18 volumio volumio[31044]: Cannot find translation for source Spotify
Feb 10 18:24:18 volumio volumio[31044]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 10 18:24:18 volumio volumio[31044]: info: CoreCommandRouter::volumioRetrievevolume
Feb 10 18:24:19 volumio volumio[31044]: info: VolumeController:: Volume=100 Mute =false
Feb 10 18:24:19 volumio volumio[31044]: info: CoreCommandRouter::volumioGetState
Feb 10 18:24:19 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:19 volumio volumio[31044]: info: CoreStateMachine::pushState
Feb 10 18:24:19 volumio volumio[31044]: info: CorePlayQueue::getTrack 0
Feb 10 18:24:19 volumio volumio[31044]: info: CoreCommandRouter::volumioPushState
Feb 10 18:24:20 volumio volumio[31044]: info: go-librespot daemon successfully initialized
Feb 10 18:24:20 volumio mpd[31276]: 2026-02-10T18:24:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 10 18:24:20 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 10 18:24:20 volumio sudo[31237]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:20 volumio sudo[31247]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:20 volumio volumio[31044]: error: MPD error: The expression evaluated to a falsy value:
Feb 10 18:24:20 volumio volumio[31044]:   assert.ok(self.idling)
Feb 10 18:24:20 volumio volumio[31044]: error: The expression evaluated to a falsy value:
Feb 10 18:24:20 volumio volumio[31044]:   assert.ok(self.idling)
Feb 10 18:24:20 volumio volumio[31044]: error: updateQueue error: null
Feb 10 18:24:20 volumio volumio[31044]: info: MPD running with PID31276
Feb 10 18:24:20 volumio volumio[31044]:  ,establishing connection
Feb 10 18:24:20 volumio volumio[31044]: info: Completed starting Core Plugins
Feb 10 18:24:20 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:24:20 volumio volumio[31044]: info: -----    MyVolumio plugins startup     ----
Feb 10 18:24:20 volumio volumio[31044]: info: -------------------------------------------
Feb 10 18:24:20 volumio volumio[31044]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 10 18:24:20 volumio volumio[31044]: error: updateQueue error: null
Feb 10 18:24:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 10 18:24:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:20 volumio go-librespot[31377]: go-librespot daemon starting...
Feb 10 18:24:20 volumio go-librespot[31378]: time="2026-02-10T18:24:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:20 volumio go-librespot[31378]: time="2026-02-10T18:24:20+07:00" level=debug msg="app state loaded"
Feb 10 18:24:20 volumio go-librespot[31378]: time="2026-02-10T18:24:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=info msg="zeroconf server listening on port 35111"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=debug msg="obtained new client token: AAAkYG5U1e0PuMLbMGAP3Y1Ti8wymP+sQ3TpaK3mIKyhF3OtPEjsS9GbRtxGy9bObLnNv5PaQ8mcVL2RlVGHmcGAyCbA2iVvqa+TW9kNqDpEmxeSDEmaaIW4bqaKEnFiETCRgfC5vGWB7Yzh2YsE6Z1dzHtGocFh8a0OIP3ZmGiyz7NWcJ2AbtxfDo2AafHaGcKSoRhIgFeEh3+vhBzO9pKofc+zoexQheTtP8K2AXRFHKtY0BQcjG4LcA=="
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 10 18:24:21 volumio go-librespot[31378]: time="2026-02-10T18:24:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:24:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:23 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:23 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 10 18:24:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:25 volumio go-librespot[31385]: go-librespot daemon starting...
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=debug msg="app state loaded"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:25 volumio volumio[31044]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=info msg="zeroconf server listening on port 35357"
Feb 10 18:24:25 volumio go-librespot[31386]: time="2026-02-10T18:24:25+07:00" level=debug msg="obtained new client token: AAAHE+kJnZM2Efwp6vuGjbhXEErWMmIzQziNTHirauXwRiMyGQMwvcE7GvI8lORerWTe347xRiZ1QvsuYNIVeRt51r6JkO5jXPLSatmGPp92OQosUxc4p64z3ROSd6wJWm4ChL/tAzWFJParTu0QANVnuVPMf5pUAZix5xW/r7sC6upheWrAHCGohV1QeJEI6Fe+oYvaMy4/55R1LjU5P48ymnJvBjj4vnQWaS+fFxEtdfxuvQIA/ucVsw=="
Feb 10 18:24:26 volumio go-librespot[31386]: time="2026-02-10T18:24:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:26 volumio go-librespot[31386]: time="2026-02-10T18:24:26+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:26 volumio go-librespot[31386]: time="2026-02-10T18:24:26+07:00" level=debug msg="completed challenge"
Feb 10 18:24:26 volumio go-librespot[31386]: time="2026-02-10T18:24:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:26 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:26 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 10 18:24:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:29 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:29 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:29 volumio go-librespot[31395]: go-librespot daemon starting...
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin multiroom to MyMusic Plugins
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=debug msg="app state loaded"
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:29 volumio volumio[31044]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 10 18:24:29 volumio volumio[31044]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 10 18:24:29 volumio go-librespot[31396]: time="2026-02-10T18:24:29+07:00" level=info msg="zeroconf server listening on port 40989"
Feb 10 18:24:30 volumio go-librespot[31396]: time="2026-02-10T18:24:30+07:00" level=debug msg="obtained new client token: AAA65+ULMl5bfJImhmNpW+h/O3n2oxw3gimxC/2yaqyMgP6SNdnPSRupEP9uiTXwNBttZ4YcKoO5pkiTkm0UB5cewKz8GoobVQlt+qtafQfMiUgzO1qh1Bd9lWOJ7dcdgSzh+w24tXYaY10qcs8Y+/NcuC9xk6KAT2k0crdT0YaeHPDm6uOBTJ4/Z8i90EvkGKzTx40ziSuCLqHLQUKzSn7gxPNWc0ntq9tdbkNId2DZErawxAQKuOw="
Feb 10 18:24:30 volumio go-librespot[31396]: time="2026-02-10T18:24:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:30 volumio go-librespot[31396]: time="2026-02-10T18:24:30+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:30 volumio go-librespot[31396]: time="2026-02-10T18:24:30+07:00" level=debug msg="completed challenge"
Feb 10 18:24:30 volumio go-librespot[31396]: time="2026-02-10T18:24:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:31 volumio volumio[31044]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 10 18:24:31 volumio volumio[31044]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 10 18:24:31 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:31 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:31 volumio volumio[31044]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 10 18:24:31 volumio volumio[31044]: info: MyVolumio login type: Token
Feb 10 18:24:31 volumio volumio[31044]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 10 18:24:31 volumio volumio[31044]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 10 18:24:33 volumio volumio[31044]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 10 18:24:33 volumio volumio[31044]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 10 18:24:33 volumio volumio[31044]: info: Streaming services startup
Feb 10 18:24:33 volumio volumio[31044]: info: Starting Streaming Daemon
Feb 10 18:24:33 volumio sudo[31422]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 10 18:24:33 volumio sudo[31422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:33 volumio volumio[31044]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 10 18:24:33 volumio sudo[31422]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:33 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:33 volumio volumio[31044]: error: Cannot start Volumio Streaming Daemon
Feb 10 18:24:33 volumio volumio[31044]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 10 18:24:33 volumio volumio[31044]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 10 18:24:33 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 10 18:24:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:33 volumio go-librespot[31428]: go-librespot daemon starting...
Feb 10 18:24:33 volumio go-librespot[31429]: time="2026-02-10T18:24:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:33 volumio go-librespot[31429]: time="2026-02-10T18:24:33+07:00" level=debug msg="app state loaded"
Feb 10 18:24:33 volumio go-librespot[31429]: time="2026-02-10T18:24:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=info msg="zeroconf server listening on port 45253"
Feb 10 18:24:34 volumio volumio[31044]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=debug msg="obtained new client token: AADw+kXwaCx7jO09I5NVlbB/yimbaIBqOZkc3+shsl33ezFQVNYeY9TGXTCKmT1jl7jR35uWQ7iLEIMJ3RGCklD5ir7f40dyY0jLCgXAfayM/NfEn+HagWLCenYF5ggL569H8mWHboAs0rxEUcZtJCoL3tTrkW/+r9KQBxmubQXbojIHYmC6cYbjyo5Mu/q71HVCEyLuA4E7ZrEJqe814zvHAXo/LtNppY+LF7JdPdORUsPIZae1Vi2i2g=="
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:34 volumio go-librespot[31429]: time="2026-02-10T18:24:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 10 18:24:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:34 volumio volumio[31044]: info: MyVolumio token set successfully
Feb 10 18:24:34 volumio volumio[31044]: info: MYVOLUMIO: Adding device
Feb 10 18:24:34 volumio volumio[31044]: info: MYVOLUMIO: Evaluating Server
Feb 10 18:24:35 volumio volumio[31044]: info: MyVolumio status changed
Feb 10 18:24:35 volumio volumio[31044]: info: Streaming services startup
Feb 10 18:24:35 volumio volumio[31044]: info: Starting Streaming Daemon
Feb 10 18:24:35 volumio volumio[31044]: info: Removing browser output: myVolumio user plan is not superstar
Feb 10 18:24:35 volumio volumio[31044]: info: Removing audio output:
Feb 10 18:24:35 volumio volumio[31044]: info: Stoppping Tunnel 1
Feb 10 18:24:35 volumio sudo[31457]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 10 18:24:35 volumio sudo[31457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:35 volumio sudo[31457]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:35 volumio sudo[31460]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 10 18:24:35 volumio sudo[31460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:35 volumio volumio[31044]: error: Cannot start Volumio Streaming Daemon
Feb 10 18:24:35 volumio volumio[31044]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 10 18:24:35 volumio volumio[31044]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio volumio[31044]: info: Setting Geolocation for MyVolumio to as1
Feb 10 18:24:35 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:35 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:35 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 10 18:24:35 volumio sudo[31460]: pam_unix(sudo:session): session closed for user root
Feb 10 18:24:35 volumio volumio[31044]: info: Remote SSH Stopped
Feb 10 18:24:36 volumio volumio[31044]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 10 18:24:36 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:36 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:36 volumio volumio[31044]: info: Updating MyVolumio device info
Feb 10 18:24:36 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:36 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:36 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:37 volumio volumio[31044]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 10 18:24:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 10 18:24:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:37 volumio go-librespot[31462]: go-librespot daemon starting...
Feb 10 18:24:37 volumio go-librespot[31463]: time="2026-02-10T18:24:37+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:37 volumio go-librespot[31463]: time="2026-02-10T18:24:37+07:00" level=debug msg="app state loaded"
Feb 10 18:24:37 volumio go-librespot[31463]: time="2026-02-10T18:24:37+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=info msg="zeroconf server listening on port 39275"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="obtained new client token: AADhNS/2sKR5oIlZhRza2+zsV+sbQ7UY9d3hDZXiKpr+oRbvTjKk9sdESjC7O80xma6Xtb61qO6i0PgfXtvfszliPDOYtFLQ1G5WJERXvATWa5oX20wiMH8OSN9RRPyqZUfrqIvsAtGDMzOwsMRyqzaDjsIAKMDhTlk5AVuSm5giHdpMNixCnb7ZxozsHFiPq63mLU5afqcUAIIv2NBTQrOqDDECuQDOm56HgkDvnIIUc4dZ5aozmlMXmw=="
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=debug msg="completed challenge"
Feb 10 18:24:38 volumio go-librespot[31463]: time="2026-02-10T18:24:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:39 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:39 volumio volumio[31044]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:40 volumio volumio[31044]: info: MYVOLUMIO: Adding device
Feb 10 18:24:40 volumio volumio[31044]: info: MYVOLUMIO: Evaluating Server
Feb 10 18:24:41 volumio volumio[31044]: info: Setting Geolocation for MyVolumio to as1
Feb 10 18:24:41 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:41 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:41 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:41 volumio volumio[31044]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 10 18:24:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 10 18:24:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:42 volumio go-librespot[31502]: go-librespot daemon starting...
Feb 10 18:24:42 volumio volumio[31044]: info: Updating MyVolumio device info
Feb 10 18:24:42 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:42 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:42 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="app state loaded"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:42 volumio volumio[31044]: info: Initializing connection to go-librespot Websocket
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="new websocket client"
Feb 10 18:24:42 volumio volumio[31044]: info: Connection to go-librespot Websocket established
Feb 10 18:24:42 volumio volumio[31044]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=info msg="zeroconf server listening on port 36017"
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="obtained new client token: AACRBW+Vp7ozXcNWpjLV3Ze43O4r0CX29nyoq3q+5+t34Hte+sdU+0xAStS5P4OB2uJukZQBUxZQ/+kRbKZB2RJzCe/UsvIyxYVbqBrQmxOeZJNowS1C1sHFPkhbPLUsTUmTtBLmZBURs2zIfgcIT3PIHzrSuiXu4Zhx7xjoSoMqyB6U07Gsgdeobie9oAlX7W9/csFsy5yaQUHfiKjRQfl0iA3W86al1wtCnDCQ4H4BBtNu5mxR+mPcng=="
Feb 10 18:24:42 volumio go-librespot[31503]: time="2026-02-10T18:24:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 10 18:24:43 volumio go-librespot[31503]: time="2026-02-10T18:24:43+07:00" level=debug msg="completed keyexchange"
Feb 10 18:24:43 volumio go-librespot[31503]: time="2026-02-10T18:24:43+07:00" level=debug msg="completed challenge"
Feb 10 18:24:43 volumio go-librespot[31503]: time="2026-02-10T18:24:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 10 18:24:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 10 18:24:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 10 18:24:43 volumio volumio[31044]: info: Connection to go-librespot Websocket closed
Feb 10 18:24:44 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 10 18:24:44 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 10 18:24:44 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 10 18:24:44 volumio volumio-remote-updater[643]: Test mode disabled
Feb 10 18:24:44 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 10 18:24:44 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 10 18:24:44 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 10 18:24:45 volumio volumio[31044]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 10 18:24:45 volumio volumio[31044]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 10 18:24:45 volumio volumio[31044]: info: Getting Spotify volume
Feb 10 18:24:45 volumio volumio[31044]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:24:45 volumio volumio[31044]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 10 18:24:45 volumio volumio[31044]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 10 18:24:45 volumio volumio[31044]:   errno: -111,
Feb 10 18:24:45 volumio volumio[31044]:   code: 'ECONNREFUSED',
Feb 10 18:24:45 volumio volumio[31044]:   syscall: 'connect',
Feb 10 18:24:45 volumio volumio[31044]:   address: '127.0.0.1',
Feb 10 18:24:45 volumio volumio[31044]:   port: 9879,
Feb 10 18:24:45 volumio volumio[31044]:   response: undefined
Feb 10 18:24:45 volumio volumio[31044]: }
Feb 10 18:24:45 volumio volumio[31044]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 10 18:24:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 10 18:24:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 10 18:24:46 volumio go-librespot[31528]: go-librespot daemon starting...
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=info msg="running go-librespot 0.4.0"
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=debug msg="app state loaded"
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 10 18:24:46 volumio sudo[31538]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 18:23'
Feb 10 18:24:46 volumio sudo[31538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 10 18:24:46 volumio go-librespot[31529]: time="2026-02-10T18:24:46+07:00" level=info msg="zeroconf server listening on port 44305"
Feb 10 18:24:47 volumio go-librespot[31529]: time="2026-02-10T18:24:47+07:00" level=debug msg="obtained new client token: AABRtw0pTjDST5G2dWPBDgfZKWyviiVFWMiQMUw1Fv+XrA1hr+aHtfKQlbfpWq/sr9KDUYluL75pqbcBb9YHinR6KM9oMAy7QV8S7UT54470Udo98p5esrljnyxcZ5+t3IvuFNhvvwlmgy8+As0g4Sd2uFXTeU8Ap/hmlShp+TA8FhMiA/pCnAGg+0zJn8K+L/l2Yh1RgBSL7yhi5lnJXkm43fXyKYbASdTxv7Nx8qJDh8yd3vHlI3A="
Feb 10 18:24:47 volumio go-librespot[31529]: time="2026-02-10T18:24:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025"
VOLUMIO_VERSION="4.084"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"