Feb 11 14:21:00 volumio volumio[13909]: info: Volumio called home Feb 11 14:21:00 volumio go-librespot[14159]: time="2026-02-11T14:21:00+07:00" level=debug msg="obtained new client token: AACGBkk/lEC4y1aQqlrtL36b8hZUQ+fNmTzLxCYeQogbGVOJD+hxo7MWdNYf1MfkJPAthz1uhdaBh/ozPOI89X4BLYELEMFSV0eYe2VdvCJL9VfQieXMriVZZAWTWJrO8oUSU4xryV7WMq2cIKkxuBaGNLStWfL48mZqoLatQGtAtHXcu0Y2YuzIjtAewQr6gtmlHuekAVCJc95jgMXN0hkzo0dcPyf5oWoyKyPobsdVXwkVAkMleI0=" Feb 11 14:21:00 volumio volumio[13909]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:21:00 volumio volumio[13909]: SPOTIFY: BQBu8jmlzfwchTdHHO9Pp1HA_EvZ9RvUA8DQ4CSNEol6M_y4yYbS5_-L6ZrfOOQTfui_KuevSqdla_Zl-GVRJgeKXxiotwWwYT7-9LRCHuv2cvbtCdwDLle1PrR33am7lbRadWdll-Nmgju52BABaNI9bsNFDNITNzr0h9T-pWwxOl0xjWBauvfU1IKhZC96sV1ijymI0dlXMzrxAM4orcIXwAd0XP5w8iXfBxXwI6QyanUi9DJWXmYs_XpnRdl_-DDcEd4PrmHYRhl06k09TiGlexnu-QG9Y2vL5TgJ6dU90-FsGH0oj21A Feb 11 14:21:00 volumio volumio[13909]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:21:00 volumio volumio[13909]: info: New Spotify access token = BQBu8jmlzfwchTdHHO9Pp1HA_EvZ9RvUA8DQ4CSNEol6M_y4yYbS5_-L6ZrfOOQTfui_KuevSqdla_Zl-GVRJgeKXxiotwWwYT7-9LRCHuv2cvbtCdwDLle1PrR33am7lbRadWdll-Nmgju52BABaNI9bsNFDNITNzr0h9T-pWwxOl0xjWBauvfU1IKhZC96sV1ijymI0dlXMzrxAM4orcIXwAd0XP5w8iXfBxXwI6QyanUi9DJWXmYs_XpnRdl_-DDcEd4PrmHYRhl06k09TiGlexnu-QG9Y2vL5TgJ6dU90-FsGH0oj21A Feb 11 14:21:00 volumio volumio[13909]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 14:21:00 volumio go-librespot[14159]: time="2026-02-11T14:21:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:00 volumio volumio[13909]: info: Starting Shairport Sync Feb 11 14:21:00 volumio volumio[13909]: info: Starting Shairport Sync Feb 11 14:21:00 volumio volumio[13909]: info: Starting Shairport Sync Feb 11 14:21:00 volumio go-librespot[14159]: time="2026-02-11T14:21:00+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:00 volumio go-librespot[14159]: time="2026-02-11T14:21:00+07:00" level=debug msg="completed challenge" Feb 11 14:21:00 volumio sudo[14196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:00 volumio sudo[14196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:00 volumio sudo[14198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:00 volumio sudo[14198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:00 volumio go-librespot[14159]: time="2026-02-11T14:21: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 11 14:21:00 volumio sudo[14200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:00 volumio sudo[14200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 14:21:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 14:21:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:00 volumio systemd[1]: shairport-sync.service: Consumed 2.348s CPU time. Feb 11 14:21:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:00 volumio volumio[13909]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:00 volumio volumio[13909]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:00 volumio sudo[14196]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:00 volumio volumio[13909]: info: Shairport-Sync Started Feb 11 14:21:00 volumio volumio[13909]: Error adding Membership: Error: addMembership EINVAL Feb 11 14:21:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 14:21:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 14:21:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:00 volumio sudo[14200]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:01 volumio sudo[14198]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:01 volumio volumio[13909]: info: Shairport-Sync Started Feb 11 14:21:01 volumio volumio[13909]: info: Shairport-Sync Started Feb 11 14:21:01 volumio volumio[13909]: 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 11 14:21:01 volumio volumio[13909]: info: Spotify Successfully logged in Feb 11 14:21:01 volumio volumio[13909]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:01 volumio volumio[13909]: info: [1770794461093] CoreMusicLibrary::Adding element Spotify Feb 11 14:21:01 volumio volumio[13909]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:01 volumio volumio[13909]: Cannot find translation for source YouTube Music Feb 11 14:21:01 volumio volumio[13909]: Cannot find translation for source Spotify Feb 11 14:21:01 volumio volumio[13909]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 14:21:01 volumio volumio[13909]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:21:02 volumio volumio[13909]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:21:02 volumio volumio[13909]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:02 volumio volumio[13909]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:02 volumio volumio[13909]: info: CoreStateMachine::pushState Feb 11 14:21:02 volumio volumio[13909]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:02 volumio volumio[13909]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:03 volumio volumio[13909]: info: go-librespot daemon successfully initialized Feb 11 14:21:03 volumio mpd[14138]: 2026-02-11T14:21:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 14:21:03 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 14:21:03 volumio sudo[14098]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:03 volumio sudo[14109]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:03 volumio volumio[13909]: error: MPD error: The expression evaluated to a falsy value: Feb 11 14:21:03 volumio volumio[13909]: assert.ok(self.idling) Feb 11 14:21:03 volumio volumio[13909]: error: The expression evaluated to a falsy value: Feb 11 14:21:03 volumio volumio[13909]: assert.ok(self.idling) Feb 11 14:21:03 volumio volumio[13909]: error: updateQueue error: null Feb 11 14:21:03 volumio volumio[13909]: info: MPD running with PID14138 Feb 11 14:21:03 volumio volumio[13909]: ,establishing connection Feb 11 14:21:03 volumio volumio[13909]: info: Completed starting Core Plugins Feb 11 14:21:03 volumio volumio[13909]: info: ------------------------------------------- Feb 11 14:21:03 volumio volumio[13909]: info: ----- MyVolumio plugins startup ---- Feb 11 14:21:03 volumio volumio[13909]: info: ------------------------------------------- Feb 11 14:21:03 volumio volumio[13909]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 14:21:03 volumio volumio[13909]: error: updateQueue error: null Feb 11 14:21:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 14:21:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:03 volumio go-librespot[14249]: go-librespot daemon starting... Feb 11 14:21:03 volumio go-librespot[14250]: time="2026-02-11T14:21:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:03 volumio go-librespot[14250]: time="2026-02-11T14:21:03+07:00" level=debug msg="app state loaded" Feb 11 14:21:03 volumio go-librespot[14250]: time="2026-02-11T14:21:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21:04+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 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21:04+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 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21:04+07:00" level=info msg="zeroconf server listening on port 39693" Feb 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21:04+07:00" level=debug msg="obtained new client token: AADOSITmk08/x5g96sH4DlLr886sdr785M/WP63IuOcXGSVmitqXS1LN/w7zbnzYb+6B05DJVTZzoWKRKr969iq0VYwhE1ymQCJDkN01zHpCnhoLH1VXOignGx7S1JsZmodsregLbzSBkYdbQdmbdMYPAUAPYFnfcQnhU3ZRtyMCp3fyTvYtHzOQ8PJJqCR6qTGMTUexGkCscSzpJfh8jvRqx7Z0uwY54Dcz8rStdieQXnEDDnQlMNvH9A==" Feb 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:04 volumio go-librespot[14250]: time="2026-02-11T14:21: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 11 14:21:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:06 volumio volumio[13909]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:06 volumio volumio[13909]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 14:21:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:08 volumio go-librespot[14257]: go-librespot daemon starting... Feb 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21:08+07:00" level=debug msg="app state loaded" Feb 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:08 volumio volumio[13909]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21: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 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21: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 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21: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 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21:08+07:00" level=info msg="zeroconf server listening on port 40391" Feb 11 14:21:08 volumio go-librespot[14258]: time="2026-02-11T14:21:08+07:00" level=debug msg="obtained new client token: AABbP1s+iAhTnux1Ot+zheebjE5gl43jQsSR/8p+pCov6LBSLBozBusgjp1nCEjvs6/uHY7CTkKSjgmAkYci0wysN3va70Lqyj3p7Qs8fAqotfDqaIXKt6L261tt9i4a7eNcLQcCW0JB6u07oJsrsI2d81sKlsQCJ6z7H5viBQLOS7j8p4DTcgpnCdJ3+otL0q0kks6md6mG00eAwBObh81sBSskRUbD7cUX1XWPcN60l0LbVW4TC/HPnQ==" Feb 11 14:21:09 volumio go-librespot[14258]: time="2026-02-11T14:21:09+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 11 14:21:09 volumio volumio[13909]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:09 volumio go-librespot[14258]: time="2026-02-11T14:21:09+07:00" level=debug msg="new websocket client" Feb 11 14:21:09 volumio volumio[13909]: info: Connection to go-librespot Websocket established Feb 11 14:21:09 volumio go-librespot[14258]: time="2026-02-11T14:21:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 14:21:09 volumio go-librespot[14258]: time="2026-02-11T14:21:09+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: read tcp 192.168.1.23:60482->104.199.241.202:443: read: connection reset by peer" Feb 11 14:21:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:09 volumio volumio[13909]: info: Connection to go-librespot Websocket closed Feb 11 14:21:12 volumio volumio[13909]: info: Getting Spotify volume Feb 11 14:21:12 volumio volumio[13909]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:21:12 volumio volumio[13909]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:12 volumio volumio[13909]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 14:21:12 volumio volumio[13909]: errno: -111, Feb 11 14:21:12 volumio volumio[13909]: code: 'ECONNREFUSED', Feb 11 14:21:12 volumio volumio[13909]: syscall: 'connect', Feb 11 14:21:12 volumio volumio[13909]: address: '127.0.0.1', Feb 11 14:21:12 volumio volumio[13909]: port: 9879, Feb 11 14:21:12 volumio volumio[13909]: response: undefined Feb 11 14:21:12 volumio volumio[13909]: } Feb 11 14:21:12 volumio volumio[13909]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:21:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 14:21:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:12 volumio go-librespot[14278]: go-librespot daemon starting... Feb 11 14:21:12 volumio go-librespot[14281]: time="2026-02-11T14:21:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:12 volumio go-librespot[14281]: time="2026-02-11T14:21:12+07:00" level=debug msg="app state loaded" Feb 11 14:21:12 volumio go-librespot[14281]: time="2026-02-11T14:21:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+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 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+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 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+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 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+07:00" level=info msg="zeroconf server listening on port 36975" Feb 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+07:00" level=debug msg="obtained new client token: AADBZJiBme9nXNnFqY68/ukQ9b0BafHk9x9quzJfpLynRtINWRdbYUJqdeImE6HWU9aKleJPVVXnE3puPFV/yr8eo/zx5OsB5fSizoIL0ANb6ie0HFgLQReg1icP9GepU0mEmwqJzsdVbXTMcAwmbA8EDHm8IevhQkDJthB+g+OZUXLZ+2HRN/Fz3Cwb7ID+bFIIo0ZB6WEcOiaH882Ov/MfrHYVW+U1K7E7hgVAbQaX212pyxPkMMKRXQ==" Feb 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:13 volumio sudo[14304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 14:20' Feb 11 14:21:13 volumio sudo[14304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:13 volumio go-librespot[14281]: time="2026-02-11T14:21:13+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 11 14:21:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:13 volumio sudo[14304]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:15 volumio volumio-remote-updater[643]: [2026-02-11 14:21:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 14:21:15 volumio volumio-remote-updater[643]: [2026-02-11 14:21:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 14:21:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 14:21:15 volumio systemd[1]: volumio.service: Consumed 49.410s CPU time. Feb 11 14:21:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 14:21:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 14:21:15 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11833. Feb 11 14:21:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 14:21:15 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 14:21:15 volumio systemd[1]: volumio.service: Consumed 49.410s CPU time. Feb 11 14:21:15 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 14:21:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 14:21:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 14:21:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:16 volumio go-librespot[14336]: go-librespot daemon starting... Feb 11 14:21:16 volumio go-librespot[14337]: time="2026-02-11T14:21:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:16 volumio go-librespot[14337]: time="2026-02-11T14:21:16+07:00" level=debug msg="app state loaded" Feb 11 14:21:16 volumio go-librespot[14337]: time="2026-02-11T14:21:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+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 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+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 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+07:00" level=info msg="zeroconf server listening on port 39541" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+07:00" level=debug msg="obtained new client token: AAB3ERgCUsWzgPnqMSnop2B/cszV3gDTOygwVN5+wDIq6GlSJRYrOaxtT4oFIhwcW0HomOC8prgc9xenN4TEsCzuE5xr5ih7Klbdy2kcMCaH9WuZ8OBh+j1S1ZiSgSfAzfdi+4IjEXOw76XD/LnDG7BzNJq3vtbvhbHciqKI8Caxx9/D7MwbgkBqH4QYD433BSraXG/NqKP+cwnyEilZYGdzW3P5J+2wxPRMJW53cyQLNr53sbs45nCiVQ==" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21:17+07:00" level=debug msg="completed challenge" Feb 11 14:21:17 volumio go-librespot[14337]: time="2026-02-11T14:21: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 11 14:21:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:19 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:19 volumio volumio[14321]: info: ----- Volumio3 ---- Feb 11 14:21:19 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:19 volumio volumio[14321]: info: ----- System startup ---- Feb 11 14:21:19 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:20 volumio volumio-remote-updater[643]: [2026-02-11 14:21:20] [connect] Successful connection Feb 11 14:21:20 volumio volumio[14321]: info: MYVOLUMIO Environment detected Feb 11 14:21:20 volumio volumio[14321]: info: Plugin folders cleanup Feb 11 14:21:20 volumio volumio[14321]: info: Scanning into folder /volumio/app/plugins/ Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category audio_interface Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category miscellanea Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category music_service Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category plugins.json Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category system_controller Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category user_interface Feb 11 14:21:20 volumio volumio[14321]: info: Scanning into folder /data/plugins/ Feb 11 14:21:20 volumio volumio[14321]: info: Scanning category music_service Feb 11 14:21:20 volumio volumio[14321]: info: Plugin folders cleanup completed Feb 11 14:21:20 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:20 volumio volumio[14321]: info: ----- Core plugins startup ---- Feb 11 14:21:20 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:20 volumio volumio[14321]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 14:21:20 volumio volumio[14321]: info: Adding plugin upnp to MyMusic Plugins Feb 11 14:21:20 volumio volumio[14321]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 14:21:20 volumio volumio[14321]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 14:21:20 volumio volumio[14321]: info: Loading plugins from folder /data/plugins/ Feb 11 14:21:20 volumio volumio[14321]: info: Loading plugin "system"... Feb 11 14:21:20 volumio volumio[14321]: info: Loading plugin "appearance"... Feb 11 14:21:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 14:21:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:21 volumio go-librespot[14357]: go-librespot daemon starting... Feb 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21:21+07:00" level=debug msg="app state loaded" Feb 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21: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 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21: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 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21: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 11 14:21:21 volumio go-librespot[14358]: time="2026-02-11T14:21:21+07:00" level=info msg="zeroconf server listening on port 36819" Feb 11 14:21:22 volumio go-librespot[14358]: time="2026-02-11T14:21:22+07:00" level=debug msg="obtained new client token: AADENtHqDzHWhjPTgt1idWhCLX3yDskshJuv1ayfNedx0b/EQMp5qLhPMT1ziXn32tigpAcrODyrbKYHRq2O6iIUblsmY18Eyvs3oTG1ubxQqUeiD35Si2AKXZkTF5Wz+/3CdC1AcZHhoTaver0O+8bSu7ymHXnT6hNQzCgb7F5uuoGNSU0W70q5PN+CPx6BTvuqNtKNooDwO52sSDKHLfqJ4ZeinKdXDQvNcwb0gIVvHGNxdF/EtUH3yQ==" Feb 11 14:21:22 volumio go-librespot[14358]: time="2026-02-11T14:21:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:22 volumio go-librespot[14358]: time="2026-02-11T14:21:22+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:22 volumio go-librespot[14358]: time="2026-02-11T14:21:22+07:00" level=debug msg="completed challenge" Feb 11 14:21:22 volumio go-librespot[14358]: time="2026-02-11T14:21:22+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 11 14:21:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:22 volumio volumio[14321]: info: Loading plugin "network"... Feb 11 14:21:22 volumio volumio[14321]: info: Refreshing Cached IP Addresses Feb 11 14:21:22 volumio sudo[14367]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 14:21:22 volumio sudo[14367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:22 volumio sudo[14367]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:22 volumio sudo[14369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 14:21:22 volumio sudo[14369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:22 volumio volumio[14321]: info: Loading plugin "services"... Feb 11 14:21:22 volumio sudo[14369]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:22 volumio volumio[14321]: info: Loading plugin "alsa_controller"... Feb 11 14:21:23 volumio sudo[14377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 14:21:23 volumio sudo[14377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:23 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "wizard"... Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "networkfs"... Feb 11 14:21:23 volumio volumio[14321]: info: Starting Udev Watcher for removable devices Feb 11 14:21:23 volumio volumio[14321]: info: Ignoring mount for partition: boot Feb 11 14:21:23 volumio volumio[14321]: info: Ignoring mount for partition: volumio Feb 11 14:21:23 volumio volumio[14321]: info: Ignoring mount for partition: volumio_data Feb 11 14:21:23 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "volumio_command_line_client"... Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "upnp"... Feb 11 14:21:23 volumio volumio[14321]: info: [1770794483269] Starting Upmpd Daemon Feb 11 14:21:23 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "my_music"... Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "mpd"... Feb 11 14:21:23 volumio volumio[14321]: info: Loading plugin "upnp_browser"... Feb 11 14:21:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 14:21:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:25 volumio go-librespot[14400]: go-librespot daemon starting... Feb 11 14:21:25 volumio go-librespot[14401]: time="2026-02-11T14:21:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:25 volumio go-librespot[14401]: time="2026-02-11T14:21:25+07:00" level=debug msg="app state loaded" Feb 11 14:21:25 volumio go-librespot[14401]: time="2026-02-11T14:21:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:25 volumio sudo[14377]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+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 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+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 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+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 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+07:00" level=info msg="zeroconf server listening on port 41743" Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+07:00" level=debug msg="obtained new client token: AABsnenfNuvLRGrGgVWwcQcoFYsFyLOkcx6Tc82YiXAZIQ7hNaPUq/1QIqOLqGqUC4/oCTCfRnjJ9XPVwLqLPjzlQm3WQ6qzIPRhWOXOp3/M3s7aSYGbTt+qJyEhwKmGUaLq0hOS8e5xAG6nISqXJn9IHpU8c476SP7yXneHb2VsqGA2WUnRHaXO2++SadfFuj2ZiQaetgwQkgp4MdvqkekdutxGfVjzOZWncJTEatSqSJzBPbQxOKZHXw==" Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21:26+07:00" level=debug msg="completed challenge" Feb 11 14:21:26 volumio go-librespot[14401]: time="2026-02-11T14:21: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 11 14:21:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:26 volumio volumio[14321]: info: Starting UPNP Browser Feb 11 14:21:26 volumio volumio[14321]: info: Loading plugin "alarm-clock"... Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "airplay_emulation"... Feb 11 14:21:27 volumio volumio[14321]: info: Starting Shairport Sync Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "last_100"... Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "webradio"... Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "i2s_dacs"... Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "volumiodiscovery"... Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:21:27 volumio node[14321]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** For more information see Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:21:27 volumio volumio[14321]: *** WARNING *** For more information see Feb 11 14:21:27 volumio node[14321]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:21:27 volumio node[14321]: *** WARNING *** For more information see Feb 11 14:21:27 volumio node[14321]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 14:21:27 volumio node[14321]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:21:27 volumio node[14321]: *** WARNING *** For more information see Feb 11 14:21:27 volumio volumio[14321]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 14:21:27 volumio volumio[14321]: info: Discovery: Started advertising with name: Volumio Feb 11 14:21:27 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:21:27 volumio volumio[14321]: info: Loading plugin "spop"... Feb 11 14:21:29 volumio volumio[14321]: info: Loading plugin "ytcr"... Feb 11 14:21:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 14:21:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:29 volumio go-librespot[14412]: go-librespot daemon starting... Feb 11 14:21:29 volumio go-librespot[14413]: time="2026-02-11T14:21:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:29 volumio go-librespot[14413]: time="2026-02-11T14:21:29+07:00" level=debug msg="app state loaded" Feb 11 14:21:29 volumio go-librespot[14413]: time="2026-02-11T14:21:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+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 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+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 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+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 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+07:00" level=info msg="zeroconf server listening on port 36705" Feb 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+07:00" level=debug msg="obtained new client token: AADD5sOCLVmrWDwx+3qVelSP+phVgtWTwT5NtFR5PKtvUfEqc/rMrlQSH7uVZUV0GaToWfxuGhfqMQEYM/Fi0K7KHhqMLX9SpIMEcb8xX50x3YYI/4Zy8dWPdRaYLc1tmdp7LwANgv005Ne36zrPMkv1noJc7lIAnBKi/J9L4sq/r1wBcV7mfbg5Y4sI+2VackjipcCLWlZ68Bx7V/6DXLg0p4LCZb+MhgHx0ceni9ERAdodamYwwaTwrQ==" Feb 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:30 volumio go-librespot[14413]: time="2026-02-11T14:21:30+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 11 14:21:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:32 volumio volumio[14321]: info: Loading plugin "ytmusic"... Feb 11 14:21:32 volumio volumio-remote-updater[643]: [2026-02-11 14:21:32] [connect] Successful connection Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "outputs"... Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "albumart"... Feb 11 14:21:33 volumio volumio[14321]: info: Plugin example_plugin is not enabled Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "inputs"... Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "updater_comm"... Feb 11 14:21:33 volumio volumio[14321]: info: Plugin mpdemulation is not enabled Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "rest_api"... Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "websocket"... Feb 11 14:21:33 volumio volumio[14321]: info: Starting Socket.io Server version 1.7.4 Feb 11 14:21:33 volumio volumio[14321]: info: Loading plugin "RoonBridge"... Feb 11 14:21:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 14:21:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:33 volumio go-librespot[14446]: go-librespot daemon starting... Feb 11 14:21:33 volumio go-librespot[14447]: time="2026-02-11T14:21:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:33 volumio go-librespot[14447]: time="2026-02-11T14:21:33+07:00" level=debug msg="app state loaded" Feb 11 14:21:33 volumio go-librespot[14447]: time="2026-02-11T14:21:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:34 volumio volumio[14321]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 14:21:34 volumio volumio[14321]: info: Loading i18n strings for locale en Feb 11 14:21:34 volumio volumio[14321]: Updating browse sources language Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:34 volumio volumio[14436]: Forking 3 albumart workers Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::initPlayerControls Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:21:34 volumio volumio[14321]: Express server listening on port 3000 Feb 11 14:21:34 volumio volumio[14321]: [Metrics] WebUI: 16s 233.02ms Feb 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21:34+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 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21:34+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 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21:34+07:00" level=info msg="zeroconf server listening on port 43275" Feb 11 14:21:34 volumio volumio[14321]: info: CoreStateMachine::resetVolumioState Feb 11 14:21:34 volumio volumio[14321]: info: CoreStateMachine::getcurrentVolume Feb 11 14:21:34 volumio volumio[14321]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:21:34 volumio sudo[14489]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 14:21:34 volumio sudo[14489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21:34+07:00" level=debug msg="obtained new client token: AACsLR8OljpcvKFqUJDhiuV1LpXYvmDxZDkr6vjdyn3ss9aD3SRgf4gnTNxBeimT7R7eo6YKuOAinrFz/Rrcz1dig0Q/unoYbM1RTlH2rDBzjM0vESkddi/DKjP1DwQl3fagyLcRZxyxhzFDijsix7IP4tBrnF69AiEJrYNJ5EDNDmNQ8HgLWqhsueMtGxYqQyPq8QXKCriA/81yvD3MIwWLfowypN8IEzeqlVzeQCBG5DCtoPaOyhIE/A==" Feb 11 14:21:34 volumio sudo[14489]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:34 volumio sudo[14492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 14:21:34 volumio sudo[14492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:34 volumio sudo[14492]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:34 volumio volumio[14321]: info: Volumio Network Manager: Network status updated: 1 Feb 11 14:21:34 volumio go-librespot[14447]: time="2026-02-11T14:21:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:35 volumio go-librespot[14447]: time="2026-02-11T14:21:35+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 11 14:21:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:35 volumio volumio[14321]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::pushState Feb 11 14:21:35 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::updateTrackBlock Feb 11 14:21:35 volumio volumio[14321]: info: CorePlayQueue::getTrackBlock Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:21:35 volumio volumio-remote-updater[643]: [2026-02-11 14:21:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770794492 101 Feb 11 14:21:35 volumio volumio[14321]: 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 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:35 volumio volumio[14321]: info: Reloading queue from file Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::setRepeat null single undefined Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::pushState Feb 11 14:21:35 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::setRandom null Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::pushState Feb 11 14:21:35 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:35 volumio volumio[14321]: info: Setting Device type: Raspberry PI Feb 11 14:21:35 volumio volumio[14321]: info: Completed loading Core Plugins Feb 11 14:21:35 volumio volumio[14321]: info: Preparing to generate the ALSA configuration file Feb 11 14:21:35 volumio volumio[14321]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:21:35 volumio volumio[14321]: info: CoreStateMachine::pushState Feb 11 14:21:35 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:35 volumio volumio[14321]: info: Asound.conf file unchanged, so no further update is needed Feb 11 14:21:35 volumio volumio[14321]: info: Output device has changed, restarting MPD Feb 11 14:21:35 volumio volumio[14321]: info: Output device has changed, restarting Shairport Sync Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:35 volumio sudo[14506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 14:21:35 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:35 volumio sudo[14506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:35 volumio sudo[14508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 14:21:35 volumio sudo[14508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:35 volumio volumio[14321]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:21:35 volumio volumio[14321]: info: ___________ START PLUGINS ___________ Feb 11 14:21:35 volumio volumio[14321]: info: ControllerMpd::onStart: Initializing MPD Feb 11 14:21:35 volumio sudo[14508]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:35 volumio volumio[14321]: info: Creating MPD Configuration file Feb 11 14:21:35 volumio sudo[14511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 14:21:35 volumio sudo[14511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:35 volumio sudo[14506]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:35 volumio sudo[14520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 14:21:35 volumio sudo[14520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:36 volumio volumio[14321]: info: [1770794496035] CoreMusicLibrary::Adding element Media Servers Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:36 volumio sudo[14520]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 14:21:36 volumio volumio[14321]: info: UPNP Browser: Client initialized successfully Feb 11 14:21:36 volumio sudo[14523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 14:21:36 volumio sudo[14523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 14:21:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 14:21:36 volumio systemd[1]: mpd.service: Consumed 7.269s CPU time. Feb 11 14:21:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 14:21:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 14:21:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 14:21:36 volumio volumio[14321]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 14:21:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 14:21:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 14:21:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 14:21:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 14:21:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 14:21:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 14:21:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 14:21:36 volumio volumio[14321]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:36 volumio volumio[14321]: info: [1770794496415] CoreMusicLibrary::Adding element Last_100 Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:36 volumio volumio[14321]: info: [1770794496458] CoreMusicLibrary::Adding element Webradio Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:21:36 volumio volumio[14321]: info: Initializing BBC Radios Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:36 volumio volumio[14321]: info: Creating Spotify config file Feb 11 14:21:36 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:36 volumio sudo[14536]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 14:21:36 volumio sudo[14536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 14:21:36 volumio sudo[14536]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:37 volumio volumio[14455]: Starting albumart workers Feb 11 14:21:37 volumio volumio[14456]: Starting albumart workers Feb 11 14:21:37 volumio volumio[14457]: Starting albumart workers Feb 11 14:21:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 14:21:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:38 volumio volumio[14321]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:38 volumio volumio[14321]: info: [1770794498144] CoreMusicLibrary::Adding element YouTube Music Feb 11 14:21:38 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:38 volumio volumio[14321]: Cannot find translation for source YouTube Music Feb 11 14:21:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:38 volumio go-librespot[14552]: go-librespot daemon starting... Feb 11 14:21:38 volumio go-librespot[14553]: time="2026-02-11T14:21:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:38 volumio volumio[14321]: info: Volumio Calling Home Feb 11 14:21:38 volumio sudo[14561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 14:21:38 volumio sudo[14561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:38 volumio sudo[14561]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:39 volumio go-librespot[14553]: time="2026-02-11T14:21:39+07:00" level=info msg="zeroconf server listening on port 33523" Feb 11 14:21:39 volumio volumio[14321]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 14:21:39 volumio volumio[14321]: info: Discovery: Found device Volumio Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:39 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:39 volumio volumio[14321]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 14:21:39 volumio volumio[14321]: info: Discovery: Found device Volumio Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:39 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:39 volumio volumio[14321]: info: MPD Permissions set Feb 11 14:21:39 volumio volumio[14321]: info: MPD Permissions set Feb 11 14:21:39 volumio volumio[14321]: info: Upmpdcli Daemon Started Feb 11 14:21:39 volumio volumio[14321]: info: Spotify config file written Feb 11 14:21:39 volumio volumio[14321]: 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 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio sudo[14568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 14:21:39 volumio sudo[14568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 14:21:39 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 14:21:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:21:39 volumio volumio[14321]: info: No need to fix Spotify hosts Feb 11 14:21:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:39 volumio go-librespot[14586]: go-librespot daemon starting... Feb 11 14:21:39 volumio sudo[14568]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:39 volumio go-librespot[14587]: time="2026-02-11T14:21:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:39 volumio go-librespot[14587]: time="2026-02-11T14:21:39+07:00" level=debug msg="app state loaded" Feb 11 14:21:39 volumio go-librespot[14587]: time="2026-02-11T14:21:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+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 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+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 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+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 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+07:00" level=info msg="zeroconf server listening on port 39245" Feb 11 14:21:40 volumio volumio[14321]: info: Volumio called home Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+07:00" level=debug msg="obtained new client token: AABmoPSToj3Y7kVgSS+Out9vuIaagfEdHbuy+1qIHxQqXkCvaTtVQxBrN26w5zsWjydxJwTyLtLm/QCVJq9Dredg8Kj5YbX3DZ+2vuF/LcbEPGF0SQeJUWJMmlDECowILEMe+gEyE4q1IMxU7SVJ/AUrFgz+9vepEstcwQ3Zde/pbTep9rzn5wj2nHZ7/14szfL0JUI5WQloEhX6F5mZ1Afa8tn6PPW6KsZbfgc/TyYvqCJUbRMk6BqInw==" Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:40 volumio volumio[14321]: info: Starting Shairport Sync Feb 11 14:21:40 volumio volumio[14321]: info: Starting Shairport Sync Feb 11 14:21:40 volumio volumio[14321]: info: Starting Shairport Sync Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:40 volumio sudo[14608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:40 volumio sudo[14608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+07:00" level=debug msg="completed challenge" Feb 11 14:21:40 volumio sudo[14610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:40 volumio sudo[14610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:40 volumio sudo[14612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:21:40 volumio sudo[14612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:40 volumio volumio[14321]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:21:40 volumio volumio[14321]: SPOTIFY: BQD4u5tkyMk1_JScaZXC4VfLqta_1QcfUxQiZW6qYcgnJVMTKzH_pcN0KeGIbIuIfjjXyjpnnXs598fi3-e62ea36bZEiUKVE7azOPx1u5_-b9Ui7VPYVqu_6Lg41s_7T71zkjXqyAIpUXy-GPkK4BtgSAbZuEC1tW7fIOqhzExD-AOKV9TRXZrkhB0a7x88p3Nb2Lol4qbnakDOyFLwWK9vw2tO6Wtpg2lCcvtEqNgimuSiEK3ES_vMwl6IyAvqeyJ3fR-Fy74DGx2fdGk9N8iLaCWdLYhKAij1-zhzYtG6YZ5IpBWfuQLN Feb 11 14:21:40 volumio volumio[14321]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:21:40 volumio volumio[14321]: info: New Spotify access token = BQD4u5tkyMk1_JScaZXC4VfLqta_1QcfUxQiZW6qYcgnJVMTKzH_pcN0KeGIbIuIfjjXyjpnnXs598fi3-e62ea36bZEiUKVE7azOPx1u5_-b9Ui7VPYVqu_6Lg41s_7T71zkjXqyAIpUXy-GPkK4BtgSAbZuEC1tW7fIOqhzExD-AOKV9TRXZrkhB0a7x88p3Nb2Lol4qbnakDOyFLwWK9vw2tO6Wtpg2lCcvtEqNgimuSiEK3ES_vMwl6IyAvqeyJ3fR-Fy74DGx2fdGk9N8iLaCWdLYhKAij1-zhzYtG6YZ5IpBWfuQLN Feb 11 14:21:40 volumio volumio[14321]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 14:21:40 volumio go-librespot[14587]: time="2026-02-11T14:21:40+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 11 14:21:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 14:21:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 14:21:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:41 volumio systemd[1]: shairport-sync.service: Consumed 2.246s CPU time. Feb 11 14:21:41 volumio volumio[14321]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:21:41 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:41 volumio sudo[14608]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:41 volumio sudo[14612]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:41 volumio sudo[14610]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:41 volumio volumio[14321]: info: Shairport-Sync Started Feb 11 14:21:41 volumio volumio[14321]: Error adding Membership: Error: addMembership EINVAL Feb 11 14:21:41 volumio volumio[14321]: info: Shairport-Sync Started Feb 11 14:21:41 volumio volumio[14321]: info: Shairport-Sync Started Feb 11 14:21:41 volumio volumio[14321]: 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 11 14:21:41 volumio volumio[14321]: info: Spotify Successfully logged in Feb 11 14:21:41 volumio volumio[14321]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:21:41 volumio volumio[14321]: info: [1770794501603] CoreMusicLibrary::Adding element Spotify Feb 11 14:21:41 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:21:41 volumio volumio[14321]: Cannot find translation for source YouTube Music Feb 11 14:21:41 volumio volumio[14321]: Cannot find translation for source Spotify Feb 11 14:21:42 volumio volumio[14321]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 14:21:42 volumio volumio[14321]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:21:42 volumio volumio[14321]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:21:42 volumio volumio[14321]: info: CoreCommandRouter::volumioGetState Feb 11 14:21:42 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:42 volumio volumio[14321]: info: CoreStateMachine::pushState Feb 11 14:21:42 volumio volumio[14321]: info: CorePlayQueue::getTrack 0 Feb 11 14:21:42 volumio volumio[14321]: info: CoreCommandRouter::volumioPushState Feb 11 14:21:43 volumio volumio[14321]: info: go-librespot daemon successfully initialized Feb 11 14:21:43 volumio mpd[14551]: 2026-02-11T14:21:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 14:21:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 14:21:43 volumio sudo[14511]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:43 volumio sudo[14523]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 11 14:21:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:44 volumio go-librespot[14652]: go-librespot daemon starting... Feb 11 14:21:44 volumio volumio[14321]: error: MPD error: The expression evaluated to a falsy value: Feb 11 14:21:44 volumio volumio[14321]: assert.ok(self.idling) Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=debug msg="app state loaded" Feb 11 14:21:44 volumio volumio[14321]: error: The expression evaluated to a falsy value: Feb 11 14:21:44 volumio volumio[14321]: assert.ok(self.idling) Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:44 volumio volumio[14321]: error: updateQueue error: null Feb 11 14:21:44 volumio volumio[14321]: info: MPD running with PID14551 Feb 11 14:21:44 volumio volumio[14321]: ,establishing connection Feb 11 14:21:44 volumio volumio[14321]: info: Completed starting Core Plugins Feb 11 14:21:44 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:44 volumio volumio[14321]: info: ----- MyVolumio plugins startup ---- Feb 11 14:21:44 volumio volumio[14321]: info: ------------------------------------------- Feb 11 14:21:44 volumio volumio[14321]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 14:21:44 volumio volumio[14321]: error: updateQueue error: null Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+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 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+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 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+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 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=info msg="zeroconf server listening on port 44267" Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=debug msg="obtained new client token: AADEb1XQ5E0TcB23OjZ6xA1bjGI/1B2WzduSn4K0wOnGliJnZ9sdB89K7T1inbPWnpTM6cDb62XoIH9bfl5KYybSsE/fUZgijS8tT4Klgj5wpeY7UkxG04RpIhC7i2A4rgJRIQZp0SkWOgu9z8DJ25GyLk6TBFLm7+CY24Txms6kfn7gxeqw0VguWeP0FdqpBhLhVZrmvBVc7QwqO0G2vSvDRfrPsbVm/8Z7yE6B6d9gqG4D2eYJIPXMHg==" Feb 11 14:21:44 volumio go-librespot[14653]: time="2026-02-11T14:21:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:45 volumio go-librespot[14653]: time="2026-02-11T14:21:45+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:45 volumio go-librespot[14653]: time="2026-02-11T14:21:45+07:00" level=debug msg="completed challenge" Feb 11 14:21:45 volumio go-librespot[14653]: time="2026-02-11T14:21: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 11 14:21:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:46 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:46 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 11 14:21:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:48 volumio go-librespot[14660]: go-librespot daemon starting... Feb 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+07:00" level=debug msg="app state loaded" Feb 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+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 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+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 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+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 11 14:21:48 volumio go-librespot[14661]: time="2026-02-11T14:21:48+07:00" level=info msg="zeroconf server listening on port 38279" Feb 11 14:21:49 volumio volumio[14321]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 14:21:49 volumio go-librespot[14661]: time="2026-02-11T14:21:49+07:00" level=debug msg="obtained new client token: AABRmNDdhIRZEAIULeWVmcFfvl7eDFnSSdlyQnsTqkZJOx1Deba8Ttxgo+/2AoNwnv2YaUwQ2ZjMChkhQpW29XNYAx9ZUlj7h3tF0VFd6QscgJoRq+1kMmfUJNTU3KmtIqq4l56oxVDxNGOjD03AdWSkCfliJIAFkPgmXL+s03YUyCOc/yxgH2aeXxrbIT4G4DdkJU2XIHVEkgE+8lbsiJ+OIUOQAQyiJ9+wkzSOviTVz6NUL9APi/Y=" Feb 11 14:21:49 volumio go-librespot[14661]: time="2026-02-11T14:21:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:49 volumio go-librespot[14661]: time="2026-02-11T14:21:49+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:49 volumio go-librespot[14661]: time="2026-02-11T14:21:49+07:00" level=debug msg="completed challenge" Feb 11 14:21:49 volumio go-librespot[14661]: time="2026-02-11T14:21:49+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 11 14:21:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:49 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:49 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 11 14:21:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:52 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:52 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:52 volumio go-librespot[14669]: go-librespot daemon starting... Feb 11 14:21:52 volumio go-librespot[14670]: time="2026-02-11T14:21:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:52 volumio go-librespot[14670]: time="2026-02-11T14:21:52+07:00" level=debug msg="app state loaded" Feb 11 14:21:52 volumio go-librespot[14670]: time="2026-02-11T14:21:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 14:21:53 volumio volumio[14321]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+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 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+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 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+07:00" level=info msg="zeroconf server listening on port 42329" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+07:00" level=debug msg="obtained new client token: AADFYhGx4yNaMtsLR/JFHE4ki1glv8FtQBR+dZXIBN9yLiMZqv6ElTI80uM6nC63zvl/fXrTmTkmdCNU/l4N/7VBGr91V5d5GZ250KTxRRO5lGyMiqcVfL8wLSz0Td2emkazjdeoCI41U2hu6cL57JrioVEvG7RfUODhHMtsAQd24Weel4HjD4SUN+WTLU74WqiQRW7mBcI5VQXeUhj+sqY0DNFUoV5/SVtiyhbK6wX0nWZUG9f1smAOIw==" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+07:00" level=debug msg="completed keyexchange" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+07:00" level=debug msg="completed challenge" Feb 11 14:21:53 volumio go-librespot[14670]: time="2026-02-11T14:21:53+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 11 14:21:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:54 volumio volumio[14321]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 14:21:54 volumio volumio[14321]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 14:21:54 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:54 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:54 volumio volumio[14321]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 14:21:55 volumio volumio[14321]: info: MyVolumio login type: Token Feb 11 14:21:55 volumio volumio[14321]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 14:21:55 volumio volumio[14321]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 14:21:56 volumio volumio[14321]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 14:21:56 volumio volumio[14321]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 14:21:56 volumio volumio[14321]: info: Streaming services startup Feb 11 14:21:56 volumio volumio[14321]: info: Starting Streaming Daemon Feb 11 14:21:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 11 14:21:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:56 volumio sudo[14693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 14:21:56 volumio volumio[14321]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 14:21:56 volumio sudo[14693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:21:56 volumio go-librespot[14696]: go-librespot daemon starting... Feb 11 14:21:56 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:21:56 volumio sudo[14693]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:56 volumio go-librespot[14700]: time="2026-02-11T14:21:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:21:56 volumio go-librespot[14700]: time="2026-02-11T14:21:56+07:00" level=debug msg="app state loaded" Feb 11 14:21:56 volumio go-librespot[14700]: time="2026-02-11T14:21:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:21:57 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:21:57 volumio volumio[14321]: error: Cannot start Volumio Streaming Daemon Feb 11 14:21:57 volumio volumio[14321]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 14:21:57 volumio volumio[14321]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+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 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+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 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+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 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+07:00" level=info msg="zeroconf server listening on port 38817" Feb 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+07:00" level=debug msg="obtained new client token: AABMhB2I1WAFRRBAcds03I1Ns/int7lb3tjhHIurFyQLkTZQZ4e+k8GedfwLoXYTG58j7XeVncWjFTa+JPaSp5Z4rMAKbOFLDDMX2c82I8qR3vvu+jYFqPK2RIVVbFAMM5CRVCWYoo/T6PwJmfDZqUR0tIxd0jJBx9ZSJemMs01bWW5nzfM56v4oqbDl0JDAQ90PMOcQL1+u1t5GKlsHn8lFKOKeuEiMtglhkzxeAbr5o7EVBlgknOeleQ==" Feb 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:21:57 volumio go-librespot[14700]: time="2026-02-11T14:21:57+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 11 14:21:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:21:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:21:57 volumio volumio[14321]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 11 14:21:59 volumio volumio[14321]: info: MyVolumio token set successfully Feb 11 14:21:59 volumio volumio[14321]: info: MYVOLUMIO: Adding device Feb 11 14:21:59 volumio volumio[14321]: info: MYVOLUMIO: Evaluating Server Feb 11 14:21:59 volumio volumio[14321]: info: MyVolumio status changed Feb 11 14:21:59 volumio volumio[14321]: info: Streaming services startup Feb 11 14:21:59 volumio volumio[14321]: info: Starting Streaming Daemon Feb 11 14:21:59 volumio volumio[14321]: info: Removing browser output: myVolumio user plan is not superstar Feb 11 14:21:59 volumio volumio[14321]: info: Removing audio output: Feb 11 14:21:59 volumio volumio[14321]: info: Stoppping Tunnel 1 Feb 11 14:21:59 volumio sudo[14728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 14:21:59 volumio sudo[14728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:59 volumio sudo[14728]: pam_unix(sudo:session): session closed for user root Feb 11 14:21:59 volumio volumio[14321]: error: Cannot start Volumio Streaming Daemon Feb 11 14:21:59 volumio sudo[14731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 11 14:21:59 volumio volumio[14321]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 14:21:59 volumio volumio[14321]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 14:21:59 volumio sudo[14731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:21:59 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 11 14:21:59 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 11 14:21:59 volumio volumio[14321]: info: Setting Geolocation for MyVolumio to as1 Feb 11 14:21:59 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:59 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:59 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:21:59 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 11 14:21:59 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 11 14:21:59 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 11 14:21:59 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 11 14:21:59 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 11 14:21:59 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 11 14:22:00 volumio sudo[14731]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:00 volumio volumio[14321]: info: Remote SSH Stopped Feb 11 14:22:00 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:00 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:22:00 volumio volumio[14321]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 14:22:00 volumio volumio[14321]: info: Updating MyVolumio device info Feb 11 14:22:00 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:00 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:00 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 11 14:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:01 volumio go-librespot[14734]: go-librespot daemon starting... Feb 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+07:00" level=debug msg="app state loaded" Feb 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:01 volumio volumio[14321]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+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 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+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 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+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 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+07:00" level=info msg="zeroconf server listening on port 38739" Feb 11 14:22:01 volumio go-librespot[14735]: time="2026-02-11T14:22:01+07:00" level=debug msg="obtained new client token: AABaR8U+4pPs16IE6Zj7KLpnmGgDLZUpkmNmKNbPnOmiKnVMXVeFNBzG/j8kFXeNrlWv9N/VSlaGRW8X5QOXn7ru7Dlf0Pn27L2ha/pylkj3DqffvUm5GcuNiiNMd5ZqFyJRG/EdWKpnngmDxqM635t04ENoYp46yH5Dst7Jlh+Y6VUpDXHxymqR0N75VHp8Sj0CYAlsuILC6Q6JQYkBL5+hgiVT7KXnkiY78ZPwoXNWY85hRWuVKt/P2g==" Feb 11 14:22:02 volumio go-librespot[14735]: time="2026-02-11T14:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:02 volumio go-librespot[14735]: time="2026-02-11T14:22:02+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 11 14:22:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:03 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:03 volumio volumio[14321]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:22:04 volumio volumio[14321]: info: MYVOLUMIO: Adding device Feb 11 14:22:04 volumio volumio[14321]: info: MYVOLUMIO: Evaluating Server Feb 11 14:22:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 11 14:22:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:05 volumio go-librespot[14767]: go-librespot daemon starting... Feb 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+07:00" level=debug msg="app state loaded" Feb 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:05 volumio volumio[14321]: info: Setting Geolocation for MyVolumio to as1 Feb 11 14:22:05 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:05 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:05 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+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 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+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 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+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 11 14:22:05 volumio go-librespot[14773]: time="2026-02-11T14:22:05+07:00" level=info msg="zeroconf server listening on port 33285" Feb 11 14:22:06 volumio volumio[14321]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+07:00" level=debug msg="new websocket client" Feb 11 14:22:06 volumio volumio[14321]: info: Connection to go-librespot Websocket established Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+07:00" level=debug msg="obtained new client token: AADbdNQ8Be83CYs6/gC31IEdYtNQ3a4NzTDV5RoQKm3zBDrRjXwcTjMdZYrT+2uHiABTCCcUc5m5Mw1QQnPBpiO6mZ3dAxKYYI/CdU0OPX2IjAU+790w26gg2zCFw+QVTCZO4Yg7OW01Nf7k5Ah7TjsmOXM3qkxO56BdkCIyq+T5ng2BwzRvS3jf6otO5IBJXYQ+UPTeX2Q00DLPpt4UJFzF0Bl42b2+LqHCz+G8Eeu0JOLyjm/jQZ8=" Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+07:00" level=debug msg="completed challenge" Feb 11 14:22:06 volumio volumio[14321]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 11 14:22:06 volumio go-librespot[14773]: time="2026-02-11T14:22:06+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 11 14:22:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:06 volumio volumio[14321]: info: Connection to go-librespot Websocket closed Feb 11 14:22:06 volumio volumio[14321]: info: Updating MyVolumio device info Feb 11 14:22:06 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:06 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:06 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:07 volumio volumio[14321]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 11 14:22:08 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:22:08 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:08 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 11 14:22:08 volumio volumio-remote-updater[643]: Test mode disabled Feb 11 14:22:08 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 11 14:22:08 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 11 14:22:08 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 11 14:22:08 volumio volumio[14321]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for CPU utilization spike
    • \n
  • Fix for triggerhappy input permission
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 11 14:22:09 volumio volumio[14321]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 11 14:22:09 volumio volumio[14321]: info: Getting Spotify volume Feb 11 14:22:09 volumio volumio[14321]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:22:09 volumio volumio[14321]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:22:09 volumio volumio[14321]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 11 14:22:09 volumio volumio[14321]: errno: -111, Feb 11 14:22:09 volumio volumio[14321]: code: 'ECONNREFUSED', Feb 11 14:22:09 volumio volumio[14321]: syscall: 'connect', Feb 11 14:22:09 volumio volumio[14321]: address: '127.0.0.1', Feb 11 14:22:09 volumio volumio[14321]: port: 9879, Feb 11 14:22:09 volumio volumio[14321]: response: undefined Feb 11 14:22:09 volumio volumio[14321]: } Feb 11 14:22:09 volumio volumio[14321]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:22:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 11 14:22:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:09 volumio go-librespot[14799]: go-librespot daemon starting... Feb 11 14:22:09 volumio go-librespot[14800]: time="2026-02-11T14:22:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:09 volumio go-librespot[14800]: time="2026-02-11T14:22:09+07:00" level=debug msg="app state loaded" Feb 11 14:22:09 volumio go-librespot[14800]: time="2026-02-11T14:22:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+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 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+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 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+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 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+07:00" level=info msg="zeroconf server listening on port 42305" Feb 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+07:00" level=debug msg="obtained new client token: AAA7raZIik4sV2Ppbx02xrIIPfTCeWGTHQ3W0rBubLmXqtDygv9QMcUiehVHyN/TumS7eS5C1L+EpXUHoZ6SNA8nr3rg1MsI05DZqIfvUHtm1v8Y3crR2FJt5j3jKtr2atdAKQ34vaq5yeG576elOcIjVC9bdxVmu/bXQyRsKLicnF8lyP0f/Sga3WiFIf1ZrU/wJSkq03454UjdVWlA6/aHEVXI8gMAARmb/h8/DNwgsmvnP4R7qkZcVA==" Feb 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:10 volumio sudo[14810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 14:21' Feb 11 14:22:10 volumio sudo[14810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:10 volumio sudo[14810]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:10 volumio go-librespot[14800]: time="2026-02-11T14:22:10+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: read tcp 192.168.1.23:44034->104.199.241.202:4070: read: connection reset by peer" Feb 11 14:22:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:11 volumio volumio-remote-updater[643]: [2026-02-11 14:22:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 14:22:11 volumio volumio-remote-updater[643]: [2026-02-11 14:22:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 14:22:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 14:22:11 volumio systemd[1]: volumio.service: Consumed 58.558s CPU time. Feb 11 14:22:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 14:22:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 14:22:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11834. Feb 11 14:22:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 14:22:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 14:22:11 volumio systemd[1]: volumio.service: Consumed 58.558s CPU time. Feb 11 14:22:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 14:22:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 14:22:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 11 14:22:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:14 volumio go-librespot[14839]: go-librespot daemon starting... Feb 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+07:00" level=debug msg="app state loaded" Feb 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+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 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+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 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+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 11 14:22:14 volumio go-librespot[14840]: time="2026-02-11T14:22:14+07:00" level=info msg="zeroconf server listening on port 44327" Feb 11 14:22:14 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:14 volumio volumio[14824]: info: ----- Volumio3 ---- Feb 11 14:22:14 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:14 volumio volumio[14824]: info: ----- System startup ---- Feb 11 14:22:14 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:15 volumio go-librespot[14840]: time="2026-02-11T14:22:15+07:00" level=debug msg="obtained new client token: AAAOhCgnOEXbt8zQ6+A8ou2g2cCU429AfIMlSdjdkrHi0HKbbybOe8qXbE/PlEp4obwQ+DxUz13KyiHZsymKlmMw46F+8ZtYF74DkFAW//Ai9vq87HqYvnsFp+Wk1pZ8oQg/DU1vuOWT4597Z8GCYAgmpv9BIq4M3jN7h5P56PbE46y54gVDirWTmYu+TXgok/ECGd8EZt65DKunthxUeiRk/jbENmkSOQF2QaSzo98LkLfEu5huV5eNeQ==" Feb 11 14:22:15 volumio go-librespot[14840]: time="2026-02-11T14:22:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:15 volumio go-librespot[14840]: time="2026-02-11T14:22:15+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:15 volumio go-librespot[14840]: time="2026-02-11T14:22:15+07:00" level=debug msg="completed challenge" Feb 11 14:22:15 volumio go-librespot[14840]: time="2026-02-11T14:22:15+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 11 14:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:16 volumio volumio-remote-updater[643]: [2026-02-11 14:22:16] [connect] Successful connection Feb 11 14:22:16 volumio volumio[14824]: info: MYVOLUMIO Environment detected Feb 11 14:22:16 volumio volumio[14824]: info: Plugin folders cleanup Feb 11 14:22:16 volumio volumio[14824]: info: Scanning into folder /volumio/app/plugins/ Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category audio_interface Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category miscellanea Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category music_service Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category plugins.json Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category system_controller Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category user_interface Feb 11 14:22:16 volumio volumio[14824]: info: Scanning into folder /data/plugins/ Feb 11 14:22:16 volumio volumio[14824]: info: Scanning category music_service Feb 11 14:22:16 volumio volumio[14824]: info: Plugin folders cleanup completed Feb 11 14:22:16 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:16 volumio volumio[14824]: info: ----- Core plugins startup ---- Feb 11 14:22:16 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:16 volumio volumio[14824]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 14:22:16 volumio volumio[14824]: info: Adding plugin upnp to MyMusic Plugins Feb 11 14:22:16 volumio volumio[14824]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 14:22:16 volumio volumio[14824]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 14:22:16 volumio volumio[14824]: info: Loading plugins from folder /data/plugins/ Feb 11 14:22:16 volumio volumio[14824]: info: Loading plugin "system"... Feb 11 14:22:16 volumio volumio[14824]: info: Loading plugin "appearance"... Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "network"... Feb 11 14:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 11 14:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:18 volumio volumio[14824]: info: Refreshing Cached IP Addresses Feb 11 14:22:18 volumio sudo[14861]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 14:22:18 volumio sudo[14861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:18 volumio sudo[14863]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 14:22:18 volumio sudo[14863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "services"... Feb 11 14:22:18 volumio sudo[14861]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "alsa_controller"... Feb 11 14:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:18 volumio go-librespot[14859]: go-librespot daemon starting... Feb 11 14:22:18 volumio sudo[14863]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:18 volumio sudo[14871]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 14:22:18 volumio sudo[14871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:18 volumio go-librespot[14881]: time="2026-02-11T14:22:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:18 volumio go-librespot[14881]: time="2026-02-11T14:22:18+07:00" level=debug msg="app state loaded" Feb 11 14:22:18 volumio go-librespot[14881]: time="2026-02-11T14:22:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:18 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "wizard"... Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "networkfs"... Feb 11 14:22:18 volumio volumio[14824]: info: Starting Udev Watcher for removable devices Feb 11 14:22:18 volumio volumio[14824]: info: Ignoring mount for partition: boot Feb 11 14:22:18 volumio volumio[14824]: info: Ignoring mount for partition: volumio Feb 11 14:22:18 volumio volumio[14824]: info: Ignoring mount for partition: volumio_data Feb 11 14:22:18 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "volumio_command_line_client"... Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "upnp"... Feb 11 14:22:18 volumio volumio[14824]: info: [1770794538881] Starting Upmpd Daemon Feb 11 14:22:18 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "my_music"... Feb 11 14:22:18 volumio volumio[14824]: info: Loading plugin "mpd"... Feb 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+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 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+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 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+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 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+07:00" level=info msg="zeroconf server listening on port 42085" Feb 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+07:00" level=debug msg="obtained new client token: AABKx36Lk8viZzEbubfuGyJbYgAJOcizbQG2828kwopmpk7gTWp071nnFovIFlyX+F8u5omZrksDixCwluPSfHJ4ozilWoahwU3CROWUk/fU+GdSLutOaG82GMK6S5YRCdmBNA8cMxQGHtEEF14zuL3ZrRTGS54kxv5lhzGTGzRvVxzzBDC07DmHKKeOovF+EupCyzSf0Zq1PCDDTIZbKZXSJ2H374pmmg9KuGnDgeGNOOUyOfu7CX//mw==" Feb 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+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 11 14:22:19 volumio volumio[14824]: info: Loading plugin "upnp_browser"... Feb 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 14:22:19 volumio go-librespot[14881]: time="2026-02-11T14:22:19+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 11 14:22:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:21 volumio sudo[14871]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:22 volumio volumio[14824]: info: Starting UPNP Browser Feb 11 14:22:22 volumio volumio[14824]: info: Loading plugin "alarm-clock"... Feb 11 14:22:22 volumio volumio[14824]: info: Loading plugin "airplay_emulation"... Feb 11 14:22:22 volumio volumio[14824]: info: Starting Shairport Sync Feb 11 14:22:22 volumio volumio[14824]: info: Loading plugin "last_100"... Feb 11 14:22:22 volumio volumio[14824]: info: Loading plugin "webradio"... Feb 11 14:22:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 11 14:22:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:22 volumio go-librespot[14901]: go-librespot daemon starting... Feb 11 14:22:22 volumio go-librespot[14902]: time="2026-02-11T14:22:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:22 volumio go-librespot[14902]: time="2026-02-11T14:22:22+07:00" level=debug msg="app state loaded" Feb 11 14:22:22 volumio go-librespot[14902]: time="2026-02-11T14:22:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:22 volumio volumio[14824]: info: Loading plugin "i2s_dacs"... Feb 11 14:22:23 volumio volumio[14824]: info: Loading plugin "volumiodiscovery"... Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** For more information see Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:22:23 volumio volumio[14824]: *** WARNING *** For more information see Feb 11 14:22:23 volumio node[14824]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 14:22:23 volumio node[14824]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:22:23 volumio node[14824]: *** WARNING *** For more information see Feb 11 14:22:23 volumio node[14824]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 14:22:23 volumio node[14824]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 14:22:23 volumio node[14824]: *** WARNING *** For more information see Feb 11 14:22:23 volumio volumio[14824]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 14:22:23 volumio volumio[14824]: info: Discovery: Started advertising with name: Volumio Feb 11 14:22:23 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 14:22:23 volumio volumio[14824]: info: Loading plugin "spop"... Feb 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+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 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+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 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+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 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+07:00" level=info msg="zeroconf server listening on port 39375" Feb 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+07:00" level=debug msg="obtained new client token: AABVp+mBhLMyDYRiCjFLqNlZ87x3rss+y+XZirlaa18e0d72AuhUtZ9oP0RVr4erPPgXCSURw0Yo0LEsu0rpG0qKvWBrfGNPsxg4DbfA+m5fWbaVn6nGYggsswtXg9uuZV2gQM4Z77c859LhVIHhTzeZrZbsfC/AvvUKZwUEgz3jqymLTBEp570jFvWLO9ApIm0YdqK9AYjWjd+OldzS0I+Q6FrqSi4tFj6l3C3a8pzce9JJX29hlk9OJg==" Feb 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+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 11 14:22:23 volumio go-librespot[14902]: time="2026-02-11T14:22:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 11 14:22:24 volumio go-librespot[14902]: time="2026-02-11T14:22:24+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:24 volumio go-librespot[14902]: time="2026-02-11T14:22:24+07:00" level=debug msg="completed challenge" Feb 11 14:22:24 volumio go-librespot[14902]: time="2026-02-11T14:22:24+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 11 14:22:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:25 volumio volumio[14824]: info: Loading plugin "ytcr"... Feb 11 14:22:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 11 14:22:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:27 volumio go-librespot[14911]: go-librespot daemon starting... Feb 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+07:00" level=debug msg="app state loaded" Feb 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:27 volumio volumio[14824]: info: Loading plugin "ytmusic"... Feb 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+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 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+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 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+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 11 14:22:27 volumio go-librespot[14912]: time="2026-02-11T14:22:27+07:00" level=info msg="zeroconf server listening on port 40265" Feb 11 14:22:28 volumio go-librespot[14912]: time="2026-02-11T14:22:28+07:00" level=debug msg="obtained new client token: AAAXvd9VOsfvYpiuwlCxCVJywszmH8peH7j8KhNxrdh8X/ZJzSFVLAx5yO5v1r/iqgSGhRgyUSzKW+ynnn/2jl0nTVGCHMUtIvITYThfpG1HgHrtm+kf76WixKGgazpvbaocrpHrkUJqEykOToVw1TnY1xsUTLzn5bA6Abw0v1NhJ2kj4HZ1M7+TZpRZ0MCav96AAdjnMS4MJEdUDJLzsi3tpUbS2vJ8r6p7avOsrfIgDm1lSyj9EeQ=" Feb 11 14:22:28 volumio go-librespot[14912]: time="2026-02-11T14:22:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:28 volumio go-librespot[14912]: time="2026-02-11T14:22:28+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:28 volumio go-librespot[14912]: time="2026-02-11T14:22:28+07:00" level=debug msg="completed challenge" Feb 11 14:22:28 volumio go-librespot[14912]: time="2026-02-11T14:22:28+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 11 14:22:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:28 volumio volumio-remote-updater[643]: [2026-02-11 14:22:28] [connect] Successful connection Feb 11 14:22:28 volumio nmbd[966]: [2026/02/11 14:22:28.533087, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 11 14:22:28 volumio nmbd[966]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.23 for name WORKGROUP<1d>. Feb 11 14:22:28 volumio nmbd[966]: This response was from IP 192.168.1.237, reporting an IP address of 192.168.1.237. Feb 11 14:22:28 volumio volumio[14824]: info: Loading plugin "outputs"... Feb 11 14:22:28 volumio volumio[14824]: info: Loading plugin "albumart"... Feb 11 14:22:28 volumio volumio[14824]: info: Plugin example_plugin is not enabled Feb 11 14:22:28 volumio volumio[14824]: info: Loading plugin "inputs"... Feb 11 14:22:28 volumio volumio[14824]: info: Loading plugin "updater_comm"... Feb 11 14:22:29 volumio volumio[14824]: info: Plugin mpdemulation is not enabled Feb 11 14:22:29 volumio volumio[14824]: info: Loading plugin "rest_api"... Feb 11 14:22:29 volumio volumio[14824]: info: Loading plugin "websocket"... Feb 11 14:22:29 volumio volumio[14824]: info: Starting Socket.io Server version 1.7.4 Feb 11 14:22:29 volumio volumio[14824]: info: Loading plugin "RoonBridge"... Feb 11 14:22:29 volumio volumio[14824]: info: Applying required configuration parameters for plugin RoonBridge Feb 11 14:22:29 volumio volumio[14824]: info: Loading i18n strings for locale en Feb 11 14:22:29 volumio volumio[14824]: Updating browse sources language Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::initPlayerControls Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:22:29 volumio volumio[14824]: Express server listening on port 3000 Feb 11 14:22:29 volumio volumio[14824]: [Metrics] WebUI: 15s 886.68ms Feb 11 14:22:29 volumio volumio[14824]: info: CoreStateMachine::resetVolumioState Feb 11 14:22:29 volumio volumio[14824]: info: CoreStateMachine::getcurrentVolume Feb 11 14:22:29 volumio volumio[14824]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:22:29 volumio volumio[14934]: Forking 3 albumart workers Feb 11 14:22:30 volumio sudo[14949]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 14:22:30 volumio sudo[14951]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 14:22:30 volumio sudo[14949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:30 volumio sudo[14951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:30 volumio sudo[14949]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:30 volumio sudo[14951]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:30 volumio volumio[14824]: info: Volumio Network Manager: Network status updated: 1 Feb 11 14:22:30 volumio volumio[14824]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::pushState Feb 11 14:22:30 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::volumioPushState Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::updateTrackBlock Feb 11 14:22:30 volumio volumio[14824]: info: CorePlayQueue::getTrackBlock Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:22:30 volumio volumio-remote-updater[643]: [2026-02-11 14:22:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770794548 101 Feb 11 14:22:30 volumio volumio[14824]: 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 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:30 volumio volumio[14824]: info: Reloading queue from file Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::setRepeat null single undefined Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::pushState Feb 11 14:22:30 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::volumioPushState Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::setRandom null Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::pushState Feb 11 14:22:30 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::volumioPushState Feb 11 14:22:30 volumio volumio[14824]: info: Setting Device type: Raspberry PI Feb 11 14:22:30 volumio volumio[14824]: info: Completed loading Core Plugins Feb 11 14:22:30 volumio volumio[14824]: info: Preparing to generate the ALSA configuration file Feb 11 14:22:30 volumio volumio[14824]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:22:30 volumio volumio[14824]: info: CoreStateMachine::pushState Feb 11 14:22:30 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::volumioPushState Feb 11 14:22:30 volumio volumio[14824]: info: Asound.conf file unchanged, so no further update is needed Feb 11 14:22:30 volumio volumio[14824]: info: Output device has changed, restarting MPD Feb 11 14:22:30 volumio sudo[14994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 14:22:30 volumio sudo[14994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:30 volumio volumio[14824]: info: Output device has changed, restarting Shairport Sync Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:30 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:30 volumio sudo[14996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 14:22:30 volumio sudo[14996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:30 volumio volumio[14824]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:22:30 volumio sudo[14996]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:31 volumio volumio[14824]: info: ___________ START PLUGINS ___________ Feb 11 14:22:31 volumio volumio[14824]: info: ControllerMpd::onStart: Initializing MPD Feb 11 14:22:31 volumio volumio[14824]: info: Creating MPD Configuration file Feb 11 14:22:31 volumio sudo[14994]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:31 volumio sudo[14998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 14:22:31 volumio sudo[14998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:22:31 volumio volumio[14824]: info: [1770794551080] CoreMusicLibrary::Adding element Media Servers Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:31 volumio volumio[14824]: info: UPNP Browser: Client initialized successfully Feb 11 14:22:31 volumio sudo[15006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 14:22:31 volumio sudo[15006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:31 volumio sudo[15006]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:31 volumio sudo[15009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 14:22:31 volumio sudo[15009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:31 volumio volumio[14824]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 14:22:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 14:22:31 volumio systemd[1]: mpd.service: Consumed 7.208s CPU time. Feb 11 14:22:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 14:22:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 14:22:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 14:22:31 volumio volumio[14824]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:22:31 volumio volumio[14824]: info: [1770794551380] CoreMusicLibrary::Adding element Last_100 Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:22:31 volumio volumio[14824]: info: [1770794551389] CoreMusicLibrary::Adding element Webradio Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:22:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 14:22:31 volumio volumio[14824]: info: Initializing BBC Radios Feb 11 14:22:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 14:22:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 11 14:22:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 14:22:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 11 14:22:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 14:22:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 14:22:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 14:22:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 14:22:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 11 14:22:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:31 volumio go-librespot[15032]: go-librespot daemon starting... Feb 11 14:22:31 volumio go-librespot[15034]: time="2026-02-11T14:22:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:31 volumio go-librespot[15034]: time="2026-02-11T14:22:31+07:00" level=debug msg="app state loaded" Feb 11 14:22:31 volumio go-librespot[15034]: time="2026-02-11T14:22:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:31 volumio volumio[14824]: info: Creating Spotify config file Feb 11 14:22:31 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:32 volumio sudo[15026]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 14:22:32 volumio sudo[15026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 14:22:32 volumio sudo[15026]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22: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-gew4.spotify.com:80]" Feb 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22:32+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 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22:32+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 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22:32+07:00" level=info msg="zeroconf server listening on port 39833" Feb 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22:32+07:00" level=debug msg="obtained new client token: AAApXbJJzY0FDflSKJefnI32X9+OYHJyKGzzbJeQZQcflMq9ShABYavahTGC5Kjaog7e11NwyY9OYbNq7XhTiGnuzweRGDunmE/4OpCjSN0i1INMLwijeb0Uo8Gdku9yi9hCqKlwycX9oCLE3YKFxPyYE8CBhvmqjKTg1G/mM6PpSuvDZrrwHC4G17pWZtbkdUxwv89JR11sRGufihB3kIFP8omhbRNJLKghXie0lQBXKP9SSWk+x9UF8g==" Feb 11 14:22:32 volumio go-librespot[15034]: time="2026-02-11T14:22:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:33 volumio go-librespot[15034]: time="2026-02-11T14:22:33+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:33 volumio go-librespot[15034]: time="2026-02-11T14:22:33+07:00" level=debug msg="completed challenge" Feb 11 14:22:33 volumio go-librespot[15034]: time="2026-02-11T14:22:33+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 11 14:22:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:33 volumio volumio[14824]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:22:33 volumio volumio[14824]: info: [1770794553145] CoreMusicLibrary::Adding element YouTube Music Feb 11 14:22:33 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:33 volumio volumio[14824]: Cannot find translation for source YouTube Music Feb 11 14:22:33 volumio volumio[14824]: info: Volumio Calling Home Feb 11 14:22:33 volumio sudo[15054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 11 14:22:33 volumio sudo[15054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:33 volumio volumio[14952]: Starting albumart workers Feb 11 14:22:33 volumio sudo[15054]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:33 volumio volumio[14955]: Starting albumart workers Feb 11 14:22:33 volumio volumio[14956]: Starting albumart workers Feb 11 14:22:33 volumio volumio[14824]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 14:22:33 volumio volumio[14824]: info: Discovery: Found device Volumio Feb 11 14:22:33 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:33 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:34 volumio volumio[14824]: info: MPD Permissions set Feb 11 14:22:34 volumio volumio[14824]: info: MPD Permissions set Feb 11 14:22:34 volumio volumio[14824]: info: Upmpdcli Daemon Started Feb 11 14:22:34 volumio volumio[14824]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 11 14:22:34 volumio volumio[14824]: info: Discovery: Found device Volumio Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:34 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:34 volumio volumio[14824]: info: Spotify config file written Feb 11 14:22:34 volumio volumio[14824]: 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 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio sudo[15061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 14:22:34 volumio sudo[15061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:34 volumio go-librespot[15068]: go-librespot daemon starting... Feb 11 14:22:34 volumio sudo[15061]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 14:22:34 volumio volumio[14824]: info: No need to fix Spotify hosts Feb 11 14:22:34 volumio go-librespot[15073]: time="2026-02-11T14:22:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:34 volumio go-librespot[15073]: time="2026-02-11T14:22:34+07:00" level=debug msg="app state loaded" Feb 11 14:22:34 volumio go-librespot[15073]: time="2026-02-11T14:22:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+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 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+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 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+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 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+07:00" level=info msg="zeroconf server listening on port 36255" Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+07:00" level=debug msg="obtained new client token: AADKDGNu6vRaxs39RcZV+mkgKILNLfnf7hmemQ+tXZ5rKqDciCrerTa+jq9n5t/WuYdAAGwUTFVFzHtl+gHhgKtrv10o3ebXz0FIeCJAbaCQdzTXPuWRvN0oO6ot889euf7PRKPVQYDzZjd/UgWQAxqjCIbDZJemspyc1Fh6nU/I9adC1mY+raEXeVoYMN8RGAL3goyDYXMxIzVkU9bf+Z2hdQa0JIs6i8F0l5ROI+7EaHVsprMKAxnTiA==" Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+07:00" level=debug msg="completed challenge" Feb 11 14:22:35 volumio volumio[14824]: info: Volumio called home Feb 11 14:22:35 volumio go-librespot[15073]: time="2026-02-11T14:22:35+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 11 14:22:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:36 volumio volumio[14824]: info: Starting Shairport Sync Feb 11 14:22:36 volumio volumio[14824]: info: Starting Shairport Sync Feb 11 14:22:36 volumio volumio[14824]: info: Starting Shairport Sync Feb 11 14:22:36 volumio sudo[15100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:22:36 volumio sudo[15100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:36 volumio sudo[15102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:22:36 volumio sudo[15102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:36 volumio sudo[15104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 14:22:36 volumio sudo[15104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:36 volumio volumio[14824]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:22:36 volumio volumio[14824]: SPOTIFY: BQB1usFoBjif-mzdYiZrv_1H8HLcTmJSRoiJPPEEIOEFxvUBBFSlFpi4sKSV_mCjpHSi42mHv51PWlymoj5F1o_TIX3Uf7eBdriU4iaXiH-BRCJOyXQX5DFWYfWWE6I1SMG0K1JBtU17qmA3-umDYB0af4OJYxV8X6e6gfuKJ8eK-iBd0tAqniEuF6g7abnutIn8fI9CBUAaoRk0SsrKwkPa3sxfbiC_fayyckSHcpbz7DgocGgQbqHwErk6g0B2HKgqucq0SEkq1acPdj_RFCSCvUMkmzRLMECYkP5vu35M6VF_kCXn38ba Feb 11 14:22:36 volumio volumio[14824]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 11 14:22:36 volumio volumio[14824]: info: New Spotify access token = BQB1usFoBjif-mzdYiZrv_1H8HLcTmJSRoiJPPEEIOEFxvUBBFSlFpi4sKSV_mCjpHSi42mHv51PWlymoj5F1o_TIX3Uf7eBdriU4iaXiH-BRCJOyXQX5DFWYfWWE6I1SMG0K1JBtU17qmA3-umDYB0af4OJYxV8X6e6gfuKJ8eK-iBd0tAqniEuF6g7abnutIn8fI9CBUAaoRk0SsrKwkPa3sxfbiC_fayyckSHcpbz7DgocGgQbqHwErk6g0B2HKgqucq0SEkq1acPdj_RFCSCvUMkmzRLMECYkP5vu35M6VF_kCXn38ba Feb 11 14:22:36 volumio volumio[14824]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 14:22:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 11 14:22:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 11 14:22:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:22:36 volumio systemd[1]: shairport-sync.service: Consumed 2.420s CPU time. Feb 11 14:22:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 11 14:22:36 volumio sudo[15102]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:36 volumio sudo[15100]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:36 volumio sudo[15104]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:36 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:36 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:36 volumio volumio[14824]: info: Shairport-Sync Started Feb 11 14:22:36 volumio volumio[14824]: Error adding Membership: Error: addMembership EINVAL Feb 11 14:22:36 volumio volumio[14824]: info: Shairport-Sync Started Feb 11 14:22:36 volumio volumio[14824]: info: Shairport-Sync Started Feb 11 14:22:36 volumio volumio[14824]: 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 11 14:22:36 volumio volumio[14824]: info: Spotify Successfully logged in Feb 11 14:22:36 volumio volumio[14824]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 14:22:36 volumio volumio[14824]: info: [1770794556925] CoreMusicLibrary::Adding element Spotify Feb 11 14:22:36 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 14:22:36 volumio volumio[14824]: Cannot find translation for source YouTube Music Feb 11 14:22:36 volumio volumio[14824]: Cannot find translation for source Spotify Feb 11 14:22:37 volumio volumio[14824]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 14:22:37 volumio volumio[14824]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 14:22:37 volumio volumio[14824]: info: VolumeController:: Volume=100 Mute =false Feb 11 14:22:37 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:37 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:37 volumio volumio[14824]: info: CoreStateMachine::pushState Feb 11 14:22:37 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:37 volumio volumio[14824]: info: CoreCommandRouter::volumioPushState Feb 11 14:22:38 volumio volumio[14824]: info: go-librespot daemon successfully initialized Feb 11 14:22:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 11 14:22:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:38 volumio go-librespot[15140]: go-librespot daemon starting... Feb 11 14:22:38 volumio go-librespot[15141]: time="2026-02-11T14:22:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:38 volumio go-librespot[15141]: time="2026-02-11T14:22:38+07:00" level=debug msg="app state loaded" Feb 11 14:22:38 volumio go-librespot[15141]: time="2026-02-11T14:22:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:39 volumio mpd[15052]: 2026-02-11T14:22:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 14:22:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 14:22:39 volumio sudo[14998]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:39 volumio sudo[15009]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:39 volumio volumio[14824]: error: MPD error: The expression evaluated to a falsy value: Feb 11 14:22:39 volumio volumio[14824]: assert.ok(self.idling) Feb 11 14:22:39 volumio volumio[14824]: error: The expression evaluated to a falsy value: Feb 11 14:22:39 volumio volumio[14824]: assert.ok(self.idling) Feb 11 14:22:39 volumio volumio[14824]: error: updateQueue error: null Feb 11 14:22:39 volumio volumio[14824]: info: MPD running with PID15052 Feb 11 14:22:39 volumio volumio[14824]: ,establishing connection Feb 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+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 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+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 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+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 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+07:00" level=info msg="zeroconf server listening on port 37883" Feb 11 14:22:39 volumio volumio[14824]: info: Completed starting Core Plugins Feb 11 14:22:39 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:39 volumio volumio[14824]: info: ----- MyVolumio plugins startup ---- Feb 11 14:22:39 volumio volumio[14824]: info: ------------------------------------------- Feb 11 14:22:39 volumio volumio[14824]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 14:22:39 volumio volumio[14824]: error: updateQueue error: null Feb 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+07:00" level=debug msg="obtained new client token: AABc9Cqkt6y1qCBT0Zee1Ga0pGnlAv+p98o9/1rESKd178HX/B8pzcTbNv9yKNVi+1dGRRCbVS1PP+3RGvgTLYq0wEMw6GUvCASCk2vNg7X1weSOE/0V8eC4QNUI2VSsYi0kLOV4UYNSyj40mkSzOlOx1tMs7QwF/1JXsSM2SDNOgX7JG5+Yd1cEvx09Sy5hFp0zbaEveJRBaMTUCybxDOvOAhG+XM/DGiyxKtDnrLjGlP5Mdox+Vyr/7w==" Feb 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:39 volumio go-librespot[15141]: time="2026-02-11T14:22:39+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:40 volumio go-librespot[15141]: time="2026-02-11T14:22:39+07:00" level=debug msg="completed challenge" Feb 11 14:22:40 volumio go-librespot[15141]: time="2026-02-11T14:22:40+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 11 14:22:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:41 volumio volumio[14824]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:41 volumio volumio[14824]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:22:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 11 14:22:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:43 volumio go-librespot[15153]: go-librespot daemon starting... Feb 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+07:00" level=debug msg="app state loaded" Feb 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+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 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+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 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+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 11 14:22:43 volumio go-librespot[15154]: time="2026-02-11T14:22:43+07:00" level=info msg="zeroconf server listening on port 39245" Feb 11 14:22:44 volumio go-librespot[15154]: time="2026-02-11T14:22:44+07:00" level=debug msg="obtained new client token: AAAu/EDW/PMcLDPUG8Fq/j3LRoLEx4gjTG9gBghdaX8tHANNkm1pqVk95SIm/o+I8yGo24V7VPszc9nK0c6yj8pQ1XsNYn1ohMQvj6lWAKBPfaZM3CUgPgP6QHci69/UOXstvciJWiOCmYpu/B3jZrBzroEbE/zZXZHR6kFpTvXZD8wLgVz3kXZXzNNCzzUDVDHdD/jIr4wKCc5XGLD6Swq2v3AohjrNMCi5pGeZfNPlzaeQS7cQge8=" Feb 11 14:22:44 volumio go-librespot[15154]: time="2026-02-11T14:22:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:44 volumio volumio[14824]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 14:22:44 volumio go-librespot[15154]: time="2026-02-11T14:22:44+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:44 volumio go-librespot[15154]: time="2026-02-11T14:22:44+07:00" level=debug msg="completed challenge" Feb 11 14:22:44 volumio go-librespot[15154]: time="2026-02-11T14:22:44+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 11 14:22:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:44 volumio volumio[14824]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:44 volumio volumio[14824]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 11 14:22:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 11 14:22:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:47 volumio go-librespot[15161]: go-librespot daemon starting... Feb 11 14:22:47 volumio go-librespot[15162]: time="2026-02-11T14:22:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:47 volumio go-librespot[15162]: time="2026-02-11T14:22:47+07:00" level=debug msg="app state loaded" Feb 11 14:22:47 volumio go-librespot[15162]: time="2026-02-11T14:22:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:47 volumio volumio[14824]: info: Initializing connection to go-librespot Websocket Feb 11 14:22:47 volumio go-librespot[15162]: time="2026-02-11T14:22:47+07:00" level=debug msg="new websocket client" Feb 11 14:22:47 volumio volumio[14824]: info: Connection to go-librespot Websocket established Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+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 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+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 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+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 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+07:00" level=info msg="zeroconf server listening on port 39779" Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 14:22:48 volumio volumio[14824]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+07:00" level=debug msg="obtained new client token: AABX6Vi0mpd8eZknHK7SNdDeQUvec9Lsi0qjKR5PZZMh6QRMQHjjGq4M9iRSSLvM4Qom/oLPeit/PcBOHRdUhwTJzWQGZlFTmKfbK5+oUPn6ks1Hy2MNh1ws55ntvZa6owJgJN9QgQYdPcDahUMIxnDAF8KbtxUeq29T6AWHIVhfSOwoz5ON3exSRx6nSfwDe48etqa7MtAznDbM4XPCQ2Huqog8KMnFJ0s+MdyKG4PT6oJ8x3PtUW6G3g==" Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+07:00" level=debug msg="completed challenge" Feb 11 14:22:48 volumio go-librespot[15162]: time="2026-02-11T14:22:48+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 11 14:22:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:50 volumio volumio[14824]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 14:22:50 volumio volumio[14824]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 14:22:50 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:50 volumio volumio[14824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 14:22:50 volumio volumio[14824]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 14:22:50 volumio volumio[14824]: info: MyVolumio login type: Token Feb 11 14:22:50 volumio volumio[14824]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 14:22:50 volumio volumio[14824]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 14:22:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 11 14:22:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 14:22:51 volumio go-librespot[15184]: go-librespot daemon starting... Feb 11 14:22:51 volumio volumio[14824]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 14:22:51 volumio volumio[14824]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 14:22:51 volumio volumio[14824]: info: Streaming services startup Feb 11 14:22:51 volumio volumio[14824]: info: Starting Streaming Daemon Feb 11 14:22:51 volumio go-librespot[15185]: time="2026-02-11T14:22:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 11 14:22:51 volumio go-librespot[15185]: time="2026-02-11T14:22:51+07:00" level=debug msg="app state loaded" Feb 11 14:22:51 volumio go-librespot[15185]: time="2026-02-11T14:22:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 14:22:51 volumio sudo[15191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 14:22:51 volumio sudo[15191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 14:22:51 volumio volumio[14824]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 14:22:52 volumio sudo[15191]: pam_unix(sudo:session): session closed for user root Feb 11 14:22:52 volumio volumio[14824]: info: Getting Spotify volume Feb 11 14:22:52 volumio volumio[14824]: info: Connection to go-librespot Websocket closed Feb 11 14:22:52 volumio volumio[14824]: error: Cannot start Volumio Streaming Daemon Feb 11 14:22:52 volumio volumio[14824]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 14:22:52 volumio volumio[14824]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 14:22:52 volumio volumio[14824]: 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 11 14:22:52 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:52 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:52 volumio volumio[14824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 11 14:22:52 volumio volumio[14824]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 14:22:52 volumio volumio[14824]: SPOTIFY: VOLUMIO VOLUME 100 Feb 11 14:22:52 volumio volumio[14824]: info: Aligning Spotify Volume to Volumio Volume Feb 11 14:22:52 volumio volumio[14824]: info: CoreCommandRouter::volumioGetState Feb 11 14:22:52 volumio volumio[14824]: info: CorePlayQueue::getTrack 0 Feb 11 14:22:52 volumio volumio[14824]: info: Setting Spotify Volume from Volumio: 100 Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+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 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+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 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+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 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+07:00" level=info msg="zeroconf server listening on port 35739" Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+07:00" level=debug msg="obtained new client token: AAAHyPy9PqFlZRdQR2dbBJT5M09zI7KE7Vg2QjuVCg3X+clIJRwFO8Qxhv0IexJoojA81KkKM57MP7QZmaCTRaEXVqz8mleA/KqpYvNljvjJUkoPPPHDnE2WsjIftnEEPvU7U5tnFuee6YpbHptxT5mVrRJ6h0krmbPytfirK9SlGDQzLDI3pO8Mdk2B4AFvrvxcYx5xBjPx3B2QqGa6ExFysLLkrpN9ByQjjUr8yasMKbI4Z209E83z/Q==" Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+07:00" level=debug msg="completed keyexchange" Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+07:00" level=debug msg="completed challenge" Feb 11 14:22:52 volumio go-librespot[15185]: time="2026-02-11T14:22:52+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 11 14:22:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 11 14:22:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 11 14:22:52 volumio volumio[14824]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:22:53 volumio volumio[14824]: Error: socket hang up Feb 11 14:22:53 volumio volumio[14824]: at connResetException (node:internal/errors:720:14) Feb 11 14:22:53 volumio volumio[14824]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 11 14:22:53 volumio volumio[14824]: at Socket.emit (node:events:526:35) Feb 11 14:22:53 volumio volumio[14824]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 11 14:22:53 volumio volumio[14824]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 11 14:22:53 volumio volumio[14824]: code: 'ECONNRESET', Feb 11 14:22:53 volumio volumio[14824]: response: undefined Feb 11 14:22:53 volumio volumio[14824]: } Feb 11 14:22:53 volumio volumio[14824]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 14:22:54 volumio sudo[15213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 14:21' Feb 11 14:22:54 volumio sudo[15213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"