-- Logs begin at Sun 2026-08-30 01:22:53 CEST, end at Sun 2026-08-30 11:27:28 CEST. --
Aug 30 11:26:01 volumio volumio[1013]: info: CoreCommandRouter::Close All Modals sent
Aug 30 11:26:03 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:08 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:26:08 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Aug 30 11:26:08 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:13 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:18 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:23 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:28 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:32 volumio volumio[1013]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf
Aug 30 11:26:32 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:32.251+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:33 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:34 volumio volumio[1013]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf
Aug 30 11:26:34 volumio volumio[1013]: info: Folder /tmp/plugins removed
Aug 30 11:26:34 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:34.512+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:35 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:35.262+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:35 volumio volumio[1013]: info: Check plugin dependencies
Aug 30 11:26:35 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 30 11:26:35 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:35.356+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:35 volumio volumio[1013]: info: Checking if plugin already exists
Aug 30 11:26:35 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:35.361+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:35 volumio volumio[1013]: info: Rename folder
Aug 30 11:26:35 volumio volumio[1013]: info: Folder /tmp/downloaded_plugin.zip removed
Aug 30 11:26:35 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:35.417+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:35 volumio volumio[1013]: info: Move to category
Aug 30 11:26:37 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:37.215+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:37 volumio volumio[1013]: info: Checking if install.sh is present
Aug 30 11:26:37 volumio volumio[1013]: info: Executing install.sh
Aug 30 11:26:37 volumio sudo[28476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh
Aug 30 11:26:37 volumio sudo[28476]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:26:37 volumio volumio[1013]: info: Installing Go-librespot
Aug 30 11:26:37 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:37.374+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:37 volumio volumio[1013]: info: Checking old vollibrespot installs
Aug 30 11:26:37 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:37.383+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:37 volumio systemd[1]: Reloading.
Aug 30 11:26:37 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Aug 30 11:26:38 volumio volumio[1013]: info: Downloading daemon
Aug 30 11:26:38 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:38.238+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:38 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:42 volumio volumio[1013]: info: Creating directories
Aug 30 11:26:42 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:42.096+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:42 volumio volumio[1013]: info: Creating data directory
Aug 30 11:26:42 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:42.101+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:42 volumio volumio[1013]: info: Creating Start Script
Aug 30 11:26:42 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:42.116+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:42 volumio systemd[1]: Reloading.
Aug 30 11:26:42 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Aug 30 11:26:42 volumio volumio[1013]: Plugin install end detected on script
Aug 30 11:26:42 volumio sudo[28476]: pam_unix(sudo:session): session closed for user root
Aug 30 11:26:42 volumio volumio[1013]: info: Install script completed
Aug 30 11:26:42 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:42.935+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:42 volumio volumio[1013]: info: Adding reference to registry
Aug 30 11:26:42 volumio volumio5-onboarding[1612]: time=2026-08-30T11:26:42.942+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Aug 30 11:26:42 volumio volumio[1013]: info: Done installing plugin.
Aug 30 11:26:42 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 30 11:26:42 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Aug 30 11:26:42 volumio volumio[1013]: info: Folder /tmp/plugins removed
Aug 30 11:26:42 volumio volumio[1013]: info: Folder /tmp/downloaded_plugin.zip removed
Aug 30 11:26:42 volumio volumio[1013]: info: Folder /data/temp removed
Aug 30 11:26:43 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:46 volumio volumio[1013]: info: Enabling plugin spop
Aug 30 11:26:46 volumio volumio[1013]: info: Loading plugin "spop"...
Aug 30 11:26:46 volumio volumio[1013]: info: PLUGIN START: spop
Aug 30 11:26:46 volumio volumio[1013]: info: Creating Spotify config file
Aug 30 11:26:46 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:26:46 volumio volumio[1013]: info: Done.
Aug 30 11:26:46 volumio volumio[1013]: info: Spotify config file written
Aug 30 11:26:46 volumio volumio[1013]: info: No need to fix Spotify hosts
Aug 30 11:26:46 volumio sudo[28578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Aug 30 11:26:46 volumio sudo[28578]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:26:47 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:26:47 volumio go-librespot[28580]: go-librespot daemon starting...
Aug 30 11:26:47 volumio sudo[28578]: pam_unix(sudo:session): session closed for user root
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=debug msg="no app state found"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=debug msg="stored credentials not found"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=info msg="generated new device id: 609484849fa9bb9954266d9fbb981de4996b1a53"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=info msg="zeroconf server listening on port 41611"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:26:47 volumio go-librespot[28580]: time="2026-08-30T11:26:47+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:26:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:26:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:26:48 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:50 volumio volumio[1013]: info: go-librespot daemon successfully initialized
Aug 30 11:26:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:26:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Aug 30 11:26:50 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:26:50 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:26:50 volumio go-librespot[28604]: go-librespot daemon starting...
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=debug msg="app state loaded"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=debug msg="stored credentials not found"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=info msg="zeroconf server listening on port 37267"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:26:50 volumio go-librespot[28604]: time="2026-08-30T11:26:50+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:26:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:26:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:26:53 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:26:53 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:26:53 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:26:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Aug 30 11:26:53 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:26:54 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:26:54 volumio go-librespot[28614]: go-librespot daemon starting...
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=debug msg="app state loaded"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=debug msg="stored credentials not found"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=info msg="zeroconf server listening on port 35937"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:26:54 volumio go-librespot[28614]: time="2026-08-30T11:26:54+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:26:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:26:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:26:56 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:26:56 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:26:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:26:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Aug 30 11:26:57 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:26:57 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:26:57 volumio go-librespot[28625]: go-librespot daemon starting...
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=debug msg="app state loaded"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=debug msg="stored credentials not found"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=info msg="zeroconf server listening on port 41509"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:26:57 volumio go-librespot[28625]: time="2026-08-30T11:26:57+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:26:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:26:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:26:58 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:26:59 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:26:59 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Aug 30 11:27:00 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:01 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:01 volumio go-librespot[28649]: go-librespot daemon starting...
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=debug msg="app state loaded"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=info msg="zeroconf server listening on port 43713"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:01 volumio go-librespot[28649]: time="2026-08-30T11:27:01+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:02 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:02 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:03 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:27:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Aug 30 11:27:04 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:04 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:04 volumio go-librespot[28659]: go-librespot daemon starting...
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=debug msg="app state loaded"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=info msg="zeroconf server listening on port 33087"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:04 volumio go-librespot[28659]: time="2026-08-30T11:27:04+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:05 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:05 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Aug 30 11:27:07 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:08 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:08 volumio go-librespot[28669]: go-librespot daemon starting...
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="app state loaded"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:08 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="new websocket client"
Aug 30 11:27:08 volumio volumio[1013]: info: Connection to go-librespot Websocket established
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=info msg="zeroconf server listening on port 39649"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:08 volumio go-librespot[28669]: time="2026-08-30T11:27:08+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:08 volumio volumio[1013]: info: Connection to go-librespot Websocket closed
Aug 30 11:27:08 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:27:11 volumio volumio[1013]: info: Getting Spotify volume
Aug 30 11:27:11 volumio volumio[1013]: (node:1013) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:11 volumio volumio[1013]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Aug 30 11:27:11 volumio volumio[1013]: (node:1013) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2536)
Aug 30 11:27:11 volumio volumio[1013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Aug 30 11:27:11 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState
Aug 30 11:27:11 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:11 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Aug 30 11:27:11 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:11 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:11 volumio go-librespot[28693]: go-librespot daemon starting...
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=debug msg="app state loaded"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=info msg="zeroconf server listening on port 34089"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:11 volumio go-librespot[28693]: time="2026-08-30T11:27:11+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:13 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:27:14 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:14 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Aug 30 11:27:14 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:15 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:15 volumio go-librespot[28704]: go-librespot daemon starting...
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=debug msg="app state loaded"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=info msg="zeroconf server listening on port 39925"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:15 volumio go-librespot[28704]: time="2026-08-30T11:27:15+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:17 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:17 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:18 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:27:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Aug 30 11:27:18 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:18 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:18 volumio go-librespot[28714]: go-librespot daemon starting...
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=debug msg="app state loaded"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=info msg="zeroconf server listening on port 43343"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:18 volumio go-librespot[28714]: time="2026-08-30T11:27:18+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:20 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:20 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Aug 30 11:27:21 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:22 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:22 volumio go-librespot[28738]: go-librespot daemon starting...
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=debug msg="app state loaded"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=info msg="zeroconf server listening on port 33151"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:22 volumio go-librespot[28738]: time="2026-08-30T11:27:22+02:00" level=fatal msg="failed running zeroconf" error="failed initializing zeroconf: failed registering zeroconf service: failed to add service: Local name collision"
Aug 30 11:27:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 11:27:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 30 11:27:23 volumio volumio[1013]: info: Discovery: Restarting Browsing
Aug 30 11:27:23 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:23 volumio volumio[1013]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 30 11:27:25 volumio volumio[1013]: info: [go-librespot] time="2026-08-30T11:27:25+02:00" level=error msg="websocket connection errored" error="failed to get reader: received close frame: status = StatusNoStatusRcvd and reason = \"\""
Aug 30 11:27:25 volumio volumio[1013]: warn: [SpotifyConnect] event stream closed, retrying…
Aug 30 11:27:25 volumio volumio[1013]: warn: [SpotifyConnect] daemon exited (0)
Aug 30 11:27:25 volumio volumio[1013]: info: Disabling plugin spotify-connect
Aug 30 11:27:25 volumio volumio[1013]: info: Preparing to generate the ALSA configuration file
Aug 30 11:27:25 volumio volumio[1013]: info: Asound.conf file unchanged, so no further update is needed
Aug 30 11:27:25 volumio volumio[1013]: info: Output device has changed, restarting MPD
Aug 30 11:27:25 volumio sudo[28749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 30 11:27:25 volumio sudo[28749]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:27:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 30 11:27:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Aug 30 11:27:25 volumio sudo[28749]: pam_unix(sudo:session): session closed for user root
Aug 30 11:27:25 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 30 11:27:25 volumio volumio[1013]: info: Output device has changed, restarting Shairport Sync
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:27:25 volumio sudo[28753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 30 11:27:25 volumio sudo[28753]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:27:25 volumio systemd[1]: Started go-librespot Daemon.
Aug 30 11:27:25 volumio go-librespot[28752]: go-librespot daemon starting...
Aug 30 11:27:25 volumio systemd[1]: Stopping Music Player Daemon...
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=info msg="running go-librespot 0.7.1"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=debug msg="app state loaded"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=debug msg="stored credentials not found"
Aug 30 11:27:25 volumio volumio[1013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 30 11:27:25 volumio volumio[1013]: info: Done.
Aug 30 11:27:25 volumio volumio[1013]: info: MPD Permissions set
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio systemd[1]: mpd.service: Succeeded.
Aug 30 11:27:25 volumio systemd[1]: Stopped Music Player Daemon.
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 30 11:27:25 volumio volumio[1013]: info: Starting Shairport Sync
Aug 30 11:27:25 volumio systemd[1]: Starting Music Player Daemon...
Aug 30 11:27:25 volumio sudo[28772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 30 11:27:25 volumio sudo[28772]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:27:25 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Aug 30 11:27:25 volumio systemd[1]: shairport-sync.service: Succeeded.
Aug 30 11:27:25 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:27:25 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Aug 30 11:27:25 volumio sudo[28766]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Aug 30 11:27:25 volumio sudo[28766]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 30 11:27:25 volumio sudo[28766]: pam_unix(sudo:session): session closed for user root
Aug 30 11:27:25 volumio sudo[28772]: pam_unix(sudo:session): session closed for user root
Aug 30 11:27:25 volumio volumio[1013]: info: Shairport-Sync Started
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=info msg="zeroconf server listening on port 38471"
Aug 30 11:27:25 volumio go-librespot[28752]: time="2026-08-30T11:27:25+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration"
Aug 30 11:27:26 volumio volumio[1013]: info: Initializing connection to go-librespot Websocket
Aug 30 11:27:26 volumio go-librespot[28752]: time="2026-08-30T11:27:26+02:00" level=debug msg="new websocket client"
Aug 30 11:27:26 volumio volumio[1013]: info: Connection to go-librespot Websocket established
Aug 30 11:27:27 volumio mpd[28778]: Aug 30 11:27 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Aug 30 11:27:27 volumio systemd[1]: Started Music Player Daemon.
Aug 30 11:27:27 volumio sudo[28753]: pam_unix(sudo:session): session closed for user root
Aug 30 11:27:27 volumio volumio[1013]: error: updateQueue error: null
Aug 30 11:27:28 volumio volumio[1013]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 30 11:27:28 volumio volumio[1013]: Error: Unable to resolve or reject the same promise twice
Aug 30 11:27:28 volumio volumio[1013]: at Promise.resolve (/data/plugins/music_service/spotify-connect/node_modules/kew/kew.js:140:43)
Aug 30 11:27:28 volumio volumio[1013]: at Timeout._onTimeout (/data/plugins/music_service/spotify-connect/index.js:162:13)
Aug 30 11:27:28 volumio volumio[1013]: at listOnTimeout (internal/timers.js:554:17)
Aug 30 11:27:28 volumio volumio[1013]: at processTimers (internal/timers.js:497:7)
Aug 30 11:27:28 volumio volumio[1013]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 30 11:27:28 volumio sudo[28792]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-30 11:26
Aug 30 11:27:28 volumio sudo[28792]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="5c0e72e4b5817fe66c91c9d15d75ff13b8e3f4ba"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Mon 30 Mar 2026 02:51:29 PM CEST"
VOLUMIO_VERSION="3.914"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="98fe12c88d8ff391f569279e2f874892"