Feb 17 08:10:00 volumio go-librespot[6800]: time="2026-02-17T08:10:00+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 17 08:10:00 volumio volumio[6542]: info: Starting Shairport Sync
Feb 17 08:10:00 volumio volumio[6542]: info: Starting Shairport Sync
Feb 17 08:10:00 volumio volumio[6542]: info: Starting Shairport Sync
Feb 17 08:10:00 volumio go-librespot[6800]: time="2026-02-17T08:10:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 08:10:00 volumio sudo[6827]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:00 volumio sudo[6827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:00 volumio sudo[6829]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:00 volumio sudo[6829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:00 volumio go-librespot[6800]: time="2026-02-17T08:10:00+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:00 volumio sudo[6831]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:00 volumio go-librespot[6800]: time="2026-02-17T08:10:00+07:00" level=debug msg="completed challenge"
Feb 17 08:10:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 08:10:00 volumio sudo[6831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 08:10:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:00 volumio systemd[1]: shairport-sync.service: Consumed 2.290s CPU time.
Feb 17 08:10:00 volumio go-librespot[6800]: time="2026-02-17T08:10: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 17 08:10:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:00 volumio sudo[6827]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:00 volumio volumio[6542]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:10:00 volumio volumio[6542]: SPOTIFY: BQC9-jrFpWiTO_yxrHGptvIG__LTuMl8qdTU7xoYqAYi-dVkkc8uubrt94Uv9SXso7v42sDy5ojDXpeJGAyXpSFFVhyr0PVKz0wVvHt-Xqw3mtqK9vMp8ZgdV13ubcx3G6tVoSf6hQfUZ2JM2zNskVWWf5nRJujoi40OMyZ-yNDyTtM7jnAAA9k3TeikrhIkYcG0ETbSfIQoTtyvHIME3SMmwC3woSlp37ROyrH5KU9-kRIxwO15Elt26OMBg6W4nkvYqWLfVq_hjEt8IaFLm6qav5lTTEk_BV04r7xK9S3rMJtr3MdeyQBb
Feb 17 08:10:00 volumio volumio[6542]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:10:00 volumio volumio[6542]: info: New Spotify access token = BQC9-jrFpWiTO_yxrHGptvIG__LTuMl8qdTU7xoYqAYi-dVkkc8uubrt94Uv9SXso7v42sDy5ojDXpeJGAyXpSFFVhyr0PVKz0wVvHt-Xqw3mtqK9vMp8ZgdV13ubcx3G6tVoSf6hQfUZ2JM2zNskVWWf5nRJujoi40OMyZ-yNDyTtM7jnAAA9k3TeikrhIkYcG0ETbSfIQoTtyvHIME3SMmwC3woSlp37ROyrH5KU9-kRIxwO15Elt26OMBg6W4nkvYqWLfVq_hjEt8IaFLm6qav5lTTEk_BV04r7xK9S3rMJtr3MdeyQBb
Feb 17 08:10:00 volumio volumio[6542]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 17 08:10:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 08:10:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 08:10:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:00 volumio volumio[6542]: info: Shairport-Sync Started
Feb 17 08:10:00 volumio volumio[6542]: Error adding Membership: Error: addMembership EINVAL
Feb 17 08:10:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:00 volumio sudo[6829]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:00 volumio sudo[6831]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:00 volumio volumio[6542]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:00 volumio volumio[6542]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:00 volumio volumio[6542]: info: Shairport-Sync Started
Feb 17 08:10:00 volumio volumio[6542]: info: Shairport-Sync Started
Feb 17 08:10:00 volumio volumio[6542]: 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 17 08:10:00 volumio volumio[6542]: info: Spotify Successfully logged in
Feb 17 08:10:00 volumio volumio[6542]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:00 volumio volumio[6542]: info: [1771290600978] CoreMusicLibrary::Adding element Spotify
Feb 17 08:10:00 volumio volumio[6542]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:00 volumio volumio[6542]: Cannot find translation for source YouTube Music
Feb 17 08:10:00 volumio volumio[6542]: Cannot find translation for source Spotify
Feb 17 08:10:01 volumio volumio[6542]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 17 08:10:01 volumio volumio[6542]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:10:01 volumio volumio[6542]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:10:01 volumio volumio[6542]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:01 volumio volumio[6542]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:01 volumio volumio[6542]: info: CoreStateMachine::pushState
Feb 17 08:10:01 volumio volumio[6542]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:01 volumio volumio[6542]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:02 volumio volumio[6542]: info: go-librespot daemon successfully initialized
Feb 17 08:10:03 volumio mpd[6770]: 2026-02-17T08:10:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 17 08:10:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 17 08:10:03 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 17 08:10:03 volumio sudo[6730]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:03 volumio sudo[6741]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:03 volumio go-librespot[6884]: go-librespot daemon starting...
Feb 17 08:10:03 volumio go-librespot[6887]: time="2026-02-17T08:10:03+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:03 volumio go-librespot[6887]: time="2026-02-17T08:10:03+07:00" level=debug msg="app state loaded"
Feb 17 08:10:03 volumio go-librespot[6887]: time="2026-02-17T08:10:03+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:03 volumio volumio[6542]: error: MPD error: The expression evaluated to a falsy value:
Feb 17 08:10:03 volumio volumio[6542]:   assert.ok(self.idling)
Feb 17 08:10:03 volumio volumio[6542]: error: The expression evaluated to a falsy value:
Feb 17 08:10:03 volumio volumio[6542]:   assert.ok(self.idling)
Feb 17 08:10:03 volumio volumio[6542]: info: MPD running with PID6770
Feb 17 08:10:03 volumio volumio[6542]:  ,establishing connection
Feb 17 08:10:03 volumio volumio[6542]: error: updateQueue error: null
Feb 17 08:10:03 volumio volumio[6542]: info: Completed starting Core Plugins
Feb 17 08:10:03 volumio volumio[6542]: info: -------------------------------------------
Feb 17 08:10:03 volumio volumio[6542]: info: -----    MyVolumio plugins startup     ----
Feb 17 08:10:03 volumio volumio[6542]: info: -------------------------------------------
Feb 17 08:10:03 volumio volumio[6542]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 17 08:10:03 volumio volumio[6542]: error: updateQueue error: null
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=info msg="zeroconf server listening on port 34949"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="obtained new client token: AABja3ePyB8AVpeXSj14gsL19GSSWigY9NcxqAxVEA63yN0oUBKR+iMZ/5uXwklT5dcdaFGtjefyt7OBFH/e9CksmuKM2vtvZ7uwGcRmRb4C+KNVfwEWn0XmPb934kLthSPitrKtfTkHfmC3V7u+r1PNyPtkHYE79wmfXfSsHcDQCggyZnlybdZKU227MybxLrF8n3+ycxuMhrughrjkc3UNirSeKApVV4yofsWtEPJzVRggWmPQZIE="
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+07:00" level=debug msg="completed challenge"
Feb 17 08:10:04 volumio go-librespot[6887]: time="2026-02-17T08:10:04+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 17 08:10:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:05 volumio volumio[6542]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:05 volumio volumio[6542]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:10:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 17 08:10:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:07 volumio go-librespot[6894]: go-librespot daemon starting...
Feb 17 08:10:07 volumio go-librespot[6895]: time="2026-02-17T08:10:07+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:07 volumio go-librespot[6895]: time="2026-02-17T08:10:07+07:00" level=debug msg="app state loaded"
Feb 17 08:10:07 volumio go-librespot[6895]: time="2026-02-17T08:10:07+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10: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 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10: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 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10: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 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=info msg="zeroconf server listening on port 36751"
Feb 17 08:10:08 volumio volumio[6542]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=debug msg="obtained new client token: AABy2Gyeu83uthlHFERxsJeGHuMpTEAfxsyfuAQ49N9oLjzd4RRyZwChQQepGpg8aIWakFlmpPqTT4/KnUQp9AbtlBNhJ9JIQIpnBcQTILepdRM7SCLObmLLmU8lpZA7Ahpvl4q1qb1S06eoR3ad6AFsBBOxYXthqV468uIvm5I33bDB6ge5j9tNOg0C69S3ct3JODS0CtJYrR9Xxio7GpoHF8SSNWbVinstnX3v6rjIP5IuPKdVW1yo+w=="
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=debug msg="completed challenge"
Feb 17 08:10:08 volumio go-librespot[6895]: time="2026-02-17T08:10:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:10:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:08 volumio volumio[6542]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:08 volumio volumio[6542]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:10:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 17 08:10:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:11 volumio go-librespot[6902]: go-librespot daemon starting...
Feb 17 08:10:11 volumio go-librespot[6903]: time="2026-02-17T08:10:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:11 volumio go-librespot[6903]: time="2026-02-17T08:10:11+07:00" level=debug msg="app state loaded"
Feb 17 08:10:11 volumio go-librespot[6903]: time="2026-02-17T08:10:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:11 volumio volumio[6542]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="new websocket client"
Feb 17 08:10:12 volumio volumio[6542]: info: Connection to go-librespot Websocket established
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+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 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+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 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=info msg="zeroconf server listening on port 37041"
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin multiroom to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 17 08:10:12 volumio volumio[6542]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="obtained new client token: AAAoHsUCY8UmpLo/tVfum0k/99ErRMuLItPbnB1XAkMqcVMfThcKgWE7PYQQN+X2a3EZ2Seov3BHI0fb/fJ6VX8l7RYaDJCTn6CSNPrQDl/Pgh4kqN30uLx2SWHdav9v/D7wHt21qTKlqlwOhbaV+AZ4Rx4BX6KhxblKlbXYX6Jt+OMKsAR/mAdq84r+KKqfEwwmGTpbMvyi+KU5UzGXwFZ3/Ydz0OGAJf+IiuG5C1egjOLKKyktjeGXMw=="
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=debug msg="completed challenge"
Feb 17 08:10:12 volumio go-librespot[6903]: time="2026-02-17T08:10:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:10:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:14 volumio volumio[6542]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 17 08:10:14 volumio volumio[6542]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 17 08:10:14 volumio volumio[6542]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:14 volumio volumio[6542]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:14 volumio volumio[6542]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 17 08:10:14 volumio volumio[6542]: info: MyVolumio login type: Token
Feb 17 08:10:14 volumio volumio[6542]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 17 08:10:14 volumio volumio[6542]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 17 08:10:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 17 08:10:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:16 volumio go-librespot[6926]: go-librespot daemon starting...
Feb 17 08:10:16 volumio volumio[6542]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 17 08:10:16 volumio volumio[6542]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 17 08:10:16 volumio volumio[6542]: info: Streaming services startup
Feb 17 08:10:16 volumio volumio[6542]: info: Starting Streaming Daemon
Feb 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+07:00" level=debug msg="app state loaded"
Feb 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:16 volumio sudo[6934]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 17 08:10:16 volumio sudo[6934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:16 volumio volumio[6542]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 17 08:10:16 volumio sudo[6934]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:16 volumio volumio[6542]: info: Getting Spotify volume
Feb 17 08:10:16 volumio volumio[6542]: info: Connection to go-librespot Websocket closed
Feb 17 08:10:16 volumio volumio[6542]: error: Cannot start Volumio Streaming Daemon
Feb 17 08:10:16 volumio volumio[6542]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 17 08:10:16 volumio volumio[6542]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 17 08:10:16 volumio volumio[6542]: 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 17 08:10:16 volumio volumio[6542]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:16 volumio volumio[6542]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:16 volumio volumio[6542]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 08:10:16 volumio volumio[6542]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 17 08:10:16 volumio volumio[6542]: SPOTIFY: VOLUMIO VOLUME 100
Feb 17 08:10:16 volumio volumio[6542]: info: Aligning Spotify Volume to Volumio Volume
Feb 17 08:10:16 volumio volumio[6542]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:16 volumio volumio[6542]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:16 volumio volumio[6542]: info: Setting Spotify Volume from Volumio: 100
Feb 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+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 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+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 17 08:10:16 volumio go-librespot[6927]: time="2026-02-17T08:10:16+07:00" level=info msg="zeroconf server listening on port 39229"
Feb 17 08:10:17 volumio go-librespot[6927]: time="2026-02-17T08:10:17+07:00" level=debug msg="obtained new client token: AADPvEQcv3x2Xi5djvhVh4RZUPq+6CTt3C69p2hlRi09sCvUW61g2NlSXcv4qKVQw1AMAzbJ3LDaHEdSMNFy+4DChLD+rXlkTuhGIpwTxoMi6TQZnDDzYIegjIQp3qUK/3mR8HAofy6y9svgXdzF8eJMbGYdYQyhjVF8tanXTOaKFo5QYqUXm5i2e9aAMITz5B+m26RkuzFgM2Kc2O5RBZLkfZG21rIwUbmIyAtER8zKT1zv35l6u2DOLg=="
Feb 17 08:10:17 volumio go-librespot[6927]: time="2026-02-17T08:10:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:17 volumio go-librespot[6927]: time="2026-02-17T08:10:17+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:17 volumio go-librespot[6927]: time="2026-02-17T08:10:17+07:00" level=debug msg="completed challenge"
Feb 17 08:10:17 volumio go-librespot[6927]: time="2026-02-17T08:10: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 17 08:10:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:17 volumio volumio[6542]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:10:17 volumio volumio[6542]: Error: socket hang up
Feb 17 08:10:17 volumio volumio[6542]:     at connResetException (node:internal/errors:720:14)
Feb 17 08:10:17 volumio volumio[6542]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 17 08:10:17 volumio volumio[6542]:     at Socket.emit (node:events:526:35)
Feb 17 08:10:17 volumio volumio[6542]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 17 08:10:17 volumio volumio[6542]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 17 08:10:17 volumio volumio[6542]:   code: 'ECONNRESET',
Feb 17 08:10:17 volumio volumio[6542]:   response: undefined
Feb 17 08:10:17 volumio volumio[6542]: }
Feb 17 08:10:17 volumio volumio[6542]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:10:18 volumio sudo[6955]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:09'
Feb 17 08:10:18 volumio sudo[6955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:19 volumio sudo[6955]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:19 volumio volumio-remote-updater[25144]: [2026-02-17 08:10:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 17 08:10:19 volumio volumio-remote-updater[25144]: [2026-02-17 08:10:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 17 08:10:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 17 08:10:19 volumio systemd[1]: volumio.service: Consumed 55.662s CPU time.
Feb 17 08:10:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 08:10:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20106.
Feb 17 08:10:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 08:10:19 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 17 08:10:19 volumio systemd[1]: volumio.service: Consumed 55.662s CPU time.
Feb 17 08:10:19 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 17 08:10:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 17 08:10:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:20 volumio go-librespot[6977]: go-librespot daemon starting...
Feb 17 08:10:20 volumio go-librespot[6978]: time="2026-02-17T08:10:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:20 volumio go-librespot[6978]: time="2026-02-17T08:10:20+07:00" level=debug msg="app state loaded"
Feb 17 08:10:20 volumio go-librespot[6978]: time="2026-02-17T08:10:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+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 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+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 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=info msg="zeroconf server listening on port 33161"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=debug msg="obtained new client token: AAALk4lKGjc9duR4Zw0Dg+HDEUyFvxu3rIF1bNp7MvS3X228okqomg6vxBB8+/4xPjhHSzMDSAeYVIwVZcgl+D7k4TV2PShpYa3qmU5anU+WRlgnqDFWawms2sOINEjpWsFtxsog8C18FtptTUtkvlTyNjkZQYSM6QT9cvggXTVgsdQhR0lJT0Yh2U5+1lJ8iwyUgtjpN/LAXPBNHMeHt8m51wcsaHEP1T3fsEtMtkazXNoBlvQz23MxZw=="
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=debug msg="completed challenge"
Feb 17 08:10:21 volumio go-librespot[6978]: time="2026-02-17T08:10:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:10:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:23 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:23 volumio volumio[6967]: info: -----            Volumio3              ----
Feb 17 08:10:23 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:23 volumio volumio[6967]: info: -----          System startup          ----
Feb 17 08:10:23 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:24 volumio volumio-remote-updater[25144]: [2026-02-17 08:10:24] [connect] Successful connection
Feb 17 08:10:24 volumio volumio[6967]: info: MYVOLUMIO Environment detected
Feb 17 08:10:24 volumio volumio[6967]: info: Plugin folders cleanup
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning into folder /volumio/app/plugins/
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category audio_interface
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category miscellanea
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category music_service
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category plugins.json
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category system_controller
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category user_interface
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning into folder /data/plugins/
Feb 17 08:10:24 volumio volumio[6967]: info: Scanning category music_service
Feb 17 08:10:24 volumio volumio[6967]: info: Plugin folders cleanup completed
Feb 17 08:10:24 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:24 volumio volumio[6967]: info: -----      Core plugins startup        ----
Feb 17 08:10:24 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:24 volumio volumio[6967]: info: Loading plugins from folder /volumio/app/plugins/
Feb 17 08:10:24 volumio volumio[6967]: info: Adding plugin upnp to MyMusic Plugins
Feb 17 08:10:24 volumio volumio[6967]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 17 08:10:24 volumio volumio[6967]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 17 08:10:24 volumio volumio[6967]: info: Loading plugins from folder /data/plugins/
Feb 17 08:10:24 volumio volumio[6967]: info: Loading plugin "system"...
Feb 17 08:10:24 volumio volumio[6967]: info: Loading plugin "appearance"...
Feb 17 08:10:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 17 08:10:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:25 volumio go-librespot[6998]: go-librespot daemon starting...
Feb 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+07:00" level=debug msg="app state loaded"
Feb 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+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 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+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 17 08:10:25 volumio go-librespot[6999]: time="2026-02-17T08:10:25+07:00" level=info msg="zeroconf server listening on port 33755"
Feb 17 08:10:26 volumio go-librespot[6999]: time="2026-02-17T08:10:26+07:00" level=debug msg="obtained new client token: AAC8HHKEdNqPCAdAfEM6JKJbMeP345MqTmBAn9kNRaU94yYZonau5yCQPWAAMzg+Cdtr4oH0bgNmvnMs3B9pjYoAkilRszDnhh7BNd8bq/ekIcX+ipey+KorYaOEOELP9/3ky0VbQYeGAehIicAHsJRBmNfyFTzBqqdy/0rixhrW3Vv0HjQ7V3ck0ZxmGnkpcoyOB5xWUGLSH9mrNprrtLoK9hTAUgrW8WIxfNKoI7Zc4itN/63ckDwRvg=="
Feb 17 08:10:26 volumio go-librespot[6999]: time="2026-02-17T08:10:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:26 volumio go-librespot[6999]: time="2026-02-17T08:10:26+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:26 volumio go-librespot[6999]: time="2026-02-17T08:10:26+07:00" level=debug msg="completed challenge"
Feb 17 08:10:26 volumio go-librespot[6999]: time="2026-02-17T08:10: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 17 08:10:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "network"...
Feb 17 08:10:26 volumio volumio[6967]: info: Refreshing Cached IP Addresses
Feb 17 08:10:26 volumio sudo[7008]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 08:10:26 volumio sudo[7008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:26 volumio sudo[7010]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 08:10:26 volumio sudo[7010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "services"...
Feb 17 08:10:26 volumio sudo[7008]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "alsa_controller"...
Feb 17 08:10:26 volumio sudo[7010]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:26 volumio sudo[7017]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 17 08:10:26 volumio sudo[7017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:26 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "wizard"...
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "networkfs"...
Feb 17 08:10:26 volumio volumio[6967]: info: Starting Udev Watcher for removable devices
Feb 17 08:10:26 volumio volumio[6967]: info: Ignoring mount for partition: boot
Feb 17 08:10:26 volumio volumio[6967]: info: Ignoring mount for partition: volumio
Feb 17 08:10:26 volumio volumio[6967]: info: Ignoring mount for partition: volumio_data
Feb 17 08:10:26 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "volumio_command_line_client"...
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "upnp"...
Feb 17 08:10:26 volumio volumio[6967]: info: [1771290626950] Starting Upmpd Daemon
Feb 17 08:10:26 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "my_music"...
Feb 17 08:10:26 volumio volumio[6967]: info: Loading plugin "mpd"...
Feb 17 08:10:27 volumio volumio[6967]: info: Loading plugin "upnp_browser"...
Feb 17 08:10:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 17 08:10:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:29 volumio go-librespot[7041]: go-librespot daemon starting...
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=debug msg="app state loaded"
Feb 17 08:10:29 volumio sudo[7017]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 17 08:10:29 volumio go-librespot[7042]: time="2026-02-17T08:10:29+07:00" level=info msg="zeroconf server listening on port 40283"
Feb 17 08:10:30 volumio go-librespot[7042]: time="2026-02-17T08:10:30+07:00" level=debug msg="obtained new client token: AAC8x42uutKl3QdPzZo4bgiAE8v3T2dXL38NNfi3h7/uQbBSsN5g5Kl8zIa12VB+5OpG/Yh8R9Ze5XAmeRhecvXjKpZI+/e+C1+z8yFeTFQwlmlJovsE5jPpxpaAVcELMLEbfla/IssVoYIYp+IJxbw3+cUBPwTM/6hor1Ru+cBzBXJLsSIdTDvIwz3lJoBn6tfqNzRfr5af0Cz62IwztIOcVdHwcJuRSZCRjZJBGk5OQqXQpQzoEFg="
Feb 17 08:10:30 volumio go-librespot[7042]: time="2026-02-17T08:10:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:30 volumio go-librespot[7042]: time="2026-02-17T08:10:30+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:30 volumio go-librespot[7042]: time="2026-02-17T08:10:30+07:00" level=debug msg="completed challenge"
Feb 17 08:10:30 volumio go-librespot[7042]: time="2026-02-17T08:10:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:10:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:30 volumio volumio[6967]: info: Starting UPNP Browser
Feb 17 08:10:30 volumio volumio[6967]: info: Loading plugin "alarm-clock"...
Feb 17 08:10:30 volumio volumio[6967]: info: Loading plugin "airplay_emulation"...
Feb 17 08:10:30 volumio volumio[6967]: info: Starting Shairport Sync
Feb 17 08:10:30 volumio volumio[6967]: info: Loading plugin "last_100"...
Feb 17 08:10:30 volumio volumio[6967]: info: Loading plugin "webradio"...
Feb 17 08:10:31 volumio volumio[6967]: info: Loading plugin "i2s_dacs"...
Feb 17 08:10:31 volumio volumio[6967]: info: Loading plugin "volumiodiscovery"...
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** For more information see 
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:10:31 volumio volumio[6967]: *** WARNING *** For more information see 
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** For more information see 
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:10:31 volumio node[6967]: *** WARNING *** For more information see 
Feb 17 08:10:31 volumio volumio[6967]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 17 08:10:31 volumio volumio[6967]: info: Discovery: Started advertising with name: Volumio
Feb 17 08:10:31 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:10:31 volumio volumio[6967]: info: Loading plugin "spop"...
Feb 17 08:10:33 volumio volumio[6967]: info: Loading plugin "ytcr"...
Feb 17 08:10:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 17 08:10:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:33 volumio go-librespot[7052]: go-librespot daemon starting...
Feb 17 08:10:33 volumio go-librespot[7053]: time="2026-02-17T08:10:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:33 volumio go-librespot[7053]: time="2026-02-17T08:10:33+07:00" level=debug msg="app state loaded"
Feb 17 08:10:33 volumio go-librespot[7053]: time="2026-02-17T08:10:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+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 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+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 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=info msg="zeroconf server listening on port 38239"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=debug msg="obtained new client token: AABbZ8hGHK9zbI4cmIzNN/TBDSPpVU6dcmXcIgc1DwjP4ZocLm7sKK6dgh39NOoyObrESdQJetJS8ya5nWG6JDnVEGQRbR+cGWzXMGx1vawBiOWoA2XlDIPDqmtAI7h7Mq20mzGzKdbImKdu7iJ0vb600Xv5w/mFXwdpNVygWBtor2juQy3+5AwCPm68oOC/ow35U9TDi++0SmLECrhEYABBihBu4QW4ad8omL9FPaQMHhp+WLrSQE42oA=="
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+07:00" level=debug msg="completed challenge"
Feb 17 08:10:34 volumio go-librespot[7053]: time="2026-02-17T08:10:34+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 17 08:10:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:35 volumio volumio[6967]: info: Loading plugin "ytmusic"...
Feb 17 08:10:36 volumio volumio-remote-updater[25144]: [2026-02-17 08:10:36] [connect] Successful connection
Feb 17 08:10:36 volumio volumio[6967]: info: Loading plugin "outputs"...
Feb 17 08:10:36 volumio volumio[6967]: info: Loading plugin "albumart"...
Feb 17 08:10:36 volumio volumio[6967]: info: Plugin example_plugin is not enabled
Feb 17 08:10:36 volumio volumio[6967]: info: Loading plugin "inputs"...
Feb 17 08:10:36 volumio volumio[6967]: info: Loading plugin "updater_comm"...
Feb 17 08:10:36 volumio volumio[6967]: info: Plugin mpdemulation is not enabled
Feb 17 08:10:36 volumio volumio[6967]: info: Loading plugin "rest_api"...
Feb 17 08:10:37 volumio volumio[6967]: info: Loading plugin "websocket"...
Feb 17 08:10:37 volumio volumio[6967]: info: Starting Socket.io Server version 1.7.4
Feb 17 08:10:37 volumio volumio[6967]: info: Loading plugin "RoonBridge"...
Feb 17 08:10:37 volumio volumio[6967]: info: Applying required configuration parameters for plugin RoonBridge
Feb 17 08:10:37 volumio volumio[6967]: info: Loading i18n strings for locale en
Feb 17 08:10:37 volumio volumio[6967]: Updating browse sources language
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 17 08:10:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:37 volumio volumio[7069]: Forking 3 albumart workers
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::initPlayerControls
Feb 17 08:10:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:37 volumio go-librespot[7085]: go-librespot daemon starting...
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:37 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Feb 17 08:10:37 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:10:37 volumio volumio[6967]: Express server listening on port 3000
Feb 17 08:10:37 volumio volumio[6967]:  [Metrics]  WebUI:  15s 865.54ms 
Feb 17 08:10:37 volumio go-librespot[7086]: time="2026-02-17T08:10:37+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:37 volumio go-librespot[7086]: time="2026-02-17T08:10:37+07:00" level=debug msg="app state loaded"
Feb 17 08:10:37 volumio go-librespot[7086]: time="2026-02-17T08:10:37+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:38 volumio volumio[6967]: info: CoreStateMachine::resetVolumioState
Feb 17 08:10:38 volumio volumio[6967]: info: CoreStateMachine::getcurrentVolume
Feb 17 08:10:38 volumio volumio[6967]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:10:38 volumio sudo[7138]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 08:10:38 volumio sudo[7138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:38 volumio sudo[7138]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:38 volumio sudo[7140]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 08:10:38 volumio sudo[7140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:38 volumio sudo[7140]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:38 volumio volumio[6967]: info: Volumio Network Manager: Network status updated: 1
Feb 17 08:10:38 volumio go-librespot[7086]: time="2026-02-17T08:10:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 08:10:38 volumio go-librespot[7086]: time="2026-02-17T08:10:38+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 17 08:10:38 volumio go-librespot[7086]: time="2026-02-17T08:10:38+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 17 08:10:38 volumio go-librespot[7086]: time="2026-02-17T08:10:38+07:00" level=info msg="zeroconf server listening on port 41981"
Feb 17 08:10:38 volumio go-librespot[7086]: time="2026-02-17T08:10:38+07:00" level=debug msg="obtained new client token: AABTq2EyrHHcq7Qqrgj73y/wDcuInQLaPVRxVUPY5ZBi1fIbc+Y5kR20rpxxeKEogHNDPjV45PiY8aee8G7bfImE48LsM/PgxH6+jO5bnCCnp6x2swDerYUqm7KFR9D0KLXfYYEW8QGnJvJ52Z/NVcKoKxexdIbjKyKCUjboqYQKnXLHlnBduFviLv1kCXQfxGZc+TXDRRcVjy4YdWYHRueGh85OwKvyYQBPahdh+PyeU1hZfvCjNl2WXQ=="
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+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 17 08:10:39 volumio volumio-remote-updater[25144]: [2026-02-17 08:10:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771290636 101
Feb 17 08:10:39 volumio volumio[6967]: 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 17 08:10:39 volumio volumio[6967]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::pushState
Feb 17 08:10:39 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused"
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::updateTrackBlock
Feb 17 08:10:39 volumio volumio[6967]: info: CorePlayQueue::getTrackBlock
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:39 volumio volumio[6967]: info: Reloading queue from file
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::setRepeat null single undefined
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::pushState
Feb 17 08:10:39 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+07:00" level=debug msg="completed challenge"
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::setRandom null
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::pushState
Feb 17 08:10:39 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:39 volumio volumio[6967]: info: Setting Device type: Raspberry PI
Feb 17 08:10:39 volumio go-librespot[7086]: time="2026-02-17T08:10:39+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 17 08:10:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:39 volumio volumio[6967]: info: Completed loading Core Plugins
Feb 17 08:10:39 volumio volumio[6967]: info: Preparing to generate the ALSA configuration file
Feb 17 08:10:39 volumio volumio[6967]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:10:39 volumio volumio[6967]: info: CoreStateMachine::pushState
Feb 17 08:10:39 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:39 volumio sudo[7165]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 17 08:10:39 volumio volumio[6967]: info: Asound.conf file unchanged, so no further update is needed
Feb 17 08:10:39 volumio volumio[6967]: info: Output device has changed, restarting MPD
Feb 17 08:10:39 volumio sudo[7165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:39 volumio volumio[6967]: info: Output device has changed, restarting Shairport Sync
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:39 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:40 volumio sudo[7168]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 08:10:40 volumio sudo[7171]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 08:10:40 volumio sudo[7165]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:40 volumio sudo[7171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:40 volumio sudo[7168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:40 volumio volumio[6967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:10:40 volumio volumio[6967]: info: ___________ START PLUGINS ___________
Feb 17 08:10:40 volumio volumio[6967]: info: ControllerMpd::onStart: Initializing MPD
Feb 17 08:10:40 volumio volumio[6967]: info: Creating MPD Configuration file
Feb 17 08:10:40 volumio sudo[7168]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:40 volumio volumio[6967]: info: [1771290640230] CoreMusicLibrary::Adding element Media Servers
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:40 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 08:10:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 08:10:40 volumio systemd[1]: mpd.service: Consumed 7.142s CPU time.
Feb 17 08:10:40 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 08:10:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 08:10:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 08:10:40 volumio sudo[7178]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 08:10:40 volumio sudo[7178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:40 volumio sudo[7180]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 08:10:40 volumio sudo[7180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:40 volumio sudo[7178]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:40 volumio volumio[6967]: info: UPNP Browser: Client initialized successfully
Feb 17 08:10:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 08:10:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:40 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 08:10:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 08:10:40 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 08:10:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 08:10:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 08:10:40 volumio volumio[6967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:40 volumio volumio[6967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 08:10:40 volumio volumio[6967]: info: [1771290640600] CoreMusicLibrary::Adding element Last_100
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:40 volumio volumio[6967]: info: [1771290640621] CoreMusicLibrary::Adding element Webradio
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:10:40 volumio volumio[6967]: info: Initializing BBC Radios
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:40 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Feb 17 08:10:40 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Feb 17 08:10:40 volumio systemd[1]: setdatetime-helper.service: Consumed 2.171s CPU time.
Feb 17 08:10:40 volumio volumio[6967]: info: Creating Spotify config file
Feb 17 08:10:40 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:41 volumio sudo[7194]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 17 08:10:41 volumio sudo[7194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 17 08:10:41 volumio sudo[7194]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:41 volumio volumio[7096]: Starting albumart workers
Feb 17 08:10:42 volumio volumio[7094]: Starting albumart workers
Feb 17 08:10:42 volumio volumio[7088]: Starting albumart workers
Feb 17 08:10:42 volumio volumio[6967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:42 volumio volumio[6967]: info: [1771290642092] CoreMusicLibrary::Adding element YouTube Music
Feb 17 08:10:42 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:42 volumio volumio[6967]: Cannot find translation for source YouTube Music
Feb 17 08:10:42 volumio volumio[6967]: info: Volumio Calling Home
Feb 17 08:10:42 volumio sudo[7216]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 17 08:10:42 volumio sudo[7216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:42 volumio sudo[7216]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 17 08:10:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:42 volumio go-librespot[7221]: go-librespot daemon starting...
Feb 17 08:10:42 volumio go-librespot[7222]: time="2026-02-17T08:10:42+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:42 volumio volumio[6967]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 08:10:42 volumio volumio[6967]: info: Discovery: Found device Volumio
Feb 17 08:10:42 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:42 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:42 volumio volumio[6967]: info: MPD Permissions set
Feb 17 08:10:42 volumio volumio[6967]: info: MPD Permissions set
Feb 17 08:10:42 volumio volumio[6967]: info: Upmpdcli Daemon Started
Feb 17 08:10:42 volumio volumio[6967]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 17 08:10:42 volumio volumio[6967]: info: Discovery: Found device Volumio
Feb 17 08:10:42 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:42 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:42 volumio volumio[6967]: info: Spotify config file written
Feb 17 08:10:43 volumio sudo[7230]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 17 08:10:43 volumio sudo[7230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:43 volumio volumio[6967]: 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 17 08:10:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 17 08:10:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 17 08:10:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:43 volumio volumio[6967]: info: Volumio called home
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:43 volumio go-librespot[7233]: go-librespot daemon starting...
Feb 17 08:10:43 volumio sudo[7230]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio go-librespot[7236]: time="2026-02-17T08:10:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:43 volumio go-librespot[7236]: time="2026-02-17T08:10:43+07:00" level=debug msg="app state loaded"
Feb 17 08:10:43 volumio go-librespot[7236]: time="2026-02-17T08:10:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:10:43 volumio volumio[6967]: info: No need to fix Spotify hosts
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+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 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+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 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+07:00" level=info msg="zeroconf server listening on port 35251"
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+07:00" level=debug msg="obtained new client token: AAC5+SGy53u9DRny2lgA4fHCkhw7ab2gi6dr1+tpGnobtr+Xfq8ZMQ7RVNWpeEW0Da6qlmcQhMDiFNF3q3+Z71a04Gdfb1+8UcZNYO23VQ0X2/nzeWQC2JE95Cz4HVqTPVdEb+P+8q0POn9lYF8JuYI+ZItGJEXjiPAzifArrfuYjh45T9cjMWQO4tegFzbdCK0G9BUX5xqKZLtv/NcIBS/ors4pSVVFv4Nx6cG/hSdamqjJzhzN1lXXgQ=="
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10:44+07:00" level=debug msg="completed challenge"
Feb 17 08:10:44 volumio go-librespot[7236]: time="2026-02-17T08:10: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 17 08:10:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:44 volumio volumio[6967]: info: Starting Shairport Sync
Feb 17 08:10:44 volumio volumio[6967]: info: Starting Shairport Sync
Feb 17 08:10:44 volumio volumio[6967]: info: Starting Shairport Sync
Feb 17 08:10:44 volumio sudo[7271]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:44 volumio sudo[7271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:44 volumio sudo[7275]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:44 volumio sudo[7275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:45 volumio sudo[7273]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:10:45 volumio sudo[7273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:10:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 08:10:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 08:10:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:45 volumio systemd[1]: shairport-sync.service: Consumed 2.263s CPU time.
Feb 17 08:10:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:45 volumio sudo[7275]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:45 volumio sudo[7271]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 08:10:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 08:10:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:45 volumio volumio[6967]: info: Shairport-Sync Started
Feb 17 08:10:45 volumio volumio[6967]: Error adding Membership: Error: addMembership EINVAL
Feb 17 08:10:45 volumio volumio[6967]: info: Shairport-Sync Started
Feb 17 08:10:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:10:45 volumio sudo[7273]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:45 volumio volumio[6967]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:10:45 volumio volumio[6967]: SPOTIFY: BQDWoipzHbtnNVJJuT0ydmaSetgvgKYS1Rxp5mtLXb-SI4ALEOhPTXXbNGA1cd9wNgzW5iVGJt-BQBIIiOEA9-D2XnDUgB_OTYA9NlKwU3wsruacvCm5tLI4fZOdWhJ0Z8p6_6EcAn2IfPp_SvLmTpcVpPmL6OZf3LGFKTR1CmG1Ix0WJzb92pWGo2vU_4j86N9QjTHV2Og0biq41n2dHPvZ8T3hFrWrrZKC9vdKZebawOd_iZk8UBzGX-oXViVFAg0RgVZEb_TDvzIRHrMXo9C1pyqGLRSBBGo894SJx_gttUZmvgHsYb9V
Feb 17 08:10:45 volumio volumio[6967]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:10:45 volumio volumio[6967]: info: New Spotify access token = BQDWoipzHbtnNVJJuT0ydmaSetgvgKYS1Rxp5mtLXb-SI4ALEOhPTXXbNGA1cd9wNgzW5iVGJt-BQBIIiOEA9-D2XnDUgB_OTYA9NlKwU3wsruacvCm5tLI4fZOdWhJ0Z8p6_6EcAn2IfPp_SvLmTpcVpPmL6OZf3LGFKTR1CmG1Ix0WJzb92pWGo2vU_4j86N9QjTHV2Og0biq41n2dHPvZ8T3hFrWrrZKC9vdKZebawOd_iZk8UBzGX-oXViVFAg0RgVZEb_TDvzIRHrMXo9C1pyqGLRSBBGo894SJx_gttUZmvgHsYb9V
Feb 17 08:10:45 volumio volumio[6967]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 17 08:10:45 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:45 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:45 volumio volumio[6967]: info: Shairport-Sync Started
Feb 17 08:10:45 volumio volumio[6967]: 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 17 08:10:45 volumio volumio[6967]: info: Spotify Successfully logged in
Feb 17 08:10:45 volumio volumio[6967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:10:45 volumio volumio[6967]: info: [1771290645844] CoreMusicLibrary::Adding element Spotify
Feb 17 08:10:45 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:10:45 volumio volumio[6967]: Cannot find translation for source YouTube Music
Feb 17 08:10:45 volumio volumio[6967]: Cannot find translation for source Spotify
Feb 17 08:10:45 volumio volumio[6967]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 17 08:10:46 volumio volumio[6967]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:10:46 volumio volumio[6967]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:10:46 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:10:46 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:46 volumio volumio[6967]: info: CoreStateMachine::pushState
Feb 17 08:10:46 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:10:46 volumio volumio[6967]: info: CoreCommandRouter::volumioPushState
Feb 17 08:10:47 volumio volumio[6967]: info: go-librespot daemon successfully initialized
Feb 17 08:10:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 17 08:10:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:47 volumio go-librespot[7312]: go-librespot daemon starting...
Feb 17 08:10:47 volumio go-librespot[7313]: time="2026-02-17T08:10:47+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:47 volumio go-librespot[7313]: time="2026-02-17T08:10:47+07:00" level=debug msg="app state loaded"
Feb 17 08:10:47 volumio go-librespot[7313]: time="2026-02-17T08:10:47+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:48 volumio mpd[7214]: 2026-02-17T08:10:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 17 08:10:48 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 17 08:10:48 volumio sudo[7180]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:48 volumio sudo[7171]: pam_unix(sudo:session): session closed for user root
Feb 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10: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 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10: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 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10: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 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10:48+07:00" level=info msg="zeroconf server listening on port 35775"
Feb 17 08:10:48 volumio volumio[6967]: error: MPD error: The expression evaluated to a falsy value:
Feb 17 08:10:48 volumio volumio[6967]:   assert.ok(self.idling)
Feb 17 08:10:48 volumio volumio[6967]: error: The expression evaluated to a falsy value:
Feb 17 08:10:48 volumio volumio[6967]:   assert.ok(self.idling)
Feb 17 08:10:48 volumio volumio[6967]: info: MPD running with PID7214
Feb 17 08:10:48 volumio volumio[6967]:  ,establishing connection
Feb 17 08:10:48 volumio volumio[6967]: error: updateQueue error: null
Feb 17 08:10:48 volumio volumio[6967]: info: Completed starting Core Plugins
Feb 17 08:10:48 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:48 volumio volumio[6967]: info: -----    MyVolumio plugins startup     ----
Feb 17 08:10:48 volumio volumio[6967]: info: -------------------------------------------
Feb 17 08:10:48 volumio volumio[6967]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 17 08:10:48 volumio volumio[6967]: error: updateQueue error: null
Feb 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10:48+07:00" level=debug msg="obtained new client token: AACSZDLnmwACDgCfLV3QFpil4ixPMmJXX7PVfVNsL+RMNQWlMCDJmXi6t3gY7sziWlYvfUu+tGfCgHgT1oEndhdRjDk+63gT1sCzLLlmplXJRw+lEGbiZxA4adI3nLym92D4iEcrkkJwycA2+USonYjffOmcKynvgxySM91AKSSy14/C2Nop7+fik41vI5Bp6cWQODLoNGRaJk9I4fpIexfA7bwa8cVSWI6++H6mkF7ohV8vUP8Fe3WyCg=="
Feb 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10:48+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 17 08:10:48 volumio go-librespot[7313]: time="2026-02-17T08:10:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 17 08:10:49 volumio go-librespot[7313]: time="2026-02-17T08:10:49+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:49 volumio go-librespot[7313]: time="2026-02-17T08:10:49+07:00" level=debug msg="completed challenge"
Feb 17 08:10:49 volumio go-librespot[7313]: time="2026-02-17T08:10: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 17 08:10:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:50 volumio volumio[6967]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:50 volumio volumio[6967]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:10:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 17 08:10:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:52 volumio go-librespot[7325]: go-librespot daemon starting...
Feb 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10:52+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10:52+07:00" level=debug msg="app state loaded"
Feb 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10:52+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10: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 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10: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 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10: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 17 08:10:52 volumio go-librespot[7326]: time="2026-02-17T08:10:52+07:00" level=info msg="zeroconf server listening on port 40395"
Feb 17 08:10:53 volumio go-librespot[7326]: time="2026-02-17T08:10:53+07:00" level=debug msg="obtained new client token: AACtA4t8KVqYayyiLRhD9uMhQCM7IXZL5TrQiWP7fOi07P0aiHgnn+Q4t7FzGci8+pm8jcdkVaAX5To95qniFAIKS1gDlcvCpePI9eLns+0npeMJGyoq+eNLrlc/N8mYOPMAouPnICGzTDr62je0P0ggsUA0Sw57JC0wb+8RYHSxI3jNQwJcKZWpk4wMXobSIedUkJJL+jIkLsorzBDGjYzRyrI5Xhsg2nK+iCed3F2r1zviyYDjBXU="
Feb 17 08:10:53 volumio go-librespot[7326]: time="2026-02-17T08:10:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:53 volumio go-librespot[7326]: time="2026-02-17T08:10:53+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:53 volumio go-librespot[7326]: time="2026-02-17T08:10:53+07:00" level=debug msg="completed challenge"
Feb 17 08:10:53 volumio volumio[6967]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 17 08:10:53 volumio go-librespot[7326]: time="2026-02-17T08:10: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 17 08:10:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:53 volumio volumio[6967]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:53 volumio volumio[6967]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:10:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 17 08:10:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:10:56 volumio go-librespot[7333]: go-librespot daemon starting...
Feb 17 08:10:56 volumio go-librespot[7334]: time="2026-02-17T08:10:56+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:10:56 volumio go-librespot[7334]: time="2026-02-17T08:10:56+07:00" level=debug msg="app state loaded"
Feb 17 08:10:56 volumio go-librespot[7334]: time="2026-02-17T08:10:56+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:10:56 volumio volumio[6967]: info: Initializing connection to go-librespot Websocket
Feb 17 08:10:56 volumio go-librespot[7334]: time="2026-02-17T08:10:56+07:00" level=debug msg="new websocket client"
Feb 17 08:10:56 volumio volumio[6967]: info: Connection to go-librespot Websocket established
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+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 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+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 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+07:00" level=info msg="zeroconf server listening on port 41095"
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin multiroom to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 17 08:10:57 volumio volumio[6967]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+07:00" level=debug msg="obtained new client token: AAAJrwk1V/DrP5uMORApOUM0Ht9ZB1J9CTnqF2feIFL9Xl8Em5bxbmfpYo8sx3qxvhxk+3Djaq5tRLhCrVHB06C6fveVasYmwDGfeuP4z7Inbzsakoptsv7dQX5vBO0XUWg29qSM9pX2vc63mxQ0Sa7UOT53yDshD7sk0h+HkfP+GoOru9l5jy3neixQOZQ1vpccNd4XFnFyn4sCrtY1p7vvV7Jcmts+Oarkv4L//6Vp0dL6QnS/mn0dEg=="
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+07:00" level=debug msg="completed keyexchange"
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+07:00" level=debug msg="completed challenge"
Feb 17 08:10:57 volumio go-librespot[7334]: time="2026-02-17T08:10:57+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 17 08:10:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:10:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:10:59 volumio volumio[6967]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 17 08:10:59 volumio volumio[6967]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 17 08:10:59 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:59 volumio volumio[6967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:10:59 volumio volumio[6967]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 17 08:10:59 volumio volumio[6967]: info: MyVolumio login type: Token
Feb 17 08:10:59 volumio volumio[6967]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 17 08:10:59 volumio volumio[6967]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 17 08:11:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 17 08:11:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:00 volumio go-librespot[7356]: go-librespot daemon starting...
Feb 17 08:11:00 volumio go-librespot[7357]: time="2026-02-17T08:11:00+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:00 volumio go-librespot[7357]: time="2026-02-17T08:11:00+07:00" level=debug msg="app state loaded"
Feb 17 08:11:00 volumio go-librespot[7357]: time="2026-02-17T08:11:00+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:01 volumio volumio[6967]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 17 08:11:01 volumio volumio[6967]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 17 08:11:01 volumio volumio[6967]: info: Streaming services startup
Feb 17 08:11:01 volumio volumio[6967]: info: Starting Streaming Daemon
Feb 17 08:11:01 volumio sudo[7364]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:01 volumio sudo[7364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:01 volumio volumio[6967]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 17 08:11:01 volumio sudo[7364]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:01 volumio volumio[6967]: info: Getting Spotify volume
Feb 17 08:11:01 volumio volumio[6967]: info: Connection to go-librespot Websocket closed
Feb 17 08:11:01 volumio volumio[6967]: error: Cannot start Volumio Streaming Daemon
Feb 17 08:11:01 volumio volumio[6967]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:01 volumio volumio[6967]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 17 08:11:01 volumio volumio[6967]: 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 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+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 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+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 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+07:00" level=info msg="zeroconf server listening on port 45823"
Feb 17 08:11:01 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:01 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:01 volumio volumio[6967]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 08:11:01 volumio volumio[6967]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 17 08:11:01 volumio volumio[6967]: SPOTIFY: VOLUMIO VOLUME 100
Feb 17 08:11:01 volumio volumio[6967]: info: Aligning Spotify Volume to Volumio Volume
Feb 17 08:11:01 volumio volumio[6967]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:01 volumio volumio[6967]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:01 volumio volumio[6967]: info: Setting Spotify Volume from Volumio: 100
Feb 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+07:00" level=debug msg="obtained new client token: AADysBXWGqK/Oj9xM23B91BbTWHt4+Yzml8rKR4NCe/TbKtvYYD94Bd27jX+sKz1X8fH5SqT3jS+ZTXiNHc/aekWw5wK98JGAayOXTFFaGLvc0adDrHylQrIwAI9KCZ4NmZLHrRtqq0TaYvYb6zRSdItV1MIJwAQCgAmjFNAvHK7bg1BWf3dU80TuMEJfibEiECO+U6f9QT1Br7h685fUJ060pyMEcG8qNQOxjNyz9KjP8EOWiqpCvENYA=="
Feb 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:01 volumio go-librespot[7357]: time="2026-02-17T08:11:01+07:00" level=debug msg="completed challenge"
Feb 17 08:11:02 volumio go-librespot[7357]: time="2026-02-17T08:11:02+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 17 08:11:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:02 volumio volumio[6967]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:11:02 volumio volumio[6967]: Error: socket hang up
Feb 17 08:11:02 volumio volumio[6967]:     at connResetException (node:internal/errors:720:14)
Feb 17 08:11:02 volumio volumio[6967]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 17 08:11:02 volumio volumio[6967]:     at Socket.emit (node:events:526:35)
Feb 17 08:11:02 volumio volumio[6967]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 17 08:11:02 volumio volumio[6967]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 17 08:11:02 volumio volumio[6967]:   code: 'ECONNRESET',
Feb 17 08:11:02 volumio volumio[6967]:   response: undefined
Feb 17 08:11:02 volumio volumio[6967]: }
Feb 17 08:11:02 volumio volumio[6967]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:11:03 volumio sudo[7391]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:10'
Feb 17 08:11:03 volumio sudo[7391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:03 volumio sudo[7391]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:03 volumio volumio-remote-updater[25144]: [2026-02-17 08:11:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 17 08:11:03 volumio volumio-remote-updater[25144]: [2026-02-17 08:11:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 17 08:11:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 17 08:11:03 volumio systemd[1]: volumio.service: Consumed 55.597s CPU time.
Feb 17 08:11:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 17 08:11:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20107.
Feb 17 08:11:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 17 08:11:04 volumio systemd[1]: volumio.service: Consumed 55.597s CPU time.
Feb 17 08:11:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 17 08:11:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 17 08:11:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 17 08:11:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:05 volumio go-librespot[7416]: go-librespot daemon starting...
Feb 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11:05+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11:05+07:00" level=debug msg="app state loaded"
Feb 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11:05+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11: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 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11: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 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11: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 17 08:11:05 volumio go-librespot[7417]: time="2026-02-17T08:11:05+07:00" level=info msg="zeroconf server listening on port 36975"
Feb 17 08:11:06 volumio go-librespot[7417]: time="2026-02-17T08:11:06+07:00" level=debug msg="obtained new client token: AACD/EDtyU15QtzdfJZorBh27V/og1R5l4Df2LqE6ZmNurvU9cUQNd91UJ3momEZ4Vg6zIr57zdorUi9wNkOpr8joTHYcERd063zZDW8W7HPRBsF3fn/R5DnfRjYzCL2PgwsAVtc865ULH+CmTpk0S46+MfsXEzQ7LLa3wDPmVGPBknn1wUjiksm4IQNOy6Qh4S/Y7KywbtWbdkXXg0bc13X81F1XIMFOjwmtwnXlNGggDNdZ7U6ZC4="
Feb 17 08:11:06 volumio go-librespot[7417]: time="2026-02-17T08:11:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:06 volumio go-librespot[7417]: time="2026-02-17T08:11:06+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:06 volumio go-librespot[7417]: time="2026-02-17T08:11:06+07:00" level=debug msg="completed challenge"
Feb 17 08:11:06 volumio go-librespot[7417]: time="2026-02-17T08:11: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 17 08:11:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:07 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:07 volumio volumio[7404]: info: -----            Volumio3              ----
Feb 17 08:11:07 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:07 volumio volumio[7404]: info: -----          System startup          ----
Feb 17 08:11:07 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:08 volumio volumio-remote-updater[25144]: [2026-02-17 08:11:08] [connect] Successful connection
Feb 17 08:11:09 volumio volumio[7404]: info: MYVOLUMIO Environment detected
Feb 17 08:11:09 volumio volumio[7404]: info: Plugin folders cleanup
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning into folder /volumio/app/plugins/
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category audio_interface
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category miscellanea
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category music_service
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category plugins.json
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category system_controller
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category user_interface
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning into folder /data/plugins/
Feb 17 08:11:09 volumio volumio[7404]: info: Scanning category music_service
Feb 17 08:11:09 volumio volumio[7404]: info: Plugin folders cleanup completed
Feb 17 08:11:09 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:09 volumio volumio[7404]: info: -----      Core plugins startup        ----
Feb 17 08:11:09 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:09 volumio volumio[7404]: info: Loading plugins from folder /volumio/app/plugins/
Feb 17 08:11:09 volumio volumio[7404]: info: Adding plugin upnp to MyMusic Plugins
Feb 17 08:11:09 volumio volumio[7404]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 17 08:11:09 volumio volumio[7404]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 17 08:11:09 volumio volumio[7404]: info: Loading plugins from folder /data/plugins/
Feb 17 08:11:09 volumio volumio[7404]: info: Loading plugin "system"...
Feb 17 08:11:09 volumio volumio[7404]: info: Loading plugin "appearance"...
Feb 17 08:11:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 17 08:11:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:09 volumio go-librespot[7437]: go-librespot daemon starting...
Feb 17 08:11:09 volumio go-librespot[7438]: time="2026-02-17T08:11:09+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:09 volumio go-librespot[7438]: time="2026-02-17T08:11:09+07:00" level=debug msg="app state loaded"
Feb 17 08:11:09 volumio go-librespot[7438]: time="2026-02-17T08:11:09+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+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 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+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 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+07:00" level=info msg="zeroconf server listening on port 34831"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+07:00" level=debug msg="obtained new client token: AAAX4K5RpG1jxsTRyaUUf7Nu66U/AsQuvBZlhGgAp4r54RVtlY0a43bAo5bKcx0o16otldha+d3wG15F8O/z/nOUsoFaYNRUkF+7+lk4+2SBOFdG9in/3TgMo8aJGoT0jd5PmkW3Hq8Y0UJ0oyPnNEW1PTfBM2o1fNQvlF3onwH8CF2bgBNkcOqtvnmHbEWYFl1sGP4D+CJiSD0lWiINUbuZ8SLlAYSso39NE+qfsrZqRv+c8y/UzxWwFA=="
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+07:00" level=debug msg="completed challenge"
Feb 17 08:11:10 volumio go-librespot[7438]: time="2026-02-17T08:11:10+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 17 08:11:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "network"...
Feb 17 08:11:11 volumio volumio[7404]: info: Refreshing Cached IP Addresses
Feb 17 08:11:11 volumio sudo[7446]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 08:11:11 volumio sudo[7446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "services"...
Feb 17 08:11:11 volumio sudo[7448]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 08:11:11 volumio sudo[7448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:11 volumio sudo[7446]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "alsa_controller"...
Feb 17 08:11:11 volumio sudo[7448]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:11 volumio sudo[7455]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 17 08:11:11 volumio sudo[7455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:11 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "wizard"...
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "networkfs"...
Feb 17 08:11:11 volumio volumio[7404]: info: Starting Udev Watcher for removable devices
Feb 17 08:11:11 volumio volumio[7404]: info: Ignoring mount for partition: boot
Feb 17 08:11:11 volumio volumio[7404]: info: Ignoring mount for partition: volumio
Feb 17 08:11:11 volumio volumio[7404]: info: Ignoring mount for partition: volumio_data
Feb 17 08:11:11 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "volumio_command_line_client"...
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "upnp"...
Feb 17 08:11:11 volumio volumio[7404]: info: [1771290671711] Starting Upmpd Daemon
Feb 17 08:11:11 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "my_music"...
Feb 17 08:11:11 volumio volumio[7404]: info: Loading plugin "mpd"...
Feb 17 08:11:12 volumio volumio[7404]: info: Loading plugin "upnp_browser"...
Feb 17 08:11:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 17 08:11:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:14 volumio go-librespot[7479]: go-librespot daemon starting...
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+07:00" level=debug msg="app state loaded"
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:14 volumio sudo[7455]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+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 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+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 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+07:00" level=info msg="zeroconf server listening on port 46637"
Feb 17 08:11:14 volumio go-librespot[7480]: time="2026-02-17T08:11:14+07:00" level=debug msg="obtained new client token: AABm0YE+fNXyLRQL5zY26C3w2S/PoPZwr5nR+1xojHYWIkRkt8NO3U0nQQsTByT/Etoa/hFzh2ZAHxzzkjQkXbqyziLXkdA66S0skvx8+Zs4yACqDWoUyGJ1Wi+r1nzxMeElM7r1LegX0hExZYEC7Grp4EsNululkC/wCy47UBXY1c6wGMZGAgvvXcEuM5sZioo4VZkkyIiaXrM/LWZIFbWhkDcUdz2kGhexDv80UZylw4Y41zug+6glgg=="
Feb 17 08:11:15 volumio go-librespot[7480]: time="2026-02-17T08:11:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:15 volumio go-librespot[7480]: time="2026-02-17T08:11:15+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:15 volumio go-librespot[7480]: time="2026-02-17T08:11:15+07:00" level=debug msg="completed challenge"
Feb 17 08:11:15 volumio go-librespot[7480]: time="2026-02-17T08:11: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 17 08:11:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:15 volumio volumio[7404]: info: Starting UPNP Browser
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "alarm-clock"...
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "airplay_emulation"...
Feb 17 08:11:15 volumio volumio[7404]: info: Starting Shairport Sync
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "last_100"...
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "webradio"...
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "i2s_dacs"...
Feb 17 08:11:15 volumio volumio[7404]: info: Loading plugin "volumiodiscovery"...
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** For more information see 
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:11:16 volumio volumio[7404]: *** WARNING *** For more information see 
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** For more information see 
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 17 08:11:16 volumio node[7404]: *** WARNING *** For more information see 
Feb 17 08:11:16 volumio volumio[7404]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 17 08:11:16 volumio volumio[7404]: info: Discovery: Started advertising with name: Volumio
Feb 17 08:11:16 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 17 08:11:16 volumio volumio[7404]: info: Loading plugin "spop"...
Feb 17 08:11:17 volumio volumio[7404]: info: Loading plugin "ytcr"...
Feb 17 08:11:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 17 08:11:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:18 volumio go-librespot[7489]: go-librespot daemon starting...
Feb 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+07:00" level=debug msg="app state loaded"
Feb 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+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 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+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 17 08:11:18 volumio go-librespot[7490]: time="2026-02-17T08:11:18+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 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+07:00" level=info msg="zeroconf server listening on port 33385"
Feb 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+07:00" level=debug msg="obtained new client token: AACHDXBcVHbojg91cTT4Kd4W6ijmwpO7gXqI8I66nirpbGa8kXzCy2OIEkf1OUw6DlUU0rsFCT2sU/+TZ5e1VCfPpPcFSFtP6USZiz12UeLVsZN/cjl30gvySHOPMcIms/zOfAFl8lXQwJtMN4hxqIF24O3fT4T8V6zC95aBC3u8ZnJkBj7GI3Y6lmT140PhnTYyc8lUMuTr230nU3pST+ShbW0ZxJb1A8qbyx3ko1ODvM1DWcv5xmc="
Feb 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+07:00" level=debug msg="completed challenge"
Feb 17 08:11:19 volumio go-librespot[7490]: time="2026-02-17T08:11:19+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 17 08:11:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:20 volumio volumio[7404]: info: Loading plugin "ytmusic"...
Feb 17 08:11:21 volumio volumio-remote-updater[25144]: [2026-02-17 08:11:21] [connect] Successful connection
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "outputs"...
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "albumart"...
Feb 17 08:11:21 volumio volumio[7404]: info: Plugin example_plugin is not enabled
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "inputs"...
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "updater_comm"...
Feb 17 08:11:21 volumio volumio[7404]: info: Plugin mpdemulation is not enabled
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "rest_api"...
Feb 17 08:11:21 volumio volumio[7404]: info: Loading plugin "websocket"...
Feb 17 08:11:22 volumio volumio[7404]: info: Starting Socket.io Server version 1.7.4
Feb 17 08:11:22 volumio volumio[7404]: info: Loading plugin "RoonBridge"...
Feb 17 08:11:22 volumio volumio[7404]: info: Applying required configuration parameters for plugin RoonBridge
Feb 17 08:11:22 volumio volumio[7404]: info: Loading i18n strings for locale en
Feb 17 08:11:22 volumio volumio[7404]: Updating browse sources language
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 17 08:11:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:22 volumio go-librespot[7522]: go-librespot daemon starting...
Feb 17 08:11:22 volumio go-librespot[7523]: time="2026-02-17T08:11:22+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:22 volumio go-librespot[7523]: time="2026-02-17T08:11:22+07:00" level=debug msg="app state loaded"
Feb 17 08:11:22 volumio go-librespot[7523]: time="2026-02-17T08:11:22+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::initPlayerControls
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:11:22 volumio volumio[7404]: Express server listening on port 3000
Feb 17 08:11:22 volumio volumio[7404]:  [Metrics]  WebUI:  16s 57.11ms 
Feb 17 08:11:22 volumio volumio[7512]: Forking 3 albumart workers
Feb 17 08:11:22 volumio volumio[7404]: info: CoreStateMachine::resetVolumioState
Feb 17 08:11:22 volumio volumio[7404]: info: CoreStateMachine::getcurrentVolume
Feb 17 08:11:22 volumio volumio[7404]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:11:23 volumio sudo[7556]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 08:11:23 volumio sudo[7556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:23 volumio sudo[7564]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 08:11:23 volumio sudo[7556]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:23 volumio sudo[7564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:23 volumio sudo[7564]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:23 volumio volumio[7404]: info: Volumio Network Manager: Network status updated: 1
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+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 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+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 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+07:00" level=info msg="zeroconf server listening on port 35383"
Feb 17 08:11:23 volumio volumio[7404]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::pushState
Feb 17 08:11:23 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::volumioPushState
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::updateTrackBlock
Feb 17 08:11:23 volumio volumio[7404]: info: CorePlayQueue::getTrackBlock
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:11:23 volumio volumio-remote-updater[25144]: [2026-02-17 08:11:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771290681 101
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+07:00" level=debug msg="obtained new client token: AACWCCVVHmlO8NEbiDHRJyei/czoLtXdT7OFEzAUGbLXsoBU+s1XWuhxZfn+cz5CzcAOB2bikWW6CFMfZ4QXIbvyioVSrbw3qf7Ci3jXdBBGz6I+F/VFA943AY+I9MGDTvsiNdNgSOX/RIqfGZV5PI1WlmVFCb49hL7mn9L/Rnf8KKYDJIqc0hLPIOcVpbLKx5XHqZNzSKwAq03YbkBNmeh5E2wMFOWjR16k/uAUcqFPV7K6Yekpq3+VCw=="
Feb 17 08:11:23 volumio volumio[7404]: 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 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:23 volumio volumio[7404]: info: Reloading queue from file
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::setRepeat null single undefined
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::pushState
Feb 17 08:11:23 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::volumioPushState
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::setRandom null
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::pushState
Feb 17 08:11:23 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::volumioPushState
Feb 17 08:11:23 volumio volumio[7404]: info: Setting Device type: Raspberry PI
Feb 17 08:11:23 volumio volumio[7404]: info: Completed loading Core Plugins
Feb 17 08:11:23 volumio volumio[7404]: info: Preparing to generate the ALSA configuration file
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+07:00" level=debug msg="completed challenge"
Feb 17 08:11:23 volumio go-librespot[7523]: time="2026-02-17T08:11:23+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 17 08:11:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:23 volumio volumio[7404]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:11:23 volumio volumio[7404]: info: CoreStateMachine::pushState
Feb 17 08:11:23 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:23 volumio volumio[7404]: info: CoreCommandRouter::volumioPushState
Feb 17 08:11:24 volumio volumio[7404]: info: Asound.conf file unchanged, so no further update is needed
Feb 17 08:11:24 volumio volumio[7404]: info: Output device has changed, restarting MPD
Feb 17 08:11:24 volumio sudo[7581]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 17 08:11:24 volumio sudo[7581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:24 volumio volumio[7404]: info: Output device has changed, restarting Shairport Sync
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:24 volumio sudo[7583]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 08:11:24 volumio sudo[7583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:24 volumio sudo[7586]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 08:11:24 volumio sudo[7586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:24 volumio sudo[7583]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:24 volumio sudo[7581]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:24 volumio volumio[7404]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:11:24 volumio volumio[7404]: info: ___________ START PLUGINS ___________
Feb 17 08:11:24 volumio volumio[7404]: info: ControllerMpd::onStart: Initializing MPD
Feb 17 08:11:24 volumio volumio[7404]: info: Creating MPD Configuration file
Feb 17 08:11:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:11:24 volumio volumio[7404]: info: [1771290684356] CoreMusicLibrary::Adding element Media Servers
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:24 volumio sudo[7594]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 17 08:11:24 volumio sudo[7594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:24 volumio sudo[7594]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:24 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 08:11:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 08:11:24 volumio systemd[1]: mpd.service: Consumed 7.148s CPU time.
Feb 17 08:11:24 volumio volumio[7404]: info: UPNP Browser: Client initialized successfully
Feb 17 08:11:24 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 08:11:24 volumio sudo[7596]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 17 08:11:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 08:11:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 08:11:24 volumio sudo[7596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 08:11:24 volumio volumio[7404]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 08:11:24 volumio volumio[7404]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 17 08:11:24 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 17 08:11:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:11:24 volumio volumio[7404]: info: [1771290684691] CoreMusicLibrary::Adding element Last_100
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:24 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 17 08:11:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 17 08:11:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:11:24 volumio volumio[7404]: info: [1771290684708] CoreMusicLibrary::Adding element Webradio
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:11:24 volumio volumio[7404]: info: Initializing BBC Radios
Feb 17 08:11:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 17 08:11:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:24 volumio volumio[7404]: info: Creating Spotify config file
Feb 17 08:11:24 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:25 volumio sudo[7615]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 17 08:11:25 volumio sudo[7615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 17 08:11:25 volumio sudo[7615]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:26 volumio volumio[7404]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:11:26 volumio volumio[7404]: info: [1771290686145] CoreMusicLibrary::Adding element YouTube Music
Feb 17 08:11:26 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:26 volumio volumio[7404]: Cannot find translation for source YouTube Music
Feb 17 08:11:26 volumio volumio[7404]: info: Volumio Calling Home
Feb 17 08:11:26 volumio volumio[7531]: Starting albumart workers
Feb 17 08:11:26 volumio volumio[7533]: Starting albumart workers
Feb 17 08:11:26 volumio sudo[7627]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 17 08:11:26 volumio sudo[7627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:26 volumio sudo[7627]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:26 volumio volumio[7534]: Starting albumart workers
Feb 17 08:11:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 17 08:11:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:27 volumio volumio[7404]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 17 08:11:27 volumio volumio[7404]: info: Discovery: Found device Volumio
Feb 17 08:11:27 volumio volumio[7404]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:27 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:27 volumio go-librespot[7633]: go-librespot daemon starting...
Feb 17 08:11:27 volumio go-librespot[7634]: time="2026-02-17T08:11:27+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:27 volumio go-librespot[7634]: time="2026-02-17T08:11:27+07:00" level=debug msg="app state loaded"
Feb 17 08:11:27 volumio go-librespot[7634]: time="2026-02-17T08:11:27+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:27 volumio volumio[7404]: info: MPD Permissions set
Feb 17 08:11:27 volumio volumio[7404]: info: MPD Permissions set
Feb 17 08:11:27 volumio volumio[7404]: info: Upmpdcli Daemon Started
Feb 17 08:11:27 volumio volumio[7404]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 17 08:11:27 volumio volumio[7404]: info: Discovery: Found device Volumio
Feb 17 08:11:27 volumio volumio[7404]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:27 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:27 volumio volumio[7404]: info: Volumio called home
Feb 17 08:11:27 volumio volumio[7404]: info: Spotify config file written
Feb 17 08:11:27 volumio sudo[7641]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 17 08:11:27 volumio sudo[7641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 17 08:11:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 17 08:11:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:27 volumio go-librespot[7645]: go-librespot daemon starting...
Feb 17 08:11:27 volumio sudo[7641]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:27 volumio go-librespot[7646]: time="2026-02-17T08:11:27+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:27 volumio go-librespot[7646]: time="2026-02-17T08:11:27+07:00" level=debug msg="app state loaded"
Feb 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:28 volumio volumio[7404]: 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 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 17 08:11:28 volumio volumio[7404]: info: No need to fix Spotify hosts
Feb 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+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 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+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 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+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 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+07:00" level=info msg="zeroconf server listening on port 44697"
Feb 17 08:11:28 volumio go-librespot[7646]: time="2026-02-17T08:11:28+07:00" level=debug msg="obtained new client token: AABdEFjR0Av4Ud4sJToxYVEwjC7bn6UmHqu+hldKFcE92g4WblpgU7NBIcAOvZLxTSlA6lTAXpEmvSHXRvRbprZxlFuc5p790QZfWQuqnzYQt5q5BH1v9TNo7gF9nenrj7pe59Z8R+8xyS007sAUWOG9Hrn7TQ97Xy3STTdioPCNZxn47LdzmUPJjMCRB/f3GqsP7AKHyBLFT4VBley3abxmWnSciMr2C/PJ/uJlnuD4dL2EIjFaAwfVzg=="
Feb 17 08:11:29 volumio go-librespot[7646]: time="2026-02-17T08:11:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:29 volumio go-librespot[7646]: time="2026-02-17T08:11:29+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:29 volumio go-librespot[7646]: time="2026-02-17T08:11:29+07:00" level=debug msg="completed challenge"
Feb 17 08:11:29 volumio volumio[7404]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:11:29 volumio volumio[7404]: SPOTIFY: BQCeCNwasWWG3omsdQfdgCNCuFBT9XrJ7I792iEs37jZNnHHKk4wmrvKSCiAVR_GgRl5_SacldlnpSHaIKRIw0Y9yrBfyWYhExYaLzTDYkrHVnq8YiRYks-HjZpR1zNmrwkB9Wkifh3-n0XFc92DrlaF2PrwvJrQEGd0QkTpsbQ9T3kEnzelVA9JKTzUTKRlOqj3o3ru03h8dY8yJrbupuQwXsE7G6_Y1rSHVn7ZMStiz_Qn3IS5piTELx_sovI3fT6ZM8EujLxWwmkelC3Mzy-fwmRIikMSTwft0u_ou-Z6s7rPrsVnDekH
Feb 17 08:11:29 volumio volumio[7404]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 17 08:11:29 volumio volumio[7404]: info: New Spotify access token = BQCeCNwasWWG3omsdQfdgCNCuFBT9XrJ7I792iEs37jZNnHHKk4wmrvKSCiAVR_GgRl5_SacldlnpSHaIKRIw0Y9yrBfyWYhExYaLzTDYkrHVnq8YiRYks-HjZpR1zNmrwkB9Wkifh3-n0XFc92DrlaF2PrwvJrQEGd0QkTpsbQ9T3kEnzelVA9JKTzUTKRlOqj3o3ru03h8dY8yJrbupuQwXsE7G6_Y1rSHVn7ZMStiz_Qn3IS5piTELx_sovI3fT6ZM8EujLxWwmkelC3Mzy-fwmRIikMSTwft0u_ou-Z6s7rPrsVnDekH
Feb 17 08:11:29 volumio volumio[7404]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 17 08:11:29 volumio go-librespot[7646]: time="2026-02-17T08:11:29+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 17 08:11:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:29 volumio volumio[7404]: info: Starting Shairport Sync
Feb 17 08:11:29 volumio volumio[7404]: info: Starting Shairport Sync
Feb 17 08:11:29 volumio volumio[7404]: info: Starting Shairport Sync
Feb 17 08:11:29 volumio sudo[7683]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:11:29 volumio sudo[7683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:29 volumio sudo[7685]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:11:29 volumio sudo[7685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:29 volumio sudo[7687]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 17 08:11:29 volumio sudo[7687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 17 08:11:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 17 08:11:29 volumio volumio[7404]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:11:29 volumio systemd[1]: shairport-sync.service: Consumed 2.296s CPU time.
Feb 17 08:11:29 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 17 08:11:29 volumio sudo[7683]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:29 volumio sudo[7687]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:29 volumio sudo[7685]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:29 volumio volumio[7404]: info: Shairport-Sync Started
Feb 17 08:11:29 volumio volumio[7404]: Error adding Membership: Error: addMembership EINVAL
Feb 17 08:11:29 volumio volumio[7404]: info: Shairport-Sync Started
Feb 17 08:11:29 volumio volumio[7404]: info: Shairport-Sync Started
Feb 17 08:11:29 volumio volumio[7404]: 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 17 08:11:29 volumio volumio[7404]: info: Spotify Successfully logged in
Feb 17 08:11:29 volumio volumio[7404]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 17 08:11:29 volumio volumio[7404]: info: [1771290689971] CoreMusicLibrary::Adding element Spotify
Feb 17 08:11:29 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 08:11:29 volumio volumio[7404]: Cannot find translation for source YouTube Music
Feb 17 08:11:29 volumio volumio[7404]: Cannot find translation for source Spotify
Feb 17 08:11:30 volumio volumio[7404]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 17 08:11:30 volumio volumio[7404]: info: CoreCommandRouter::volumioRetrievevolume
Feb 17 08:11:30 volumio volumio[7404]: info: VolumeController:: Volume=100 Mute =false
Feb 17 08:11:30 volumio volumio[7404]: info: CoreCommandRouter::volumioGetState
Feb 17 08:11:30 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:30 volumio volumio[7404]: info: CoreStateMachine::pushState
Feb 17 08:11:30 volumio volumio[7404]: info: CorePlayQueue::getTrack 0
Feb 17 08:11:30 volumio volumio[7404]: info: CoreCommandRouter::volumioPushState
Feb 17 08:11:32 volumio volumio[7404]: info: go-librespot daemon successfully initialized
Feb 17 08:11:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 17 08:11:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:32 volumio go-librespot[7723]: go-librespot daemon starting...
Feb 17 08:11:32 volumio mpd[7625]: 2026-02-17T08:11:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11:32+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11:32+07:00" level=debug msg="app state loaded"
Feb 17 08:11:32 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11:32+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:32 volumio sudo[7596]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:32 volumio sudo[7586]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:32 volumio volumio[7404]: error: MPD error: The expression evaluated to a falsy value:
Feb 17 08:11:32 volumio volumio[7404]:   assert.ok(self.idling)
Feb 17 08:11:32 volumio volumio[7404]: error: The expression evaluated to a falsy value:
Feb 17 08:11:32 volumio volumio[7404]:   assert.ok(self.idling)
Feb 17 08:11:32 volumio volumio[7404]: info: MPD running with PID7625
Feb 17 08:11:32 volumio volumio[7404]:  ,establishing connection
Feb 17 08:11:32 volumio volumio[7404]: error: updateQueue error: null
Feb 17 08:11:32 volumio volumio[7404]: info: Completed starting Core Plugins
Feb 17 08:11:32 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:32 volumio volumio[7404]: info: -----    MyVolumio plugins startup     ----
Feb 17 08:11:32 volumio volumio[7404]: info: -------------------------------------------
Feb 17 08:11:32 volumio volumio[7404]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 17 08:11:32 volumio volumio[7404]: error: updateQueue error: null
Feb 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11: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 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11: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 17 08:11:32 volumio go-librespot[7724]: time="2026-02-17T08:11: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 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11:33+07:00" level=info msg="zeroconf server listening on port 40383"
Feb 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11:33+07:00" level=debug msg="obtained new client token: AAD9i7q1O/tPhDpg5Nuc1EuChRjj5caJzOZO7nwv5RGWzlciZhxOndrrRFF9bJL6KYkdzciE5gRZ7gXBKAsULZkExQwVR5tBC65njcrs5ujlhuf8bsnXoE41WLEf3CAoosy47n3uGNpg8AvHuy0ZH9nOuAwDWNsp1nJd8dmZpu+4GPqMYk+z5nFDNGKwY5Vpj71kjEkx58QzUeNZwCb7DYtUdDL4+EiZoMicOxckonBgyWAA0G5f6I0="
Feb 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11:33+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11:33+07:00" level=debug msg="completed challenge"
Feb 17 08:11:33 volumio go-librespot[7724]: time="2026-02-17T08:11: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 17 08:11:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:35 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:35 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 17 08:11:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:36 volumio go-librespot[7736]: go-librespot daemon starting...
Feb 17 08:11:36 volumio go-librespot[7737]: time="2026-02-17T08:11:36+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:36 volumio go-librespot[7737]: time="2026-02-17T08:11:36+07:00" level=debug msg="app state loaded"
Feb 17 08:11:36 volumio go-librespot[7737]: time="2026-02-17T08:11:36+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+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 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+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 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+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 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=info msg="zeroconf server listening on port 39633"
Feb 17 08:11:37 volumio volumio[7404]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=debug msg="obtained new client token: AACzNf4y/e/528JTqmARqF1FuR8zrnVA8UMcOLF1so1SlzzUqQXkX1++lH6ZxPLOX3d5AppiI6dcu5dNGgyipJEgsu0gnSdG5IG81bdjXz0GIJTWpzXETvbpQPCnGGqLOtOrXORzfDOEp73/XUtPpXwFUQR7WLR7z9oYZw/ayUFnIAmgSRFyS9yFKWjuzI7rRHydLetf9hHf9XlTtbwz2y1wo7SseYqSxnndzMqxhMA/OXZU4sulASeo7A=="
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=debug msg="completed challenge"
Feb 17 08:11:37 volumio go-librespot[7737]: time="2026-02-17T08:11:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:11:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:38 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:38 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 17 08:11:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:41 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:41 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:41 volumio go-librespot[7744]: go-librespot daemon starting...
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=debug msg="app state loaded"
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin multiroom to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 17 08:11:41 volumio volumio[7404]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+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 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+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 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=info msg="zeroconf server listening on port 41833"
Feb 17 08:11:41 volumio go-librespot[7745]: time="2026-02-17T08:11:41+07:00" level=debug msg="obtained new client token: AAAoRZj+skiz6IbJUgGjls46uXRQgzOUcpLNMN4dQToq976HA1IaG4fXF6rPAO2daW9Emr5S7waj4Aow+JArlh1V2AFyfxcbdNmx165tZBAHgSaWzLQ8j+a9UMTHhwv+sAzwQp65/5VT/q8RyZPTFJ0+kTqA6cPdMqT6vvaH9PjP/xv1KAJmemAVgbApybNZhPs03Q1YgWhJKnRLsBMHUU1aSlnzJJuXoYEq4w/S5Bx9+mkSryf3FgR0Jg=="
Feb 17 08:11:42 volumio go-librespot[7745]: time="2026-02-17T08:11:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:42 volumio go-librespot[7745]: time="2026-02-17T08:11:42+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:42 volumio go-librespot[7745]: time="2026-02-17T08:11:42+07:00" level=debug msg="completed challenge"
Feb 17 08:11:42 volumio go-librespot[7745]: time="2026-02-17T08:11:42+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 17 08:11:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:43 volumio volumio[7404]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 17 08:11:43 volumio volumio[7404]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 17 08:11:43 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:43 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:43 volumio volumio[7404]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 17 08:11:43 volumio volumio[7404]: info: MyVolumio login type: Token
Feb 17 08:11:43 volumio volumio[7404]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 17 08:11:43 volumio volumio[7404]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 17 08:11:45 volumio volumio[7404]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 17 08:11:45 volumio volumio[7404]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 17 08:11:45 volumio volumio[7404]: info: Streaming services startup
Feb 17 08:11:45 volumio volumio[7404]: info: Starting Streaming Daemon
Feb 17 08:11:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 17 08:11:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:45 volumio sudo[7767]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:45 volumio sudo[7767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:45 volumio volumio[7404]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 17 08:11:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:45 volumio go-librespot[7773]: go-librespot daemon starting...
Feb 17 08:11:45 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+07:00" level=debug msg="app state loaded"
Feb 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:45 volumio sudo[7767]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:45 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:45 volumio volumio[7404]: error: Cannot start Volumio Streaming Daemon
Feb 17 08:11:45 volumio volumio[7404]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:45 volumio volumio[7404]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+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 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+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 17 08:11:45 volumio go-librespot[7774]: time="2026-02-17T08:11:45+07:00" level=info msg="zeroconf server listening on port 36999"
Feb 17 08:11:46 volumio go-librespot[7774]: time="2026-02-17T08:11:46+07:00" level=debug msg="obtained new client token: AAA65besNdzJdG1mSiwzQeYJFFJZfne/QS98dPlps9I0ZTlBd/r+K+u3k92wzAeyvbVfyArPaPm78dwRFh0oWwJuYT3u3WgETrdG0XgazeHz647EMhvgAhPAG+wgpNKinaMiiNHNRFBH3yMvxTH0Uu9CXsFyzky46v21v3XMYvJCfheQ9DoD4lAyysiG7dAYWyOVDoSpUDRcF0zXMAAnMQuFxJorHllppecXITEgjtQkhVG6/kSW2WQ="
Feb 17 08:11:46 volumio go-librespot[7774]: time="2026-02-17T08:11:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:46 volumio go-librespot[7774]: time="2026-02-17T08:11:46+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:46 volumio go-librespot[7774]: time="2026-02-17T08:11:46+07:00" level=debug msg="completed challenge"
Feb 17 08:11:46 volumio go-librespot[7774]: time="2026-02-17T08:11:46+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 17 08:11:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:47 volumio volumio[7404]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 17 08:11:48 volumio volumio[7404]: info: MyVolumio token set successfully
Feb 17 08:11:48 volumio volumio[7404]: info: MYVOLUMIO: Adding device
Feb 17 08:11:48 volumio volumio[7404]: info: MYVOLUMIO: Evaluating Server
Feb 17 08:11:48 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:48 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:48 volumio volumio[7404]: info: MyVolumio status changed
Feb 17 08:11:48 volumio volumio[7404]: info: Streaming services startup
Feb 17 08:11:48 volumio volumio[7404]: info: Starting Streaming Daemon
Feb 17 08:11:48 volumio volumio[7404]: info: Removing browser output: myVolumio user plan is not superstar
Feb 17 08:11:48 volumio volumio[7404]: info: Removing audio output:
Feb 17 08:11:48 volumio volumio[7404]: info: Stoppping Tunnel 1
Feb 17 08:11:48 volumio sudo[7804]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:48 volumio sudo[7804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:49 volumio sudo[7804]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:49 volumio sudo[7807]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 17 08:11:49 volumio sudo[7807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:49 volumio volumio[7404]: error: Cannot start Volumio Streaming Daemon
Feb 17 08:11:49 volumio volumio[7404]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 17 08:11:49 volumio volumio[7404]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 17 08:11:49 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 17 08:11:49 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 17 08:11:49 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 17 08:11:49 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 17 08:11:49 volumio volumio[7404]: info: Setting Geolocation for MyVolumio to as1
Feb 17 08:11:49 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:49 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:49 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:49 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 17 08:11:49 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 17 08:11:49 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 17 08:11:49 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 17 08:11:49 volumio sudo[7807]: pam_unix(sudo:session): session closed for user root
Feb 17 08:11:49 volumio volumio[7404]: info: Remote SSH Stopped
Feb 17 08:11:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 17 08:11:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:49 volumio volumio[7404]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 17 08:11:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:49 volumio go-librespot[7809]: go-librespot daemon starting...
Feb 17 08:11:49 volumio go-librespot[7810]: time="2026-02-17T08:11:49+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:49 volumio go-librespot[7810]: time="2026-02-17T08:11:49+07:00" level=debug msg="app state loaded"
Feb 17 08:11:49 volumio go-librespot[7810]: time="2026-02-17T08:11:49+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+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 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+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 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+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 17 08:11:50 volumio volumio[7404]: info: Updating MyVolumio device info
Feb 17 08:11:50 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:50 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:50 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+07:00" level=info msg="zeroconf server listening on port 40319"
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+07:00" level=debug msg="obtained new client token: AADpP5ParA+LzZFnEAN1/WyqtgrbGre6HGg43vALf/GAdNGj2mIfvMk+39KWG4O89NHyOxmadS17p9DzfmRnxnUGFq60go6r7oMzkNVpPEgaASj+7jdg/YrpRj0ZSLX/TsruybltG1Sntki/OjYyt6xplN9jy0taZsmKVgPX35BVKEMGTlnTeHF5FBTXZQEdyDx5lRgNpIbFgwIgm2iH4rnYNbrH0WbOO82seh66UgJPUlG2N1IVEncHdg=="
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+07:00" level=debug msg="completed challenge"
Feb 17 08:11:50 volumio go-librespot[7810]: time="2026-02-17T08:11:50+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 17 08:11:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:51 volumio volumio[7404]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 17 08:11:51 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:51 volumio volumio[7404]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:53 volumio volumio[7404]: info: MYVOLUMIO: Adding device
Feb 17 08:11:53 volumio volumio[7404]: info: MYVOLUMIO: Evaluating Server
Feb 17 08:11:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 17 08:11:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:53 volumio go-librespot[7832]: go-librespot daemon starting...
Feb 17 08:11:53 volumio go-librespot[7835]: time="2026-02-17T08:11:53+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:53 volumio go-librespot[7835]: time="2026-02-17T08:11:53+07:00" level=debug msg="app state loaded"
Feb 17 08:11:53 volumio go-librespot[7835]: time="2026-02-17T08:11:53+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:54 volumio volumio[7404]: info: Setting Geolocation for MyVolumio to as1
Feb 17 08:11:54 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:54 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:54 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+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 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+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 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+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 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=info msg="zeroconf server listening on port 41813"
Feb 17 08:11:54 volumio volumio[7404]: info: Initializing connection to go-librespot Websocket
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=debug msg="new websocket client"
Feb 17 08:11:54 volumio volumio[7404]: info: Connection to go-librespot Websocket established
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=debug msg="obtained new client token: AABOMZiooWSQ8B4y92h3l68S2vDZ9eF8pORicrhWHbO5vqt9nbppVy7Gmq4cH41oSDz786yvj6SR2s12QXEue62+OoYxU/G0n4vT4vGQa96ZWpVQN9wZXlJ/d7b9jfAakdKy/PoqF8wZtJiUVy4QZT2BRGLS2ciTuKpv4dPLqv+ct+rVmIpO0KdjLJHrcU3dGxvajU1tAt8xQwkbYoGRDFsIRKNPOgF0M2RxuYLGQnwH37ZoVRmquqrzQg=="
Feb 17 08:11:54 volumio volumio[7404]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=debug msg="completed challenge"
Feb 17 08:11:54 volumio go-librespot[7835]: time="2026-02-17T08:11:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 17 08:11:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 17 08:11:54 volumio volumio[7404]: info: Connection to go-librespot Websocket closed
Feb 17 08:11:55 volumio volumio[7404]: info: Updating MyVolumio device info
Feb 17 08:11:55 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:55 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:55 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:55 volumio volumio[7404]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 17 08:11:56 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 17 08:11:56 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 17 08:11:56 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 17 08:11:56 volumio volumio-remote-updater[25144]: Test mode disabled
Feb 17 08:11:56 volumio volumio-remote-updater[25144]: Alpha mode disabled
Feb 17 08:11:56 volumio volumio-remote-updater[25144]: Alpha legacy test mode disabled
Feb 17 08:11:56 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 17 08:11:56 volumio volumio[7404]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 17 08:11:57 volumio volumio[7404]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 17 08:11:57 volumio volumio[7404]: info: Getting Spotify volume
Feb 17 08:11:57 volumio volumio[7404]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:11:57 volumio volumio[7404]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 17 08:11:57 volumio volumio[7404]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 17 08:11:57 volumio volumio[7404]:   errno: -111,
Feb 17 08:11:57 volumio volumio[7404]:   code: 'ECONNREFUSED',
Feb 17 08:11:57 volumio volumio[7404]:   syscall: 'connect',
Feb 17 08:11:57 volumio volumio[7404]:   address: '127.0.0.1',
Feb 17 08:11:57 volumio volumio[7404]:   port: 9879,
Feb 17 08:11:57 volumio volumio[7404]:   response: undefined
Feb 17 08:11:57 volumio volumio[7404]: }
Feb 17 08:11:57 volumio volumio[7404]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 08:11:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 17 08:11:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 17 08:11:58 volumio go-librespot[7875]: go-librespot daemon starting...
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=info msg="running go-librespot 0.4.0"
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=debug msg="app state loaded"
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+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 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+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 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=info msg="zeroconf server listening on port 42825"
Feb 17 08:11:58 volumio go-librespot[7876]: time="2026-02-17T08:11:58+07:00" level=debug msg="obtained new client token: AACiAWk3qkQuOs74V85ZpMeD290w3pc5Ic12NLUifwWL7ylRCFcls8bwyT/MBV44binfA+RT1R2n52gqYkgDStigctnninzOjKL/fBWn6C70M3fMI+7LptH6WEd209KucBW8lHCV2QM/vjNfyZd9q3BS95pSLyGUS/bO2n214krYl/zt1sSgqhlkvEilboXX0FiizT6Jv4nkzw6yMOZmgrLBPx7LhhhETE49o6u6kSB32GeE/5u8IEreEA=="
Feb 17 08:11:59 volumio go-librespot[7876]: time="2026-02-17T08:11:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 17 08:11:59 volumio sudo[7886]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 08:10'
Feb 17 08:11:59 volumio sudo[7886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 08:11:59 volumio go-librespot[7876]: time="2026-02-17T08:11:59+07:00" level=debug msg="completed keyexchange"
Feb 17 08:11:59 volumio go-librespot[7876]: time="2026-02-17T08:11:59+07:00" level=debug msg="completed challenge"
Feb 17 08:11:59 volumio go-librespot[7876]: time="2026-02-17T08:11:59+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 17 08:11:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 17 08:11:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
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"