Aug 29 16:11:01 volumio volumio[1241]: info: [now-playing] ConfigUpdater: config is up to date. Aug 29 16:11:01 volumio volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 16:11:01 volumio volumio[1241]: info: [1788037861679] CoreMusicLibrary::Adding element Randomizer Aug 29 16:11:01 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 16:11:01 volumio volumio[1241]: Cannot find translation for source Bandcamp Discover Aug 29 16:11:01 volumio volumio[1241]: Cannot find translation for source Jellyfin Aug 29 16:11:01 volumio volumio[1241]: Cannot find translation for source Mixcloud Aug 29 16:11:01 volumio volumio[1241]: Cannot find translation for source Randomizer Aug 29 16:11:01 volumio volumio[1241]: info: Loading i18n strings for locale en Aug 29 16:11:01 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:11:01 volumio volumio[1241]: info: Volumio Calling Home Aug 29 16:11:02 volumio sudo[1744]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 29 16:11:02 volumio sudo[1744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:02 volumio sudo[1744]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:02 volumio sudo[1753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 29 16:11:02 volumio sudo[1753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:02 volumio sudo[1751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 29 16:11:02 volumio sudo[1754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 29 16:11:02 volumio sudo[1754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:02 volumio sudo[1751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:02 volumio sudo[1753]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:03 volumio systemd[1]: Reloading. Aug 29 16:11:03 volumio volumio[1241]: info: [now-playing] App is listening on port 4004. Aug 29 16:11:03 volumio volumio[1241]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Aug 29 16:11:03 volumio volumio[1241]: info: Upmpdcli Daemon Started Aug 29 16:11:04 volumio volumio[1241]: info: touch_display: Backlight interface detected. Aug 29 16:11:04 volumio volumio[1241]: info: touch_display: systemctl stop getty@tty1.service succeeded. Aug 29 16:11:04 volumio volumio[1241]: info: MPD Permissions set Aug 29 16:11:04 volumio volumio[1241]: info: MPD Permissions set Aug 29 16:11:05 volumio sudo[1778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Aug 29 16:11:05 volumio sudo[1778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:05 volumio sudo[1754]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:05 volumio systemd[1]: Reloading. Aug 29 16:11:05 volumio sudo[1778]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:06 volumio volumio[1241]: info: Volumio called home Aug 29 16:11:06 volumio volumio[1241]: info: Spotify config file written Aug 29 16:11:06 volumio mpd[1699]: 2026-08-29T16:11:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 16:11:06 volumio sudo[1801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 16:11:06 volumio sudo[1801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:07 volumio volumio5-onboarding[1682]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:36018->127.0.0.1:3000: i/o timeout Aug 29 16:11:07 volumio upmpdcli[1806]: writing RSA key Aug 29 16:11:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 16:11:07 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:07 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 16:11:07 volumio sudo[1677]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:07 volumio sudo[1751]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:07 volumio sudo[1662]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:07 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 16:11:07 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 16:11:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:07 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 16:11:07 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 16:11:07 volumio go-librespot[1818]: go-librespot daemon starting... Aug 29 16:11:07 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 16:11:07 volumio sudo[1801]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:07 volumio volumio5-onboarding[1820]: time=2026-08-29T16:11:07.806-05:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 16:11:07 volumio volumio[1241]: info: touch_display: systemctl daemon-reload succeeded. Aug 29 16:11:07 volumio volumio[1241]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 29 16:11:07 volumio sudo[1836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Aug 29 16:11:07 volumio sudo[1836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Aug 29 16:11:08 volumio volumio[1241]: info: No need to fix Spotify hosts Aug 29 16:11:08 volumio sudo[1836]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:11:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:08 volumio go-librespot[1821]: time="2026-08-29T16:11:08-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:08 volumio go-librespot[1821]: time="2026-08-29T16:11:08-05:00" level=debug msg="app state loaded" Aug 29 16:11:08 volumio startx[1874]: X.Org X Server 1.21.1.7 Aug 29 16:11:08 volumio startx[1874]: X Protocol Version 11, Revision 0 Aug 29 16:11:08 volumio startx[1874]: Current Operating System: Linux volumio 6.12.74-v7+ #1948 SMP Mon Mar 2 11:25:27 GMT 2026 armv7l Aug 29 16:11:08 volumio startx[1874]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_hdmi=0 snd_bcm2835.enable_hdmi=0 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=9caf6474-168f-4972-add4-ace36a467bc2 imgfile=/volumio_current.sqsh bootpart=UUID=807D-2966 datapart=UUID=bea3e05c-62cf-4b22-a58d-66213927f56a uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Aug 29 16:11:08 volumio startx[1874]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Aug 29 16:11:08 volumio startx[1874]: Current version of pixman: 0.44.0 Aug 29 16:11:08 volumio startx[1874]: Before reporting problems, check http://wiki.x.org Aug 29 16:11:08 volumio startx[1874]: to make sure that you have the latest version. Aug 29 16:11:08 volumio startx[1874]: Markers: (--) probed, (**) from config file, (==) default setting, Aug 29 16:11:08 volumio startx[1874]: (++) from command line, (!!) notice, (II) informational, Aug 29 16:11:08 volumio startx[1874]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Aug 29 16:11:08 volumio startx[1874]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Aug 29 16:11:08 2026 Aug 29 16:11:08 volumio startx[1874]: (==) Using config directory: "/etc/X11/xorg.conf.d" Aug 29 16:11:08 volumio startx[1874]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Aug 29 16:11:08 volumio go-librespot[1821]: time="2026-08-29T16:11:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:09 volumio volumio[1241]: info: touch_display: systemctl disable getty@tty1.service succeeded. Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=info msg="zeroconf server listening on port 37969" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="obtained new client token: AAHKf4nW37sbIYWwou3h9PGWOsDuZ/nVZTDV1lmRC2gDzml/DAJjtNgeoJDsJyrruqoZ1zjocPXpsE2U5gkP9sSSRAoXWjIIZ3C3FXVJcPlhoHa7dgrlxZnCIik0tci9wQXd83BFJ1+VvGe5niXWzOmycn9/qN2FBRt/h5KlUsNpbcKpJg5Br5PkQ75g+BkSaYYQTdM+5RcBOUTlp20OjLYNdqw96zkbWyNSiHl1uCXedZMU9EAOI2F7iA==" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=debug msg="completed challenge" Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:09 volumio volumio[1241]: info: New Spotify access tokenBQB1s72gbt... Aug 29 16:11:09 volumio go-librespot[1821]: time="2026-08-29T16:11:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:10 volumio volumio[1241]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 16:11:10 volumio volumio[1241]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Aug 29 16:11:10 volumio volumio[1241]: info: touch_display: Volumio Kiosk started. Aug 29 16:11:10 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:10 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:10 volumio volumio[1241]: info: Completed starting Core Plugins Aug 29 16:11:10 volumio volumio[1241]: info: ------------------------------------------- Aug 29 16:11:10 volumio volumio[1241]: info: ----- MyVolumio plugins startup ---- Aug 29 16:11:10 volumio volumio[1241]: info: ------------------------------------------- Aug 29 16:11:10 volumio volumio[1241]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 16:11:10 volumio sudo[1907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Aug 29 16:11:10 volumio sudo[1907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:10 volumio volumio[1241]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Aug 29 16:11:10 volumio sudo[1907]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:10 volumio sudo[1911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 29 16:11:10 volumio sudo[1911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:10 volumio sudo[1911]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:10 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:10 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:11 volumio sudo[1914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Aug 29 16:11:11 volumio sudo[1914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:11 volumio sudo[1914]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:11 volumio volumio[1241]: info: [jellyfin-poller] Polled http://192.168.8.118:8096: online Aug 29 16:11:11 volumio volumio[1241]: error: MPD error: The expression evaluated to a falsy value: Aug 29 16:11:11 volumio volumio[1241]: assert.ok(self.idling) Aug 29 16:11:11 volumio volumio[1241]: error: The expression evaluated to a falsy value: Aug 29 16:11:11 volumio volumio[1241]: assert.ok(self.idling) Aug 29 16:11:11 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 29 16:11:11 volumio volumio[1241]: info: touch_display: X display number found: 0 Aug 29 16:11:12 volumio volumio[1241]: info: MPD running with PID1699 Aug 29 16:11:12 volumio volumio[1241]: ,establishing connection Aug 29 16:11:12 volumio volumio[1241]: info: Starting Shairport Sync Aug 29 16:11:12 volumio volumio[1241]: info: Starting Shairport Sync Aug 29 16:11:12 volumio volumio-remote-updater[775]: [2026-08-29 16:11:12] [connect] Successful connection Aug 29 16:11:12 volumio volumio[1241]: info: Starting Shairport Sync Aug 29 16:11:12 volumio sudo[1943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 16:11:12 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:12 volumio volumio[1241]: error: updateQueue error: null Aug 29 16:11:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 16:11:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 16:11:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio systemd[1]: shairport-sync.service: Consumed 1.556s CPU time. Aug 29 16:11:12 volumio sudo[1945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 16:11:12 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 16:11:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 16:11:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio sudo[1958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 16:11:12 volumio sudo[1958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:12 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:12 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 29 16:11:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 16:11:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 16:11:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 16:11:12 volumio sudo[1958]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 16:11:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:13 volumio go-librespot[1993]: go-librespot daemon starting... Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=debug msg="app state loaded" Aug 29 16:11:13 volumio volumio[1241]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:13 volumio volumio[1241]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 29 16:11:13 volumio volumio[1241]: info: touch_display: File permissions for backlight brightness control set. Aug 29 16:11:13 volumio volumio[1241]: info: go-librespot daemon successfully initialized Aug 29 16:11:13 volumio volumio[1241]: info: Listing playlists Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=info msg="zeroconf server listening on port 42373" Aug 29 16:11:13 volumio go-librespot[1994]: time="2026-08-29T16:11:13-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:14 volumio volumio[1241]: info: Listing playlists Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=debug msg="obtained new client token: AAH0Ja/b1qGIIzPP6KHfWXcfKBf3lRiQFd17BD//xDw43H9VzH5G7ssFH8vlAxtFxTVo0g+3t1v5h/lP/JU+IF06qkr6dsu+mMiur7tdRUZk7wseuBa2gGZJH0mT4RqbGU4W7julI6LAttQzzJ/RLijtfaynDKncDwdLlgZgUxPsNHni1ZpDZ61dvqFQk1ZAAWmPw4RjouwizYWt01EnpepIVC4OiLWFecKHuMLaFc0l+mFI3GYL" Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=debug msg="completed challenge" Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:14 volumio go-librespot[1994]: time="2026-08-29T16:11:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:14 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 29 16:11:14 volumio volumio[1241]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Aug 29 16:11:14 volumio volumio[1241]: info: Shairport-Sync Started Aug 29 16:11:14 volumio volumio[1241]: Error adding Membership: Error: addMembership EINVAL Aug 29 16:11:14 volumio volumio[1241]: info: Shairport-Sync Started Aug 29 16:11:14 volumio volumio[1241]: info: Shairport-Sync Started Aug 29 16:11:15 volumio volumio[1241]: error: updateQueue error: null Aug 29 16:11:15 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 29 16:11:15 volumio volumio[1241]: info: Received Get System Info Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:11:15 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:15 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:11:15 volumio volumio5-onboarding[1820]: time=2026-08-29T16:11:15.204-05:00 level=INFO msg="system info for 881cc1f8dbdae5876eb0a58926007e09" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 16:11:15 volumio volumio5-onboarding[1820]: time=2026-08-29T16:11:15.220-05:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 16:11:15 volumio volumio[1241]: info: touch_display: X display number found: 0 Aug 29 16:11:15 volumio volumio[1241]: info: Received Get System Info Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:11:15 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:15 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:15 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:11:15 volumio volumio-remote-updater[775]: [2026-08-29 16:11:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788037872 101 Aug 29 16:11:15 volumio volumio[1241]: 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: 5 Aug 29 16:11:16 volumio volumio[1241]: info: touch_display: Setting screensaver timeout to 120 seconds. Aug 29 16:11:16 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:11:16 volumio volumio[1241]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 16:11:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 16:11:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:17 volumio go-librespot[2043]: go-librespot daemon starting... Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=debug msg="app state loaded" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:17 volumio go-librespot[2044]: time="2026-08-29T16:11:17-05:00" level=info msg="zeroconf server listening on port 39425" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=debug msg="obtained new client token: AAHdobtDmXD4x+/mASnjq/9sDFkm2fWC3oOMiXhgYQ14j/3TRaByAuffFuBRxt4qQJAXSUfDPpe9R5MOb32HxlSJq6GtJ0sChfVpB0ZwBqEG0C4Jk0nEASKCZLp9s7IGY2FN+o1N6fBKkI7rCF0eqrv8PoBi+yx0mvSc/vzAPEoqpC/pXCKBvYPbXR4kw4/K3inrn2y5R0mBSosBkZawgACM3eG9TsHwJnRpB+4hZwIdIH/waefHn9M=" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=debug msg="completed challenge" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:18 volumio go-librespot[2044]: time="2026-08-29T16:11:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:19 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:11:20 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 29 16:11:20 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:20 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 16:11:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:21 volumio go-librespot[2093]: go-librespot daemon starting... Aug 29 16:11:21 volumio go-librespot[2099]: time="2026-08-29T16:11:21-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:21 volumio go-librespot[2099]: time="2026-08-29T16:11:21-05:00" level=debug msg="app state loaded" Aug 29 16:11:22 volumio go-librespot[2099]: time="2026-08-29T16:11:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=info msg="zeroconf server listening on port 44277" Aug 29 16:11:23 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="obtained new client token: AAGgp3H1T+zlv4GAxWlHwd7VKAA/N8EqGbzq2aY+44KW9fsoJGFEIymoKiKWjmD732WLe4Vt0CKUYIn0cWqLKGVAPM/E5m6l3fWqA4iGPrK5AQaMbReNFU5tUanAv50Pmok9+hLWmPJht0hShB6ye4K/yAVvqIbq1XWOiFubonu9zBTusbGB6uI+Pe/Fkttu2EBtfusqGsw6ptG8UqjVU0DEHTUTMpA2rJZCP6aZ0pfXNe7uTilzkgiStg==" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=debug msg="completed challenge" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:23 volumio go-librespot[2099]: time="2026-08-29T16:11:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 16:11:24 volumio volumio[1241]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 16:11:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 16:11:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:27 volumio go-librespot[2137]: go-librespot daemon starting... Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=debug msg="app state loaded" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=info msg="zeroconf server listening on port 37241" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:27 volumio go-librespot[2143]: time="2026-08-29T16:11:27-05:00" level=debug msg="obtained new client token: AAG3d5GNss1NYWb58OjR62dHnYwun3zWhtyrWb2C0d1kAEkvfwG0xuDebAndNYkRhXZ7EJWLrbx7tdqEyR7O2/9wkU73Xp4suC4uSTtsbmIQLRImE+Mo+eRQc2GmpXaeduS0vWp692xiATTOAp4Ny6aUGY6OZtGrh3zOTAUcArYOVaOkkwIVlV2/fDvPXfZYyNKcE7tNKxQDKEYjrOGkhhRly+/3owf4P8WDgUyRSqA4o7q0pilNc9gP2Q==" Aug 29 16:11:28 volumio go-librespot[2143]: time="2026-08-29T16:11:28-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:28 volumio go-librespot[2143]: time="2026-08-29T16:11:28-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:28 volumio go-librespot[2143]: time="2026-08-29T16:11:28-05:00" level=debug msg="completed challenge" Aug 29 16:11:28 volumio go-librespot[2143]: time="2026-08-29T16:11:28-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:28 volumio go-librespot[2143]: time="2026-08-29T16:11:28-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 16:11:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:31 volumio go-librespot[2202]: go-librespot daemon starting... Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=debug msg="app state loaded" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=info msg="zeroconf server listening on port 33157" Aug 29 16:11:31 volumio go-librespot[2203]: time="2026-08-29T16:11:31-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=debug msg="obtained new client token: AAHJIRdUaloA6l9GuvJmYEgUj0C1BPAvDg3W0C1gssWLZUeXlUmfR7xFectUt2De47jGWE7jFAtReiZLkaZoN6KSDz9kbIhzhLUkySvYSndI14suHkvY1qXthwvKWW6PZwcUvfDs19Wgiu/LZ09wPi24NGen9nf23XADCNCt6BO9eD1tGDRUzRGOX6bTo/BqJzH8IvNoKc7g2wx9sipu3bXRgDbEOun7tLSlCiQ0hPDv/sWh4VfdDaY=" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=debug msg="completed challenge" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:32 volumio go-librespot[2203]: time="2026-08-29T16:11:32-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 16:11:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:35 volumio go-librespot[2212]: go-librespot daemon starting... Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=debug msg="app state loaded" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:36 volumio volumio[1241]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 16:11:36 volumio volumio[1241]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 16:11:36 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:11:36 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:11:36 volumio volumio[1241]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 16:11:36 volumio volumio[1241]: info: MyVolumio login type: Token Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=info msg="zeroconf server listening on port 35919" Aug 29 16:11:36 volumio go-librespot[2213]: time="2026-08-29T16:11:36-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:37 volumio volumio[1241]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=debug msg="obtained new client token: AAGal/0pm8nk2lLSHV3qjbU20ohFO1dL2p5TfSXolVu9ffYPxXfVi12WBFvTKuoJLcgvKSk1cjwkME+V3Dy+79Dm7tfI3nXO4tFy8VkshVDs/370qBjWn2thwSxJiAcYRA/bKbF32k5FN/yUyLavJjBMiXxbJqOc7mN4MSJvRWnb0hxGBiM4rliG9LqG15RHRhS0uwTSug9fVaCuROqfca28CY1Kl/38q628Z/Zr4dZ98cww+MYVY/8=" Aug 29 16:11:37 volumio volumio[1241]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=debug msg="completed challenge" Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:37 volumio go-librespot[2213]: time="2026-08-29T16:11:37-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 16:11:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:40 volumio go-librespot[2238]: go-librespot daemon starting... Aug 29 16:11:40 volumio go-librespot[2239]: time="2026-08-29T16:11:40-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:40 volumio go-librespot[2239]: time="2026-08-29T16:11:40-05:00" level=debug msg="app state loaded" Aug 29 16:11:40 volumio go-librespot[2239]: time="2026-08-29T16:11:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=info msg="zeroconf server listening on port 32931" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="obtained new client token: AAFoswZLmnIasI6ZN8C5Neib5f/wO1M/XQZ1Y9BQ8tKFPPMHWT91n6tL7DQd2T2GAQ0X8oBRvVPvC6AEu3f8AXuJXW7zkuaqdClYO+O+p2bcNTJnms7+rGWbrhtKXyABCQVlDVYGB5+U26//zug5IdyIpBWBL3Pbft/4OeHN02fuK+y6IH1d/1NymzHU3/vobAR5DH6k7u5INOSNg3HMbJjc4k9fSQVWv9XYQ3RaQhXs4srLldq8OXY=" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=debug msg="completed challenge" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:41 volumio go-librespot[2239]: time="2026-08-29T16:11:41-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:43 volumio volumio[1241]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 16:11:43 volumio volumio[1241]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 16:11:43 volumio volumio[1241]: info: Streaming services startup Aug 29 16:11:43 volumio volumio[1241]: info: Starting Streaming Daemon Aug 29 16:11:43 volumio volumio[1241]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 16:11:44 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:11:44 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:11:44 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 16:11:44 volumio sudo[2249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 16:11:44 volumio sudo[2249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:11:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 16:11:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:44 volumio go-librespot[2258]: go-librespot daemon starting... Aug 29 16:11:44 volumio sudo[2249]: pam_unix(sudo:session): session closed for user root Aug 29 16:11:44 volumio go-librespot[2259]: time="2026-08-29T16:11:44-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:44 volumio go-librespot[2259]: time="2026-08-29T16:11:44-05:00" level=debug msg="app state loaded" Aug 29 16:11:44 volumio go-librespot[2259]: time="2026-08-29T16:11:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:45 volumio volumio5-onboarding[1820]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=info msg="zeroconf server listening on port 44613" Aug 29 16:11:45 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:45 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="obtained new client token: AAF5TbZ4q+q6uMDwwyxPm694w8LFLDGbd4HG4+W1cTvtq/WUhxw489WlxzTcMMY6XhdT9VGRGJ+LwZIm2kWDN+LSHGbBts/sLBhFqQH14cPw528JknMUhXPa4hpNNtY64jKCuhK81ci4unedyPIb/Qa7iGw5wUhmpgYxP4bdZJYfBfTa4IdV+9JAdfL8nebFmkPvdwgZjvTA3/3an7+pr7nh/kVKzwhSuCVfdMYhqOPS7eTF8d5ngoJUVA==" Aug 29 16:11:45 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Aug 29 16:11:45 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:45 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=debug msg="completed challenge" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:45 volumio go-librespot[2259]: time="2026-08-29T16:11:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:45 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:45.814-05:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 16:11:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 29 16:11:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:49 volumio go-librespot[2276]: go-librespot daemon starting... Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="app state loaded" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:49 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 29 16:11:49 volumio volumio[1241]: error: Cannot start Volumio Streaming Daemon Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=info msg="zeroconf server listening on port 39703" Aug 29 16:11:49 volumio volumio[1241]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 16:11:49 volumio volumio[1241]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:49 volumio volumio[1241]: SPOTIFY: User informations: {"account_id":"Yy3MimSrmf","country":"US","display_name":"mrsbunnysworth","email":"mrsbunnysworth@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/mrsbunnysworth"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/mrsbunnysworth","id":"mrsbunnysworth","images":[],"product":"free","type":"user","uri":"spotify:user:mrsbunnysworth"} Aug 29 16:11:49 volumio volumio[1241]: info: Spotify Successfully logged in Aug 29 16:11:49 volumio volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 16:11:49 volumio volumio[1241]: info: [1788037909711] CoreMusicLibrary::Adding element Spotify Aug 29 16:11:49 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 16:11:49 volumio volumio[1241]: Cannot find translation for source Bandcamp Discover Aug 29 16:11:49 volumio volumio[1241]: Cannot find translation for source Jellyfin Aug 29 16:11:49 volumio volumio[1241]: Cannot find translation for source Mixcloud Aug 29 16:11:49 volumio volumio[1241]: Cannot find translation for source Randomizer Aug 29 16:11:49 volumio volumio[1241]: Cannot find translation for source Spotify Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="obtained new client token: AAHb4fHaC/oAZ8FEmgCUMG7imGjMvHTDqecXdxQMmuQGbPNhLShPCC6txRIitqlvv998W3+FTn+FaUt9hp425n1PxArJhaMkN+6G3zrxkxaD5v1GqjeHN+XnqrN+aUaZzGld7hKIJOvCSF1dNFNcm+yrf4yfsJGVIn+AUl1kS/9cPl0HA9wc15MOQYy1g8MraXxycBQwJxEZYDSoI/BENFvZNxKJ3GmRrmG3Ebdm9r+ZH8QWslUs8tGFcQ==" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=debug msg="completed challenge" Aug 29 16:11:49 volumio go-librespot[2277]: time="2026-08-29T16:11:49-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:50 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:50 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:50 volumio go-librespot[2277]: time="2026-08-29T16:11:50-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:50 volumio volumio[1241]: info: Listing playlists Aug 29 16:11:50 volumio volumio[1241]: info: Listing playlists Aug 29 16:11:51 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Aug 29 16:11:51 volumio volumio[1241]: error: MyVolumio Custom Token format not valid, refreshing it Aug 29 16:11:51 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Aug 29 16:11:51 volumio volumio[1241]: info: Received Get System Info Aug 29 16:11:51 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:11:51 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:11:51 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:11:51 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:51 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:51 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:11:51 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:51.857-05:00 level=INFO msg="system info for 881cc1f8dbdae5876eb0a58926007e09" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 16:11:51 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:51.876-05:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 16:11:51 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 16:11:52 volumio volumio-remote-updater[775]: Test mode disabled Aug 29 16:11:52 volumio volumio-remote-updater[775]: Alpha mode disabled Aug 29 16:11:52 volumio volumio-remote-updater[775]: Alpha legacy test mode disabled Aug 29 16:11:52 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 29 16:11:52 volumio volumio[1241]: info: Received Get System Info Aug 29 16:11:52 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:11:52 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:11:52 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:11:52 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:52 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:52 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:11:52 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:11:52 volumio volumio-remote-updater[775]: Test mode disabled Aug 29 16:11:52 volumio volumio-remote-updater[775]: Alpha mode disabled Aug 29 16:11:52 volumio volumio-remote-updater[775]: Alpha legacy test mode disabled Aug 29 16:11:53 volumio volumio[1241]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:53 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 29 16:11:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:53 volumio go-librespot[2305]: go-librespot daemon starting... Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="app state loaded" Aug 29 16:11:53 volumio volumio[1241]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 16:11:53 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:11:53 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:53.401-05:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 29 16:11:53 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:53.433-05:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 29 16:11:53 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:53.434-05:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=info msg="zeroconf server listening on port 34993" Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:53 volumio volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 29 16:11:53 volumio volumio[1241]: info: Received Get System Info Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:11:53 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:53 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:53 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="obtained new client token: AAF+eW+9RJjszWPDaXlpiqUw1b3gbmwPgrf+X9VlUeA4kETYZhSHmoSm28p3oaZAxBmivL740qPM0TbL6OHfN6hUcLtX1Lv2tSZgZvb5jkni0JX6xfNmnKIrpLPY99NDVBv/jDzdtwd3OkV3E2EVnzeBxtd0A1TQTDfKLzqeBqJXGXgWyjNykrGaPWAY+3CV9QzK/oBBD3SI6/t0NQbPp6kPFGbptvy959x0+keZ9pDCOJBxsYe0rOTGHQ==" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=debug msg="completed challenge" Aug 29 16:11:53 volumio go-librespot[2306]: time="2026-08-29T16:11:53-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:54 volumio go-librespot[2306]: time="2026-08-29T16:11:54-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:54 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 16:11:54 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 16:11:54 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:54.435-05:00 level=INFO msg="enabling local network discovery" Aug 29 16:11:54 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:54.463-05:00 level=INFO msg="enabling BLE discovery" Aug 29 16:11:55 volumio volumio5-onboarding[2268]: time=2026-08-29T16:11:55.552-05:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 16:11:55 volumio volumio[1241]: info: MyVolumio login type: Token Aug 29 16:11:55 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:11:55 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:11:56 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 16:11:56 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:11:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 29 16:11:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:11:57 volumio go-librespot[2320]: go-librespot daemon starting... Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="app state loaded" Aug 29 16:11:57 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=info msg="zeroconf server listening on port 43771" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="obtained new client token: AAEDlmtYmW6tYs31LbP6ER8DE2xhd3cntF3hIu2U7fJzGr+LLO9NhTrTXf3gfk/k1VJ6EiZ+kvV7y0KeokGolIOHd0B4Mol/KWVLmufMXGmsAoMFZQmYOi+265d3G5Yx+SW3v+NYpiJYtyzHFgRRnlxafdPMV7jHmvJ14LSggNrmbzk31Ng1eKMYBT2QqbpD6IJQx1BFlvlKg8Fl+4+GEjy8yq5YOmAjgu4gwCwpR7KJNfE6McRQOgAOsQ==" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="completed keyexchange" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=debug msg="completed challenge" Aug 29 16:11:57 volumio go-librespot[2321]: time="2026-08-29T16:11:57-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:11:58 volumio go-librespot[2321]: time="2026-08-29T16:11:58-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:11:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:11:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:11:58 volumio volumio[1241]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 16:11:58 volumio volumio[1241]: info: MyVolumio token set successfully Aug 29 16:11:58 volumio volumio[1241]: info: MYVOLUMIO: Adding device Aug 29 16:11:58 volumio volumio[1241]: info: MYVOLUMIO: Evaluating Server Aug 29 16:12:00 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:12:00 volumio volumio[1241]: info: MyVolumio status changed Aug 29 16:12:00 volumio volumio[1241]: info: Streaming services startup Aug 29 16:12:00 volumio volumio[1241]: info: Starting Streaming Daemon Aug 29 16:12:00 volumio volumio[1241]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 16:12:00 volumio volumio[1241]: info: Removing audio output: Aug 29 16:12:00 volumio sudo[2365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 16:12:00 volumio sudo[2365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:12:00 volumio volumio[1241]: info: Stoppping Tunnel 1 Aug 29 16:12:01 volumio sudo[2365]: pam_unix(sudo:session): session closed for user root Aug 29 16:12:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 29 16:12:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:01 volumio sudo[2368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 16:12:01 volumio sudo[2368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:12:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:01 volumio go-librespot[2370]: go-librespot daemon starting... Aug 29 16:12:01 volumio volumio[1241]: info: Setting Geolocation for MyVolumio to us4 Aug 29 16:12:01 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:01 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:01 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=debug msg="app state loaded" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 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. Aug 29 16:12:01 volumio volumio[1241]: error: Cannot start Volumio Streaming Daemon Aug 29 16:12:01 volumio sudo[2368]: pam_unix(sudo:session): session closed for user root Aug 29 16:12:01 volumio volumio[1241]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 16:12:01 volumio volumio[1241]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 16:12:01 volumio volumio[1241]: info: Remote SSH Stopped Aug 29 16:12:01 volumio volumio[1241]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=info msg="zeroconf server listening on port 46551" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:01 volumio go-librespot[2371]: time="2026-08-29T16:12:01-05:00" level=debug msg="obtained new client token: AAE0GIYz2DR/10gtlyPu48s7k3FBVIF0hY8b5aBe5Nj6naI6hA5+Hc3ZcEkktIfZ4w7Z2FajkeID/V8quh7ap/CGPzJpapkh6rA2Q3AhWRABKKMKrHLlfCaGNtn3FC6NX6px8FpYebT8cCrrwwVppvCYVuPTrigJQq+t/OyaNsnIZz7DX6vm4iGX1nduaxkWux0JBKDKE9lf/hLqYzfg/2ospBPhMGDiRVRjn1ZFNSDxaBMkEmJX8lxh8Q==" Aug 29 16:12:02 volumio go-librespot[2371]: time="2026-08-29T16:12:02-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:02 volumio go-librespot[2371]: time="2026-08-29T16:12:02-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:02 volumio go-librespot[2371]: time="2026-08-29T16:12:02-05:00" level=debug msg="completed challenge" Aug 29 16:12:02 volumio go-librespot[2371]: time="2026-08-29T16:12:02-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:02 volumio volumio[1241]: info: Updating MyVolumio device info Aug 29 16:12:02 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:02 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:02 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:02 volumio go-librespot[2371]: time="2026-08-29T16:12:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:02 volumio volumio[1241]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 29 16:12:02 volumio volumio[1241]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 29 16:12:02 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:12:02 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:12:03 volumio volumio[1241]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 29 16:12:03 volumio volumio[1241]: info: Completed starting MyVolumio Plugin Aug 29 16:12:03 volumio volumio[1241]: [Metrics] CommandRouter: 111s 963.86ms Aug 29 16:12:03 volumio volumio[1241]: info: CoreCommandRouter::volumiosetStartupVolume Aug 29 16:12:03 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:12:03 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:03 volumio volumio[1241]: info: CoreCommandRouter::Close All Modals sent Aug 29 16:12:03 volumio volumio[1241]: info: CoreCommandRouter::Close All Modals sent Aug 29 16:12:04 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:12:04 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:12:04 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 29 16:12:04 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 16:12:04 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 29 16:12:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 29 16:12:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:05 volumio go-librespot[2384]: go-librespot daemon starting... Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=debug msg="app state loaded" Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:05 volumio volumio[1241]: info: MYVOLUMIO: Adding device Aug 29 16:12:05 volumio volumio[1241]: info: MYVOLUMIO: Evaluating Server Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:05 volumio go-librespot[2385]: time="2026-08-29T16:12:05-05:00" level=info msg="zeroconf server listening on port 46121" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=debug msg="obtained new client token: AAGlQf0SxAg23nRkDnr5GxQqPZ7t3tR3Uf5gN/7NFZ183dVGMbpjL0XIW1db1TDyZZXd6GlbnNHf2lKxKYs/B8y7esM8G1e+vo8VboQFAY/OHCbOgSFVVzMbtnsLJqSA486IH1pzCFOFx+tKyjiMjAKRgcFniM/EB9i5jF8AQMrZpezY2orTuXKLKqf9NEHvjbk4gxDZ5caLZ9PIbE88SkjoctRvOMfeidnGgUaFR1E5bTINNOEqDqM=" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=debug msg="completed challenge" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:06 volumio go-librespot[2385]: time="2026-08-29T16:12:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:07 volumio volumio[1241]: info: Setting Geolocation for MyVolumio to us1 Aug 29 16:12:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:07 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:07 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:12:07 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:12:08 volumio volumio[1241]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 29 16:12:08 volumio volumio[1241]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 29 16:12:08 volumio volumio[1241]: info: Updating MyVolumio device info Aug 29 16:12:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:08 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:12:09 volumio volumio[1241]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 29 16:12:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 29 16:12:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:09 volumio go-librespot[2422]: go-librespot daemon starting... Aug 29 16:12:09 volumio go-librespot[2423]: time="2026-08-29T16:12:09-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:09 volumio go-librespot[2423]: time="2026-08-29T16:12:09-05:00" level=debug msg="app state loaded" Aug 29 16:12:09 volumio go-librespot[2423]: time="2026-08-29T16:12:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=info msg="zeroconf server listening on port 42541" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="obtained new client token: AAHoeEp9Coi9a2zxChY8bXopCYZ9W8D16NvYMdW7QHXjASafgpiWLl+omy+5BLtNZTA/IzGkTfETzoU+9z5n/EP9q727x7qAQW+71V/BQwf9+WP2FHMqFZ9+dh4xz7OSycHs86w97Q08+qvgX0XABz7cDpSzPwZrc9gJsF+oZWMAZgHoNYzip7wuwlPgzSJdxH2+F7amUqc/qbH30GhF/yK7ReyZhPIuk9q2xRkifTObtNJicaGbmp19vA==" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=debug msg="completed challenge" Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:10 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:12:10 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:12:10 volumio go-librespot[2423]: time="2026-08-29T16:12:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:10 volumio volumio[1241]: info: BOOT COMPLETED Aug 29 16:12:11 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 16:12:11 volumio volumio[1241]: info: Listing playlists Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 16:12:11 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 16:12:11 volumio volumio[1241]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:12:12 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:12:12 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:12:12 volumio volumio[1241]: info: Listing playlists Aug 29 16:12:12 volumio volumio[1241]: info: Listing playlists Aug 29 16:12:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 29 16:12:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:14 volumio go-librespot[2448]: go-librespot daemon starting... Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="app state loaded" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:14 volumio volumio[1241]: info: Initializing connection to go-librespot Websocket Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="new websocket client" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=info msg="zeroconf server listening on port 41929" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:14 volumio volumio[1241]: info: Connection to go-librespot Websocket established Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="obtained new client token: AAEOuNzolEIIQcrlckcJHyC0wrC3lUDXSLEaxsf2N45L3s0hKAPiRvO1Fu3ZLqOMuoAn3zFN7lXtrAmsp/Ty9N+cXd0xkt+iPjnP3qzQKLgYWiHKBUomBZq0DT5pjZ1VuLfhs5pK9JKTOTaCwL6v3Xm435TyhV+pFCTuvwDtC4RCxg9LjeOwL5MR6qLWro9Wck0QlJ/L5oc7FMAg+1z/sZcmTcwK2rgQcfZtEJ9BwqR5h0HI2V4w6Bihcw==" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:14 volumio go-librespot[2449]: time="2026-08-29T16:12:14-05:00" level=debug msg="completed challenge" Aug 29 16:12:15 volumio go-librespot[2449]: time="2026-08-29T16:12:15-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:15 volumio go-librespot[2449]: time="2026-08-29T16:12:15-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:15 volumio volumio[1241]: info: Connection to go-librespot Websocket closed Aug 29 16:12:16 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 16:12:16 volumio volumio[1241]: info: Received Get System Info Aug 29 16:12:16 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:12:16 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:12:16 volumio volumio[1241]: info: Discovery: Getting this device information Aug 29 16:12:16 volumio volumio[1241]: info: CoreCommandRouter::volumioGetState Aug 29 16:12:16 volumio volumio[1241]: info: CorePlayQueue::getTrack 0 Aug 29 16:12:16 volumio volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:12:17 volumio volumio[1241]: info: Getting Spotify volume Aug 29 16:12:17 volumio volumio[1241]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 16:12:18 volumio volumio[1241]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 16:12:18 volumio volumio[1241]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 16:12:18 volumio volumio[1241]: errno: -111, Aug 29 16:12:18 volumio volumio[1241]: code: 'ECONNREFUSED', Aug 29 16:12:18 volumio volumio[1241]: syscall: 'connect', Aug 29 16:12:18 volumio volumio[1241]: address: '127.0.0.1', Aug 29 16:12:18 volumio volumio[1241]: port: 9879, Aug 29 16:12:18 volumio volumio[1241]: response: undefined Aug 29 16:12:18 volumio volumio[1241]: } Aug 29 16:12:18 volumio volumio[1241]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 16:12:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 29 16:12:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:18 volumio go-librespot[2461]: go-librespot daemon starting... Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="app state loaded" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=info msg="zeroconf server listening on port 46415" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="obtained new client token: AAF++jehsMQbd01hDiy54XYcV/pJSQCCO5aqwBc0VUAVpU+2oA4ZHcnYwIOk8LvQLRbmPemHLk4hOOCeS6SwJMmXGxKIkH2nnxtMR3adow5r94fD1Dj88AF3kWhp4IQf7QuGlfpoxM57Gi+ow0HEWTP/+yN7jmnESFTrKIy7bWaPq4lnqsF3dxotW7dSG1dRKfSnLfh5vuGtI6WP4ION7dqr9DnqpYeWrupMyZAobVVKD8n5ACI8SsMeVA==" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:18 volumio go-librespot[2462]: time="2026-08-29T16:12:18-05:00" level=debug msg="completed challenge" Aug 29 16:12:19 volumio go-librespot[2462]: time="2026-08-29T16:12:19-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:19 volumio go-librespot[2462]: time="2026-08-29T16:12:19-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 29 16:12:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:22 volumio go-librespot[2492]: go-librespot daemon starting... Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=debug msg="app state loaded" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=info msg="zeroconf server listening on port 34935" Aug 29 16:12:22 volumio go-librespot[2493]: time="2026-08-29T16:12:22-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=debug msg="obtained new client token: AAHWXg1JROr+BnIC8msC4y0cim6554YF16JviIk5cQi3BOjpBFzt46OQKPTckEuHj0Wbj08worlxWna8m6VtngvBcUY1Q+dEUaWoZVeYMI7izQlLLibENtGrAkDS2KA693qKe7C6Vk3P0obowRBpSj23GzdNRL+3gb/QVdoupzke7eDtLNi0z1Gt8ePqAEhW6aiVmk5bjxOSlNID7VofKkf3Tn8Lzk2eetHsRlwKgvReP8heuzq8obw=" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=debug msg="completed challenge" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:23 volumio go-librespot[2493]: time="2026-08-29T16:12:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 29 16:12:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:26 volumio go-librespot[2505]: go-librespot daemon starting... Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="app state loaded" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=info msg="zeroconf server listening on port 36203" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="obtained new client token: AAF/kTcP97Yt0S2O19rkfnd477oTaNuaLtMUOKphuqAQwC6euwrzwmkxUjEc2loKGMaUMdSOaYINPcnmi/HF5QLhqrHX0S53g8bg6ZhxVrdmpaHWg5w6krMp0LJRgPp90Byw1LlyyIUa9dLQDoqhGNxUgF8harGKuu06ivYNLYV27mz34fZ14HQMOBXxOxykkIn7oEPyLt49NaMHAecbdAQhXzvLYQI1NFTBz1o2qdtej6VJP55sHetP7w==" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=debug msg="completed challenge" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:27 volumio go-librespot[2506]: time="2026-08-29T16:12:27-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 29 16:12:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:31 volumio go-librespot[2522]: go-librespot daemon starting... Aug 29 16:12:31 volumio go-librespot[2523]: time="2026-08-29T16:12:31-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:31 volumio go-librespot[2523]: time="2026-08-29T16:12:31-05:00" level=debug msg="app state loaded" Aug 29 16:12:31 volumio go-librespot[2523]: time="2026-08-29T16:12:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=info msg="zeroconf server listening on port 38921" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="obtained new client token: AAHoNvtfFnOWAapugPp3GRudROMI/a+ZRomhO6ZNgmn09DOdgnwyFqgmPKzDh2LkAzCY/aK1SorelmZhTjpqmS8qHA+/DfxfGg/PbEMaD4ylvuLQoWCnyYeqU+eTerx7W3VjaOTGvVbp+d/jamudYekBTbA0xIBV/HhRtKcc6bpNukI1AQTSLGDHAH17JwHI4DqfvjUavK866sb/VcZgSymG6dATz4RgSKb3ii+uAUCK7pAcg1UbdzERcQ==" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=debug msg="completed challenge" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:32 volumio go-librespot[2523]: time="2026-08-29T16:12:32-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 16:12:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 29 16:12:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 16:12:36 volumio go-librespot[2557]: go-librespot daemon starting... Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=info msg="running go-librespot 0.7.1" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="app state loaded" Aug 29 16:12:36 volumio sudo[2556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 16:11' Aug 29 16:12:36 volumio sudo[2556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=info msg="zeroconf server listening on port 39883" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="obtained new client token: AAFLraU/40R3j940zEvt/4xIRl+LFabhiNWGJRR9UDPn8d0fezwt8fPZ/okgOO4hSkl3tfaYWdmRbJit8bsl704G0ESEILKJyhhUIL5NHrtdGrT2PKE6GjHRyWNdJwYWbYdtKz5+X1fNVIcFnRjOi/oc+B4LSorBJa3lwry67enNno567Yq2SGbg2hfEJuhvZJnJXHxk6hiUcJPbcPf5wft/f0XtocwFSv/PbGmP+6C61tg1AQ0BC1ZpFw==" Aug 29 16:12:36 volumio go-librespot[2558]: time="2026-08-29T16:12:36-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 29 16:12:37 volumio go-librespot[2558]: time="2026-08-29T16:12:37-05:00" level=debug msg="completed keyexchange" Aug 29 16:12:37 volumio go-librespot[2558]: time="2026-08-29T16:12:37-05:00" level=debug msg="completed challenge" Aug 29 16:12:37 volumio go-librespot[2558]: time="2026-08-29T16:12:37-05:00" level=info msg="authenticated AP" username="mr**********th" Aug 29 16:12:37 volumio go-librespot[2558]: time="2026-08-29T16:12:37-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 16:12:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 16:12:37 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"