Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 10:48:01 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 29 10:48:01 deskplayer volumio[1430]: info: AutoStart - Check #9/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 10:48:01 deskplayer volumio[1430]: info: MyVolumio status changed Aug 29 10:48:01 deskplayer volumio[1430]: info: Streaming services startup Aug 29 10:48:01 deskplayer volumio[1430]: info: Starting Streaming Daemon Aug 29 10:48:02 deskplayer volumio[1430]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 10:48:02 deskplayer volumio[1430]: info: Removing audio output: Aug 29 10:48:02 deskplayer volumio[1430]: info: Stoppping Tunnel 1 Aug 29 10:48:02 deskplayer sudo[2481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 10:48:02 deskplayer sudo[2481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 10:48:02 deskplayer volumio[1430]: info: Received Get System Info Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 10:48:02 deskplayer volumio[1430]: info: Discovery: Getting this device information Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState Aug 29 10:48:02 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 10:48:02 deskplayer sudo[2483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 10:48:02 deskplayer sudo[2483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:02 deskplayer sudo[2481]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:02 deskplayer volumio[1430]: info: Received Get System Info Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 10:48:02 deskplayer volumio[1430]: info: Discovery: Getting this device information Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState Aug 29 10:48:02 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:02 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer 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 10:48:02 deskplayer sudo[2483]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:03 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 29 10:48:03 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:03 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:03 deskplayer go-librespot[2486]: go-librespot daemon starting... Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="app state loaded" Aug 29 10:48:03 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:03 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+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 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+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 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+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 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="zeroconf server listening on port 37917" Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="obtained new client token: AAEQBBmUjlDLU783z0AHUyc3D56QdPT4XVVxYl9I72YbyThpLLSE9GEOkfzYHOaWd3CE5t1y1FAZ4sxX5TY/w/B0/KmkPbD9Q4fMq1DT13u0JP5yuwJ3q7CMW4UlSPTdBA8y5l1yK/TU8rjYk1IkVHyD6udyg9D+0Zy3JOoYrP3+5zsKBjaeAJbZg2uYL2Hs8fX3SUyMJoa6XDAW8ab2M0yMU7Bey5G1SvXloufNRCQjL2hDmA2qBv/K" Aug 29 10:48:03 deskplayer go-librespot[2487]: time="2026-08-29T10:48:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=debug msg="completed challenge" Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:04 deskplayer go-librespot[2487]: time="2026-08-29T10:48:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:04 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:04 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:04 deskplayer volumio[1430]: info: Remote SSH Stopped Aug 29 10:48:04 deskplayer volumio[1430]: error: Cannot start Volumio Streaming Daemon Aug 29 10:48:04 deskplayer volumio[1430]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 10:48:04 deskplayer volumio[1430]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 10:48:05 deskplayer volumio[1430]: info: BOOT COMPLETED Aug 29 10:48:05 deskplayer volumio[1430]: info: Setting Geolocation for MyVolumio to eu4 Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:05 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:05 deskplayer volumio[1430]: info: Successfully Added MyVolumio device Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 10:48:06 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket Aug 29 10:48:06 deskplayer volumio[1430]: info: Updating MyVolumio device info Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:48:06 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Check #10/60 - VOLUMIO_SYSTEM_STATUS = ready Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - System ready state CONFIRMED after 10 checks Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Setting startup volume to 50 Aug 29 10:48:06 deskplayer volumio[1430]: info: VolumeController::SetAlsaVolume50 Aug 29 10:48:06 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:06.934+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:06.934+02:00 Aug 29 10:48:06 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:06.934+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:06.934+02:00 Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Startup volume set successfully to 50 Aug 29 10:48:06 deskplayer volumio[1430]: info: AutoStart - Applying additional delay of 5000ms before playback Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:06 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:06 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:07 deskplayer volumio[1430]: info: Successfully Updated MyVolumio device Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.176+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=0uH8bJv4ugNB6Mzw6w5INVMwAf52 tokenExpiry=2026-08-29T11:48:07.176+02:00 Aug 29 10:48:07 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 29 10:48:07 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:07 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:07 deskplayer go-librespot[2511]: go-librespot daemon starting... Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.668+02:00 level=ERROR msg="failed to broadcast user info" component=state error="failed to get logged user: could not get custom token: failed to fetch custom token: Get \"https://functions.volumio.cloud/api/v1/getCustomToken?idToken=eyJhbGciOiJSUzI1NiIsImtpZCI6ImFhMmNiOTcyNTIzMzc3ZWRlMjE2MzQwYmNkNTg4MTA0MTQxZTYxY2MiLCJ0eXAiOiJKV1QifQ.eyJpc3MiOiJodHRwczovL3NlY3VyZXRva2VuLmdvb2dsZS5jb20vbXl2b2x1bWlvIiwiYXVkIjoibXl2b2x1bWlvIiwiYXV0aF90aW1lIjoxNzg3OTkzMjg2LCJ1c2VyX2lkIjoiMHVIOGJKdjR1Z05CNk16dzZ3NUlOVk13QWY1MiIsInN1YiI6IjB1SDhiSnY0dWdOQjZNenc2dzVJTlZNd0FmNTIiLCJpYXQiOjE3ODc5OTMyODYsImV4cCI6MTc4Nzk5Njg4NiwiZW1haWwiOiJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiZmlyZWJhc2UiOnsiaWRlbnRpdGllcyI6eyJlbWFpbCI6WyJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iXX0sInNpZ25faW5fcHJvdmlkZXIiOiJjdXN0b20ifX0.mhPmtg-GHaEqwhoqnTABRHLMU50gwdMWMCxnCwozOSCyMNyhxUOZkcYWJaaLXKagytPMWGLdVYe67x1hckeajtObiyuBBjC0KX_MkKv2H6zRwgLibxiLof8T9SVghFjC7a9U2VlNANZ-IKMJxvHjmcLbrf47oS-_OUmZdiyZK-H0WIXcmlXZO_cGxBC7pnsRG7MNdy8Es_apthU2znnMYDiEGjzLzfvxeZFGcjwbK615kQDHnJP4bH5gcCTNORN9WP0t8BU03bNUU8jN9CjXBZ4mZJxddAb4LW-AbEfCdv4jsc9Akobcp66Px6bg3X06sKeaHl6V-hPrgcWGPJ9cgA\": context deadline exceeded" Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=debug msg="app state loaded" Aug 29 10:48:07 deskplayer go-librespot[2512]: time="2026-08-29T10:48:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:07 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:07.752+02:00 level=ERROR msg="failed to broadcast user info" component=state error="failed to get logged user: could not get custom token: failed to fetch custom token: Get \"https://functions.volumio.cloud/api/v1/getCustomToken?idToken=eyJhbGciOiJSUzI1NiIsImtpZCI6ImFhMmNiOTcyNTIzMzc3ZWRlMjE2MzQwYmNkNTg4MTA0MTQxZTYxY2MiLCJ0eXAiOiJKV1QifQ.eyJpc3MiOiJodHRwczovL3NlY3VyZXRva2VuLmdvb2dsZS5jb20vbXl2b2x1bWlvIiwiYXVkIjoibXl2b2x1bWlvIiwiYXV0aF90aW1lIjoxNzg3OTkzMjg2LCJ1c2VyX2lkIjoiMHVIOGJKdjR1Z05CNk16dzZ3NUlOVk13QWY1MiIsInN1YiI6IjB1SDhiSnY0dWdOQjZNenc2dzVJTlZNd0FmNTIiLCJpYXQiOjE3ODc5OTMyODYsImV4cCI6MTc4Nzk5Njg4NiwiZW1haWwiOiJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwiZmlyZWJhc2UiOnsiaWRlbnRpdGllcyI6eyJlbWFpbCI6WyJmbHVjaHQuY2FjaGluZ0BnbWFpbC5jb20iXX0sInNpZ25faW5fcHJvdmlkZXIiOiJjdXN0b20ifX0.mhPmtg-GHaEqwhoqnTABRHLMU50gwdMWMCxnCwozOSCyMNyhxUOZkcYWJaaLXKagytPMWGLdVYe67x1hckeajtObiyuBBjC0KX_MkKv2H6zRwgLibxiLof8T9SVghFjC7a9U2VlNANZ-IKMJxvHjmcLbrf47oS-_OUmZdiyZK-H0WIXcmlXZO_cGxBC7pnsRG7MNdy8Es_apthU2znnMYDiEGjzLzfvxeZFGcjwbK615kQDHnJP4bH5gcCTNORN9WP0t8BU03bNUU8jN9CjXBZ4mZJxddAb4LW-AbEfCdv4jsc9Akobcp66Px6bg3X06sKeaHl6V-hPrgcWGPJ9cgA\": context deadline exceeded" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+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 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+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 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="zeroconf server listening on port 41893" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="obtained new client token: AAHzc7xuH04nuzknLad4y+IZXroqG19jc/y6Fi5gHEuLs9HkTxhgp+6UNWIU1kHQXMJFf1/Iu4tFGg337VCxhNwGxo3FyH6sv8l2zGYTDXpMKA6bJrZLibNieVk2hXPKD0Y3n/agQA9EAx5XbaBjCGnGGmeqU6vX+jCmoj6YxkU+N8XsU4cbt40z/6aQB0QGws+1x/tEPvzwGWhLV4DWgazQn0kpysIxHWKqUc4TYAwABAvOmCz4tFds" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=debug msg="completed challenge" Aug 29 10:48:08 deskplayer go-librespot[2512]: time="2026-08-29T10:48:08+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:08 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 10:48:08 deskplayer volumio[1430]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 29 10:48:08 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 29 10:48:09 deskplayer go-librespot[2512]: time="2026-08-29T10:48:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:09 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:09 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:09 deskplayer volumio[1430]: info: Received Get System Version Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 10:48:09 deskplayer volumio[1430]: info: Received Get System Info Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 10:48:09 deskplayer volumio[1430]: info: Discovery: Getting this device information Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetState Aug 29 10:48:09 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 10:48:09 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket Aug 29 10:48:09 deskplayer volumio[1430]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 10:48:09 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - startPlayback called Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreCommandRouter::volumioGetQueue Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::getQueue Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getQueue Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - Queue has 18 items Aug 29 10:48:12 deskplayer volumio[1430]: info: AutoStart - Playing from position 0 Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPlay Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::play index 0 Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::stop Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::play index undefined Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:12 deskplayer volumio[1430]: info: CoreStateMachine::startPlaybackTimer Aug 29 10:48:12 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:12 deskplayer volumio[1430]: info: [1787993292294] ControllerWebradio::clearAddPlayTrack Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 10:48:12 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 29 10:48:12 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:12 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:12 deskplayer go-librespot[2539]: go-librespot daemon starting... Aug 29 10:48:12 deskplayer volumio[1430]: info: sendMpdCommand stop took 105 milliseconds Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 10:48:12 deskplayer volumio[1430]: info: Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=debug msg="app state loaded" Aug 29 10:48:12 deskplayer volumio[1430]: info: sendMpdCommand clear took 81 milliseconds Aug 29 10:48:12 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand load "https://orf-live.ors-shoutcast.at/oe1-q2a" Aug 29 10:48:12 deskplayer volumio[1430]: info: Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:12 deskplayer go-librespot[2540]: time="2026-08-29T10:48:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:12 deskplayer volumio[1430]: info: Aug 29 10:48:12 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:12 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:12 deskplayer volumio[1430]: error: updateQueue error: null Aug 29 10:48:12 deskplayer volumio[1430]: info: ------------------------------ 245ms Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+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 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+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 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+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 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="zeroconf server listening on port 34439" Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Aug 29 10:48:13 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="obtained new client token: AAFZGm0opykwtOdDg622UHXKW5fgKP5haX6i7DCboE0yzeEpsVr2Or8EofRvIkdmDauYwY6k2YjcMrtyvWhjjPWnIfyw8/ddIAMSmAyXzqlz3AWGVahHQrYp4fF5JzoWe4XhLgWycnhReyqVVT+oo4dRmiW0NRt1j689ihxETJD+WWOOALH0KcD5HDP0jdrMIMcB2UjVm07jPjE69zakCDLfXSI/v6hqcdMHvFNYKUbuhl58AYUz/mAA" Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:13 deskplayer volumio[1430]: info: Received Get System Version Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 10:48:13 deskplayer volumio[1430]: error: updateQueue error: null Aug 29 10:48:13 deskplayer volumio[1430]: error: updateQueue error: null Aug 29 10:48:13 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand add "https://orf-live.ors-shoutcast.at/oe1-q2a" Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 1085ms Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 1024ms Aug 29 10:48:13 deskplayer volumio[1430]: info: Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="new websocket client" Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=debug msg="completed challenge" Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:13 deskplayer volumio[1430]: info: sendMpdCommand add "https://orf-live.ors-shoutcast.at/oe1-q2a" took 144 milliseconds Aug 29 10:48:13 deskplayer volumio[1430]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 10:48:13 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand play Aug 29 10:48:13 deskplayer volumio[1430]: info: Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:13 deskplayer volumio[1430]: info: Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:13 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:13 deskplayer go-librespot[2540]: time="2026-08-29T10:48:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:13 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:13 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 267ms Aug 29 10:48:13 deskplayer volumio[1430]: info: sendMpdCommand play took 142 milliseconds Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 151ms Aug 29 10:48:13 deskplayer volumio[1430]: info: ------------------------------ 92ms Aug 29 10:48:13 deskplayer volumio[1430]: info: Connection to go-librespot Websocket established Aug 29 10:48:13 deskplayer volumio[1430]: info: Aug 29 10:48:13 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: Connection to go-librespot Websocket closed Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 386 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 224 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 171 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:14 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:14 deskplayer volumio[1430]: info: Aug 29 10:48:14 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:14 deskplayer volumio[1430]: info: ------------------------------ 336ms Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 265 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 227 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 226 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 184 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: info: ------------------------------ 206ms Aug 29 10:48:14 deskplayer volumio[1430]: info: sendMpdCommand status took 183 milliseconds Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:14 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:14 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:14 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":988,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:14 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus stop Aug 29 10:48:14 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:14 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:14 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1230,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:14 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:14 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:14 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:15 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1230,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:15 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:15 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1332ms Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1603ms Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1574ms Aug 29 10:48:15 deskplayer volumio[1430]: info: Aug 29 10:48:15 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:15 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:15 deskplayer volumio[1430]: info: Aug 29 10:48:15 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:15 deskplayer volumio[1430]: info: ------------------------------ 1196ms Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand status took 1171 milliseconds Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1014 milliseconds Aug 29 10:48:15 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1011 milliseconds Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:15 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:15 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:15 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1357,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:15 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:15 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:48:15 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:16 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1609,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Ö1 im Internet: oe1.ORF.at","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:16 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:16 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:16 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:16 deskplayer volumio[1430]: info: ------------------------------ 2305ms Aug 29 10:48:16 deskplayer volumio[1430]: info: ------------------------------ 2007ms Aug 29 10:48:16 deskplayer volumio[1430]: info: Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:16 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:16 deskplayer volumio[1430]: info: Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:16 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:16 deskplayer volumio[1430]: info: Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces system playlist update Aug 29 10:48:16 deskplayer volumio[1430]: info: Ignoring MPD Status Update Aug 29 10:48:16 deskplayer volumio[1430]: info: Aug 29 10:48:16 deskplayer volumio[1430]: ---------------------------- MPD announces state update: player Aug 29 10:48:16 deskplayer volumio[1430]: info: ControllerMpd::getState Aug 29 10:48:16 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand status Aug 29 10:48:17 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 29 10:48:17 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:17 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:17 deskplayer go-librespot[2581]: go-librespot daemon starting... Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=debug msg="app state loaded" Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:17 deskplayer volumio[1430]: info: Getting Spotify volume Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 1563ms Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 1513 milliseconds Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 1548 milliseconds Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 529ms Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 438 milliseconds Aug 29 10:48:17 deskplayer volumio[1430]: info: ------------------------------ 437ms Aug 29 10:48:17 deskplayer volumio[1430]: info: sendMpdCommand status took 461 milliseconds Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::parseState Aug 29 10:48:17 deskplayer volumio[1430]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 10:48:17 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:17 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:17 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1609,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:17 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:17 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:17 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+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 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+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 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+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 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="zeroconf server listening on port 43367" Aug 29 10:48:17 deskplayer go-librespot[2582]: time="2026-08-29T10:48:17+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="obtained new client token: AAHywC710MHqGT8DTHG98eKnhUbulk+ezTfAvyPZ4W/9+XafeIJojNO+wQVYY1fx4Lj4bUzMB3NfCu1+8KFdOfIKzJbJmCFJ3cZQtPEnr+7CAtdomebJYG6OGFWNFldmOIEYhobkNUXZ3y5RcW278Jv/WVyEcoH5hB12vXRwqGQkGA1IomaguVVo9YNHz22lZEhfyNxeUDJHzxm1c5h8ifvVr4GIx5sCWxs8GrKX8mod7xGd8Atj2Q==" Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:18 deskplayer volumio[1430]: info: ------------------------------ 3470ms Aug 29 10:48:18 deskplayer volumio[1430]: info: Initializing connection to go-librespot Websocket Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 729 milliseconds Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 687 milliseconds Aug 29 10:48:18 deskplayer volumio[1430]: info: sendMpdCommand playlistinfo took 686 milliseconds Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:18 deskplayer volumio[1430]: verbose: ControllerMpd::parseTrackInfo Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=debug msg="completed challenge" Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2861,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:18 deskplayer go-librespot[2582]: time="2026-08-29T10:48:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:18 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:18 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3981,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:18 deskplayer volumio[1430]: info: ControllerMpd::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::servicePushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CorePlayQueue::getTrack 0 Aug 29 10:48:18 deskplayer volumio[1430]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3981,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Nächste Sendung: Tipps für Ö1 Club-Mitglieder","artist":null,"album":null,"uri":"https://orf-live.ors-shoutcast.at/oe1-q2a","trackType":"at/oe1-q2a"} Aug 29 10:48:18 deskplayer volumio[1430]: verbose: CURRENT POSITION 0 Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState stateService play Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::syncState currentStatus play Aug 29 10:48:18 deskplayer volumio[1430]: info: Received an update from plugin. extracting info from payload Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreStateMachine::pushState Aug 29 10:48:18 deskplayer volumio[1430]: info: CoreCommandRouter::volumioPushState Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 3611ms Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 2475ms Aug 29 10:48:19 deskplayer volumio[1430]: info: ------------------------------ 2465ms Aug 29 10:48:19 deskplayer volumio[1430]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 10:48:19 deskplayer volumio[1430]: Error: socket hang up Aug 29 10:48:19 deskplayer volumio[1430]: at connResetException (node:internal/errors:720:14) Aug 29 10:48:19 deskplayer volumio[1430]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 29 10:48:19 deskplayer volumio[1430]: at Socket.emit (node:events:526:35) Aug 29 10:48:19 deskplayer volumio[1430]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 29 10:48:19 deskplayer volumio[1430]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 29 10:48:19 deskplayer volumio[1430]: code: 'ECONNRESET', Aug 29 10:48:19 deskplayer volumio[1430]: response: undefined Aug 29 10:48:19 deskplayer volumio[1430]: } Aug 29 10:48:19 deskplayer volumio[1430]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 10:48:21 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 29 10:48:21 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:21 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:21 deskplayer go-librespot[2598]: go-librespot daemon starting... Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=debug msg="app state loaded" Aug 29 10:48:21 deskplayer go-librespot[2599]: time="2026-08-29T10:48:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+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 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+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 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="zeroconf server listening on port 36695" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="obtained new client token: AAGFP1bmSY6xTtJqr06GbsBTuX1jxWZ4CPKi/6yuZc64hvux9EWiCed6VqyOU6XQBiG8liSmahFnvot7huYq9i/QNmrTgIYkfABR6Q7WHk8iCIXmAsXxlMkr+pB43/zsgC3daN8DG9071JhQa/xhJTrPfzWGf3ErpfQe6enlwpSWCC2awr14+Uwtem8g9DLjHvs+nSDxD0oVaC6zn1P8Gmi2jK1TiQfmuHJ7CUT7xHKDcG/63b0USbYT" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=debug msg="completed challenge" Aug 29 10:48:22 deskplayer go-librespot[2599]: time="2026-08-29T10:48:22+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:23 deskplayer go-librespot[2599]: time="2026-08-29T10:48:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:23 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:23 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:26 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 29 10:48:26 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:26 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:26 deskplayer go-librespot[2632]: go-librespot daemon starting... Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=debug msg="app state loaded" Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+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 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+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 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+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 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="zeroconf server listening on port 36245" Aug 29 10:48:26 deskplayer go-librespot[2633]: time="2026-08-29T10:48:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="obtained new client token: AAHJp6H6zlT1dobNhgOrBfSyZBQk/sJJw+3lJp6V0zj99f2Vkvorb/eeSnE2zRSGOtP5PjUnJJ06yMBlsCsuvkulfKo9qcMDr5jHStdEe2K/XrRKdcbM9PLhRkF3a1LWK5A7ImHcn6XXzZvB/wal5wOK/Vg2j7VzfcnM7z8cH/JR5U9FR7ab5EzeU/gUPQbuZnhAa2Q26DBB1RWw/CDlpdJGKt87BlDr+D5QQFtp0yVoR8GAK0WgAw==" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=debug msg="completed challenge" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:27 deskplayer go-librespot[2633]: time="2026-08-29T10:48:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:27 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:27 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:30 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 29 10:48:30 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:30 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:30 deskplayer go-librespot[2643]: go-librespot daemon starting... Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=debug msg="app state loaded" Aug 29 10:48:30 deskplayer go-librespot[2644]: time="2026-08-29T10:48:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+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 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+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 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+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 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="zeroconf server listening on port 37583" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="obtained new client token: AAGj4l8hYrYEpzY1aRYGtqCkPTGCVVNiKUbJd4cfQRcVuGkrEkR70AkDJLiq7CiSLExeIKlqJPA/ieFqMYtsHKcoMK7nPaFNovyavOO/wNG/odfNv4Z+CdOrl7HnHVtSoBwyRD6xSWOO+armHo78HfGziAo8cDLmctH3N+8fW//wecci4lHhlqtR/i1vhL9MgDUXscbk8ZSHpD0Z46o63apcLoXNwQLqM7PcD9obv93DOGdyVUhi2Ijr" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=debug msg="completed challenge" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:31 deskplayer go-librespot[2644]: time="2026-08-29T10:48:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:31 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:31 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:35 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 29 10:48:35 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:35 deskplayer sudo[2655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 10:47' Aug 29 10:48:35 deskplayer sudo[2655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:35 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:35 deskplayer go-librespot[2656]: go-librespot daemon starting... Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=debug msg="app state loaded" Aug 29 10:48:35 deskplayer go-librespot[2658]: time="2026-08-29T10:48:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+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 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+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 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+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 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="zeroconf server listening on port 34615" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="obtained new client token: AAFk1PSDDzwcDI3VOo3JoN0442bMFZB7Kmh7WF06TFN6H5oZ6rDUJrcVZYYhCy7q52zCW4yJrHDYOnIFHK2zTxBaqH7hhJi2S+/oi8rRZ1cK0nsl+yTTpqH8qxWnuXq0KNyCsr7FMl+SQaMh4W0OzNBnv0LVg7AJG/ce/O+wigCl7zqGZ0Pv+lw9NTeNdlt26oZV2L1Omik44aFXRjKnbfx9T0RvSsU/E5qHzJgJpzlNm4k1CaRrJ99b" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=debug msg="completed challenge" Aug 29 10:48:36 deskplayer go-librespot[2658]: time="2026-08-29T10:48:36+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:37 deskplayer go-librespot[2658]: time="2026-08-29T10:48:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:37 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:37 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:39 deskplayer sshd[2681]: Accepted publickey for volumio from 192.168.1.210 port 54994 ssh2: RSA SHA256:ODKQL3gpmI5vrRENu+fRTs7eXecqGFHwdVJSLYBXV/4 Aug 29 10:48:39 deskplayer sshd[2681]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Aug 29 10:48:39 deskplayer systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Aug 29 10:48:39 deskplayer systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Aug 29 10:48:39 deskplayer systemd-logind[594]: New session 3 of user volumio. Aug 29 10:48:39 deskplayer sudo[2655]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:39 deskplayer systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Aug 29 10:48:39 deskplayer systemd[1]: Starting user@1000.service - User Manager for UID 1000... Aug 29 10:48:39 deskplayer (systemd)[2684]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Aug 29 10:48:40 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 29 10:48:40 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:40 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:40 deskplayer go-librespot[2704]: go-librespot daemon starting... Aug 29 10:48:40 deskplayer systemd[2684]: Queued start job for default target default.target. Aug 29 10:48:40 deskplayer go-librespot[2705]: time="2026-08-29T10:48:40+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:40 deskplayer go-librespot[2705]: time="2026-08-29T10:48:40+02:00" level=debug msg="app state loaded" Aug 29 10:48:40 deskplayer systemd[2684]: Created slice app.slice - User Application Slice. Aug 29 10:48:40 deskplayer systemd[2684]: Reached target paths.target - Paths. Aug 29 10:48:40 deskplayer systemd[2684]: Reached target timers.target - Timers. Aug 29 10:48:40 deskplayer systemd[2684]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Aug 29 10:48:40 deskplayer systemd[2684]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 29 10:48:40 deskplayer systemd[2684]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Aug 29 10:48:40 deskplayer systemd[2684]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Aug 29 10:48:40 deskplayer systemd[2684]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Aug 29 10:48:40 deskplayer systemd[2684]: Reached target sockets.target - Sockets. Aug 29 10:48:40 deskplayer systemd[2684]: Reached target basic.target - Basic System. Aug 29 10:48:40 deskplayer systemd[1]: Started user@1000.service - User Manager for UID 1000. Aug 29 10:48:40 deskplayer systemd[2684]: Started mpris-proxy.service - Bluetooth mpris proxy. Aug 29 10:48:40 deskplayer systemd[2684]: Reached target default.target - Main User Target. Aug 29 10:48:40 deskplayer systemd[2684]: Startup finished in 1.121s. Aug 29 10:48:40 deskplayer systemd[1]: Started session-3.scope - Session 3 of User volumio. Aug 29 10:48:40 deskplayer go-librespot[2705]: time="2026-08-29T10:48:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:40 deskplayer mpris-proxy[2712]: Can't get on session bus Aug 29 10:48:40 deskplayer systemd[2684]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:40 deskplayer systemd[2684]: mpris-proxy.service: Failed with result 'exit-code'. Aug 29 10:48:41 deskplayer sshd[2681]: pam_env(sshd:session): deprecated reading of user environment enabled Aug 29 10:48:41 deskplayer go-librespot[2705]: time="2026-08-29T10:48:41+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 29 10:48:41 deskplayer go-librespot[2705]: time="2026-08-29T10:48:41+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 29 10:48:41 deskplayer go-librespot[2705]: time="2026-08-29T10:48:41+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 29 10:48:41 deskplayer go-librespot[2705]: time="2026-08-29T10:48:41+02:00" level=info msg="zeroconf server listening on port 34105" Aug 29 10:48:41 deskplayer go-librespot[2705]: time="2026-08-29T10:48:41+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:41 deskplayer systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:41 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:41.945+02:00 level=ERROR msg="failed reading message" error="read tcp 127.0.0.1:60878->127.0.0.1:3000: read: connection reset by peer" Aug 29 10:48:41 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:41.947+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:41 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:41] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Aug 29 10:48:41 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:41] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Aug 29 10:48:42 deskplayer systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 29 10:48:42 deskplayer systemd[1]: volumio.service: Consumed 4min 31.177s CPU time. Aug 29 10:48:42 deskplayer systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=debug msg="obtained new client token: AAGZTNZr6TmsPLu8e0+rwSxB+NVaT8tSD77G0h3qWi95rMdG7AOlxxDFMzD9f9kGY8w3ZvBVxb7rE+SvQJ1VszQnj9vpf/muvl/ztFMiEHDdTCVstg2vmhnGPdA15xgy7KuqNO5N4lpteerLbOYzqenEThj0CA9IADrtVJKG1wJdwFDz8fZzZ8FKxQFeG7Svr0Q7hemQGtkbRIgTc2UGDPMDihUpDfEv+oYShaaL+UKs8leQBo93Rg==" Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:42 deskplayer systemd[1]: dynamicswap.service: Deactivated successfully. Aug 29 10:48:42 deskplayer systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Aug 29 10:48:42 deskplayer systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 29 10:48:42 deskplayer systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 29 10:48:42 deskplayer systemd[1]: volumio.service: Consumed 4min 31.177s CPU time. Aug 29 10:48:42 deskplayer systemd[1]: Started volumio.service - Volumio Backend Module. Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=debug msg="completed challenge" Aug 29 10:48:42 deskplayer systemd[1]: dynamicswap.service: Deactivated successfully. Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:42 deskplayer go-librespot[2705]: time="2026-08-29T10:48:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:42 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:42 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:42 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:42.951+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:43 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:43.952+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:44 deskplayer pirate_port[1714]: [2026-08-29T08:48:44.099Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { Aug 29 10:48:44 deskplayer pirate_port[1714]: message: 'xhr poll error', Aug 29 10:48:44 deskplayer pirate_port[1714]: stack: 'Error: xhr poll error\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at Transport.onError (/data/plugins/system_hardware/pirate_port/node_modules/engine.io-client/lib/transport.js:68:13)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at Request. (/data/plugins/system_hardware/pirate_port/node_modules/engine.io-client/lib/transports/polling-xhr.js:132:10)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at Emitter.emit (/data/plugins/system_hardware/pirate_port/node_modules/component-emitter/index.js:145:20)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at Request.onError (/data/plugins/system_hardware/pirate_port/node_modules/engine.io-client/lib/transports/polling-xhr.js:314:8)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at Timeout._onTimeout (/data/plugins/system_hardware/pirate_port/node_modules/engine.io-client/lib/transports/polling-xhr.js:261:18)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at listOnTimeout (node:internal/timers:573:17)\n' + Aug 29 10:48:44 deskplayer pirate_port[1714]: ' at process.processTimers (node:internal/timers:514:7)' Aug 29 10:48:44 deskplayer pirate_port[1714]: } Aug 29 10:48:44 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:44.955+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:45 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 29 10:48:45 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:45 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:45 deskplayer go-librespot[2771]: go-librespot daemon starting... Aug 29 10:48:45 deskplayer go-librespot[2772]: time="2026-08-29T10:48:45+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:45 deskplayer go-librespot[2772]: time="2026-08-29T10:48:45+02:00" level=debug msg="app state loaded" Aug 29 10:48:45 deskplayer go-librespot[2772]: time="2026-08-29T10:48:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:45 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:45.957+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+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 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+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 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+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 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+02:00" level=info msg="zeroconf server listening on port 46485" Aug 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+02:00" level=debug msg="obtained new client token: AAFPmNXW2OwHP95+pbA5SoPXLO/qyjUfpGrENot/Z7glhV9cI3H4H1ky1aTfPPvFrDTdUszqge9yhDZyILkd9r03BGksCFVkat+SMd2700W51ru0SvgqZoiJvcITYeXvhITlO+YDdTaaSKwzQIDEMkrk1c8XHLn6TkZkRwAUHNN28QiXR0vDFqHertOzWOMA2IwPfSC401mC5e/DIc7jp/3urFyLew280MVdNUhfO6cJOXr3+BlEW35n" Aug 29 10:48:46 deskplayer go-librespot[2772]: time="2026-08-29T10:48:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:46 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:46.959+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 10:48:46 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:46] [info] asio async_connect error: asio.system:111 (Connection refused) Aug 29 10:48:47 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:46] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Aug 29 10:48:47 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:46] [error] handle_connect error: Connection refused Aug 29 10:48:47 deskplayer go-librespot[2772]: time="2026-08-29T10:48:47+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:47 deskplayer go-librespot[2772]: time="2026-08-29T10:48:47+02:00" level=debug msg="completed challenge" Aug 29 10:48:47 deskplayer go-librespot[2772]: time="2026-08-29T10:48:47+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:47 deskplayer go-librespot[2772]: time="2026-08-29T10:48:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:47 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:47 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:48 deskplayer volumio[2754]: info: ------------------------------------------- Aug 29 10:48:48 deskplayer volumio[2754]: info: ----- Volumio3 ---- Aug 29 10:48:48 deskplayer volumio[2754]: info: ------------------------------------------- Aug 29 10:48:48 deskplayer volumio[2754]: info: ----- System startup ---- Aug 29 10:48:48 deskplayer volumio[2754]: info: ------------------------------------------- Aug 29 10:48:50 deskplayer volumio[2754]: info: MYVOLUMIO Environment detected Aug 29 10:48:50 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 29 10:48:50 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:50 deskplayer volumio[2754]: info: Plugin folders cleanup Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning into folder /volumio/app/plugins/ Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category audio_interface Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category miscellanea Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category music_service Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category plugins.json Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category system_controller Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category user_interface Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning into folder /data/plugins/ Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category music_service Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category system_controller Aug 29 10:48:50 deskplayer volumio[2754]: info: Scanning category system_hardware Aug 29 10:48:50 deskplayer volumio[2754]: info: Plugin folders cleanup completed Aug 29 10:48:50 deskplayer volumio[2754]: info: ------------------------------------------- Aug 29 10:48:50 deskplayer volumio[2754]: info: ----- Core plugins startup ---- Aug 29 10:48:50 deskplayer volumio[2754]: info: ------------------------------------------- Aug 29 10:48:50 deskplayer volumio[2754]: info: Loading plugins from folder /volumio/app/plugins/ Aug 29 10:48:50 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:50 deskplayer go-librespot[2789]: go-librespot daemon starting... Aug 29 10:48:50 deskplayer volumio[2754]: info: Adding plugin upnp to MyMusic Plugins Aug 29 10:48:50 deskplayer volumio[2754]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 29 10:48:50 deskplayer volumio[2754]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 29 10:48:50 deskplayer volumio[2754]: info: Loading plugins from folder /data/plugins/ Aug 29 10:48:50 deskplayer volumio[2754]: info: Loading plugin "system"... Aug 29 10:48:50 deskplayer go-librespot[2790]: time="2026-08-29T10:48:50+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:50 deskplayer go-librespot[2790]: time="2026-08-29T10:48:50+02:00" level=debug msg="app state loaded" Aug 29 10:48:50 deskplayer go-librespot[2790]: time="2026-08-29T10:48:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:50 deskplayer volumio[2754]: info: Loading plugin "appearance"... Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+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 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+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 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+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 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=info msg="zeroconf server listening on port 36347" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=debug msg="obtained new client token: AAFUel9IIOS/F0WpSp8xs99GHz6JHq1er+ihrcPAdm8ZWVprPBi5f5nKPJRPdSCIcMtdNV3vbznpWyBFZ36OqYfuM444uUqe+aK+m18DNZa+XXCp6dQEuaw29d92PyHVIhtlf/aaT39vWufFZ+PTkYibeXGTjikjoRusCKki0Z5SHE4gSM6gq8hbzycyPad8SUuw0ZinLCBhTqGY2yamrirnvxfQhuYoY6FEQqHzq4dE+odq2JBcHXTA" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=debug msg="completed challenge" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:51 deskplayer go-librespot[2790]: time="2026-08-29T10:48:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:51 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:51 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:53 deskplayer volumio[2754]: info: Loading plugin "network"... Aug 29 10:48:53 deskplayer volumio[2754]: info: Refreshing Cached IP Addresses Aug 29 10:48:53 deskplayer pirate_port[1714]: [2026-08-29T08:48:53.915Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' } Aug 29 10:48:53 deskplayer sudo[2807]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 10:48:53 deskplayer sudo[2807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:53 deskplayer volumio[2754]: info: Loading plugin "services"... Aug 29 10:48:53 deskplayer volumio[2754]: info: Loading plugin "volumio5onboarding"... Aug 29 10:48:53 deskplayer sudo[2809]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 10:48:53 deskplayer sudo[2809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:53 deskplayer sudo[2817]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 29 10:48:53 deskplayer sudo[2817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:48:53 deskplayer sudo[2807]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:54 deskplayer sudo[2809]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "alsa_controller"... Aug 29 10:48:54 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "wizard"... Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "networkfs"... Aug 29 10:48:54 deskplayer volumio[2754]: info: Starting Udev Watcher for removable devices Aug 29 10:48:54 deskplayer volumio[2754]: info: Ignoring mount for partition: boot Aug 29 10:48:54 deskplayer volumio[2754]: info: Ignoring mount for partition: volumio Aug 29 10:48:54 deskplayer volumio[2754]: info: Ignoring mount for partition: volumio_data Aug 29 10:48:54 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "volumio_command_line_client"... Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "upnp"... Aug 29 10:48:54 deskplayer volumio[2754]: info: [1787993334435] Starting Upmpd Daemon Aug 29 10:48:54 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "my_music"... Aug 29 10:48:54 deskplayer volumio[2754]: info: Loading plugin "mpd"... Aug 29 10:48:54 deskplayer volumio-remote-updater[600]: [2026-08-29 10:48:54] [connect] Successful connection Aug 29 10:48:54 deskplayer sudo[2817]: pam_unix(sudo:session): session closed for user root Aug 29 10:48:55 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 29 10:48:55 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:55 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:48:55 deskplayer go-librespot[2839]: go-librespot daemon starting... Aug 29 10:48:55 deskplayer go-librespot[2840]: time="2026-08-29T10:48:55+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:48:55 deskplayer go-librespot[2840]: time="2026-08-29T10:48:55+02:00" level=debug msg="app state loaded" Aug 29 10:48:55 deskplayer go-librespot[2840]: time="2026-08-29T10:48:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:48:55 deskplayer volumio[2754]: info: Loading plugin "upnp_browser"... Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+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 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+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 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+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 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=info msg="zeroconf server listening on port 41063" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=debug msg="obtained new client token: AAGWkerZYFcIaEX/aioModr2CyWLTPvqxNc1vX5pGq/FpzBZXer+tWbGDWEMcSGy6w9hBDQYhtSPb+HaWZNvixrmNBBMrDJdTxoRYGwqBv/zmS/TSlESV3qS8MyTHMNCoFt0ZM5aSP0A00V4nqlOxk2BGlGIFgPjT1XFjha/qOlZuvhTJaSBoarA3jDVbAHPC/1zwBQB782XO2uJJKzv9NDEqh7fv3jjvMEvoXGroL54UoRZPaFgPWja" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=debug msg="completed keyexchange" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=debug msg="completed challenge" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:48:56 deskplayer go-librespot[2840]: time="2026-08-29T10:48:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:48:56 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:48:56 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:48:57 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:48:57.961+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:48072->127.0.0.1:3000: i/o timeout" Aug 29 10:48:58 deskplayer volumio[2754]: info: Starting UPNP Browser Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "alarm-clock"... Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "airplay_emulation"... Aug 29 10:48:58 deskplayer volumio[2754]: info: Starting Shairport Sync Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "last_100"... Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "webradio"... Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "i2s_dacs"... Aug 29 10:48:58 deskplayer volumio[2754]: info: Loading plugin "volumiodiscovery"... Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** For more information see Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 10:48:58 deskplayer volumio[2754]: *** WARNING *** For more information see Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** For more information see Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 10:48:58 deskplayer node[2754]: *** WARNING *** For more information see Aug 29 10:48:58 deskplayer volumio[2754]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 10:48:58 deskplayer volumio[2754]: info: Discovery: Started advertising with name: deskplayer Aug 29 10:48:59 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 10:48:59 deskplayer volumio[2754]: info: Loading plugin "spop"... Aug 29 10:49:00 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 29 10:49:00 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:00 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:00 deskplayer go-librespot[2856]: go-librespot daemon starting... Aug 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+02:00" level=debug msg="app state loaded" Aug 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+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 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+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 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+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 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+02:00" level=info msg="zeroconf server listening on port 36165" Aug 29 10:49:00 deskplayer go-librespot[2857]: time="2026-08-29T10:49:00+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=debug msg="obtained new client token: AAGz2szharR0t6gputI64IumqBoO47de6hgvW96hz4kmxNNzQtjsIbrtBpqwevgBNKSbkCKiWSVovNl2RnL7j+XctQBaf1BAXlTyVqDBI+ovw8lDco0cmKrYPTvB8jlVKr8QSFa+L9Az9sWgRe/5GLzkFCXWmvBXPtxlSVoUSd+HjatILdSBZMmHDfOLdHVmRWy1irQq1qS3hLXDq38XWUSaZCQOnrcuMNixxyuTh/ukX0gcGGK/wA==" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=debug msg="completed challenge" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:01 deskplayer go-librespot[2857]: time="2026-08-29T10:49:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:01 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:01 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:03 deskplayer volumio[2754]: info: Loading plugin "autostart"... Aug 29 10:49:03 deskplayer volumio[2754]: info: Applying required configuration parameters for plugin autostart Aug 29 10:49:03 deskplayer volumio[2754]: info: AutoStart - onVolumioStart - read config.json Aug 29 10:49:03 deskplayer volumio[2754]: info: Loading plugin "outputs"... Aug 29 10:49:03 deskplayer volumio[2754]: info: Loading plugin "albumart"... Aug 29 10:49:04 deskplayer volumio[2754]: info: Plugin example_plugin is not enabled Aug 29 10:49:04 deskplayer volumio[2754]: info: Loading plugin "inputs"... Aug 29 10:49:04 deskplayer volumio[2754]: info: Loading plugin "updater_comm"... Aug 29 10:49:04 deskplayer volumio[2754]: info: Plugin mpdemulation is not enabled Aug 29 10:49:04 deskplayer volumio[2754]: info: Loading plugin "rest_api"... Aug 29 10:49:04 deskplayer volumio[2754]: info: Loading plugin "websocket"... Aug 29 10:49:04 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 29 10:49:04 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:04 deskplayer volumio[2754]: info: Starting Socket.io Server version 1.7.4 Aug 29 10:49:04 deskplayer volumio[2754]: info: Loading plugin "podcast"... Aug 29 10:49:04 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:04 deskplayer go-librespot[2894]: go-librespot daemon starting... Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=debug msg="app state loaded" Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:05 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:49:05.370+02:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+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 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+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 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+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 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=info msg="zeroconf server listening on port 37073" Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:05 deskplayer go-librespot[2895]: time="2026-08-29T10:49:05+02:00" level=debug msg="obtained new client token: AAFEAs4h9Ug6+w9qWeOpV9j1uEzVyoUQvQa2SUKpQbTJHvy94N8Fg8Gxtafl2EUbJkh8YP3/kANdnyjkciNxzSL2SCcvXxlgFpr1BbzkCEGfcVyD3NBiTGoT2K8GOx0iUvGVGeXJHH+Ykk3hxbPmJzeChD4ZdkYGlcE40deNo7Dfg+Um0lXlFoRVNCP/fJl0I0tnYDI7H4APMYQEFgnvB2xL86qr3UsH5dj4fGvLsGsXJCqZ/xnCkKgH" Aug 29 10:49:05 deskplayer volumio[2869]: Forking 3 albumart workers Aug 29 10:49:06 deskplayer volumio[2754]: info: ControllerPodcast::constructor Aug 29 10:49:06 deskplayer go-librespot[2895]: time="2026-08-29T10:49:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:06 deskplayer go-librespot[2895]: time="2026-08-29T10:49:06+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:06 deskplayer go-librespot[2895]: time="2026-08-29T10:49:06+02:00" level=debug msg="completed challenge" Aug 29 10:49:06 deskplayer go-librespot[2895]: time="2026-08-29T10:49:06+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:06 deskplayer pirate_port[1714]: [2026-08-29T08:49:06.439Z] [ERROR] (VolumioClient.js:302) Socket.io connection error: { message: 'timeout' } Aug 29 10:49:06 deskplayer go-librespot[2895]: time="2026-08-29T10:49:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:06 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:06 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:07 deskplayer volumio[2754]: info: Loading plugin "backup_restore"... Aug 29 10:49:08 deskplayer volumio5-onboarding[2314]: time=2026-08-29T10:49:08.964+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:54682->127.0.0.1:3000: i/o timeout" Aug 29 10:49:09 deskplayer volumio-remote-updater[600]: [2026-08-29 10:49:09] [connect] Successful connection Aug 29 10:49:09 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 29 10:49:09 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:09 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:09 deskplayer go-librespot[2937]: go-librespot daemon starting... Aug 29 10:49:09 deskplayer go-librespot[2938]: time="2026-08-29T10:49:09+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:09 deskplayer go-librespot[2938]: time="2026-08-29T10:49:09+02:00" level=debug msg="app state loaded" Aug 29 10:49:10 deskplayer go-librespot[2938]: time="2026-08-29T10:49:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:10 deskplayer volumio[2754]: info: Applying required configuration parameters for plugin backup_restore Aug 29 10:49:10 deskplayer volumio[2754]: info: Loading plugin "pirate_port"... Aug 29 10:49:10 deskplayer volumio[2754]: info: Loading configuration from: /data/configuration/system_hardware/pirate_port/config.json Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+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 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+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 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=info msg="zeroconf server listening on port 39203" Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:11 deskplayer volumio[2754]: info: Configuration loaded successfully. Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=debug msg="obtained new client token: AAFVgFx+k4AO+f8JRVBHo2ruqXhkAblAYwkxO9Iuqg2XDF0dSNAVMGsnDBAMDSDjZ95muR4Mz8RDMoxXva61dDZ7b0xWo5hiLO3Tic9yTqqE7+RG6VrfLRpcpwOiFuhWWpB2xGiCNn/hFxBX6eM6HjuwwH7CSOwFZmHkEVK1nydBUkiRVt/7H0+6ciCkBqS/7Gvn13/Y410EwoRUAS5zhjEJM9iH2gVVTeBy6ybmKSByz/hLyRBaaFJg" Aug 29 10:49:11 deskplayer volumio[2754]: info: Loading i18n strings for locale de Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:11 deskplayer volumio[2754]: Updating browse sources language Aug 29 10:49:11 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=debug msg="completed challenge" Aug 29 10:49:11 deskplayer go-librespot[2938]: time="2026-08-29T10:49:11+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:12 deskplayer go-librespot[2938]: time="2026-08-29T10:49:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:12 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:12 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::initPlayerControls Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 10:49:12 deskplayer volumio[2754]: Express server listening on port 3000 Aug 29 10:49:12 deskplayer volumio[2754]: [Metrics] WebUI: 25s 807.22ms Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreStateMachine::resetVolumioState Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreStateMachine::getcurrentVolume Aug 29 10:49:12 deskplayer volumio[2754]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 10:49:13 deskplayer sudo[2957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 10:49:13 deskplayer sudo[2957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:13 deskplayer sudo[2957]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:13 deskplayer sudo[2959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 10:49:13 deskplayer sudo[2959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:13 deskplayer sudo[2959]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:13 deskplayer volumio[2754]: info: Volumio Network Manager: Network status updated: 2 Aug 29 10:49:13 deskplayer volumio[2754]: info: CoreStateMachine::pushState Aug 29 10:49:13 deskplayer volumio[2907]: Starting albumart workers Aug 29 10:49:13 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:13 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:49:13 deskplayer volumio[2754]: info: CoreCommandRouter::volumioPushState Aug 29 10:49:13 deskplayer volumio[2754]: info: CoreStateMachine::updateTrackBlock Aug 29 10:49:13 deskplayer volumio[2754]: info: CorePlayQueue::getTrackBlock Aug 29 10:49:13 deskplayer volumio[2754]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 10:49:14 deskplayer volumio[2754]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreStateMachine::pushState Aug 29 10:49:14 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreCommandRouter::volumioPushState Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:14 deskplayer volumio[2754]: info: Reloading queue from file Aug 29 10:49:14 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreStateMachine::setRepeat false single undefined Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreStateMachine::pushState Aug 29 10:49:14 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:49:14 deskplayer volumio[2754]: info: CoreCommandRouter::volumioPushState Aug 29 10:49:15 deskplayer volumio[2754]: info: CoreStateMachine::setRandom false Aug 29 10:49:15 deskplayer volumio[2754]: info: CoreStateMachine::pushState Aug 29 10:49:15 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:15 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 10:49:15 deskplayer volumio[2754]: info: CoreCommandRouter::volumioPushState Aug 29 10:49:15 deskplayer volumio[2754]: info: Setting Device type: Raspberry PI Aug 29 10:49:15 deskplayer volumio[2906]: Starting albumart workers Aug 29 10:49:15 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Aug 29 10:49:15 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:15 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:15 deskplayer volumio[2754]: info: Completed loading Core Plugins Aug 29 10:49:15 deskplayer go-librespot[2993]: go-librespot daemon starting... Aug 29 10:49:15 deskplayer go-librespot[2994]: time="2026-08-29T10:49:15+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:15 deskplayer go-librespot[2994]: time="2026-08-29T10:49:15+02:00" level=debug msg="app state loaded" Aug 29 10:49:15 deskplayer volumio[2754]: info: Preparing to generate the ALSA configuration file Aug 29 10:49:15 deskplayer go-librespot[2994]: time="2026-08-29T10:49:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:15 deskplayer volumio[2908]: Starting albumart workers Aug 29 10:49:16 deskplayer volumio[2754]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 29 10:49:16 deskplayer volumio[2754]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 Aug 29 10:49:16 deskplayer volumio[2754]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 29 10:49:16 deskplayer volumio[2754]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 29 10:49:16 deskplayer volumio[2754]: info: Reading ALSA contributions from plugins. Aug 29 10:49:16 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Aug 29 10:49:16 deskplayer go-librespot[2994]: time="2026-08-29T10:49:16+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 29 10:49:16 deskplayer go-librespot[2994]: time="2026-08-29T10:49:16+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 29 10:49:16 deskplayer go-librespot[2994]: time="2026-08-29T10:49:16+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 29 10:49:16 deskplayer go-librespot[2994]: time="2026-08-29T10:49:16+02:00" level=info msg="zeroconf server listening on port 45683" Aug 29 10:49:16 deskplayer volumio[2754]: info: Discovery: adding b39a8fe8-93df-4d7c-9fd4-35b3202c7627 Aug 29 10:49:16 deskplayer volumio[2754]: info: Discovery: Found device deskplayer Aug 29 10:49:16 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:16 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:16 deskplayer go-librespot[2994]: time="2026-08-29T10:49:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:16 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Aug 29 10:49:16 deskplayer sudo[3011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 10:49:16 deskplayer sudo[3011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:16 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Aug 29 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=debug msg="obtained new client token: AAEYrVuyyYPwe+i++4EjZy0E0VYbJQSQ9ALt7dUPJ/YbgEPhxRbqjcQjsMOivKsAQKa2AKvkt6LG/w27ZC/8qWiWPfRdplrViKFcJLiejt7dgwzV3B0GkA5vYe9FMNJmP52kKR9t6m/4MbSRmNLL4kvY4w2Dkt3egXxkkzaOH2PdZd5erFa0/pJA+43uirRb8gRBYcIIoutL1jIRKhqMBbQ9iCkiJsvyjdkU5esr7025IGY1PBdnjM3+" Aug 29 10:49:17 deskplayer volumio[2754]: 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 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=debug msg="completed challenge" Aug 29 10:49:17 deskplayer sudo[3011]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:17 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 10:49:17 deskplayer volumio[2754]: info: Discovery: this is already registered, b39a8fe8-93df-4d7c-9fd4-35b3202c7627 Aug 29 10:49:17 deskplayer volumio[2754]: info: Discovery: Found device deskplayer Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:17 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:17 deskplayer volumio[2754]: info: Upmpdcli Daemon Started Aug 29 10:49:17 deskplayer go-librespot[2994]: time="2026-08-29T10:49:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:17 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:17 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:17 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:17 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 10:49:17 deskplayer volumio[2754]: info: Received Get System Info Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 10:49:17 deskplayer volumio[2754]: info: Discovery: Getting this device information Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:17 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 10:49:17 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:17 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:17 deskplayer volumio[2754]: info: Listing playlists Aug 29 10:49:18 deskplayer volumio[2754]: 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: 8 Aug 29 10:49:18 deskplayer volumio[2754]: verbose: New Socket.io Connection to 192.168.1.181 from 192.168.1.210 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 29 10:49:18 deskplayer volumio[2754]: info: Asound.conf file unchanged, so no further update is needed Aug 29 10:49:18 deskplayer volumio[2754]: info: Output device has changed, restarting MPD Aug 29 10:49:18 deskplayer volumio[2754]: info: Output device has changed, restarting Shairport Sync Aug 29 10:49:18 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:18 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:18 deskplayer sudo[3024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 10:49:18 deskplayer sudo[3024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:18 deskplayer sudo[3022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 10:49:18 deskplayer sudo[3022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:18 deskplayer volumio[2754]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 10:49:18 deskplayer volumio[2754]: info: ___________ START PLUGINS ___________ Aug 29 10:49:18 deskplayer sudo[3022]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:18 deskplayer systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 29 10:49:18 deskplayer volumio[2754]: info: ControllerMpd::onStart: Initializing MPD Aug 29 10:49:18 deskplayer volumio[2754]: info: Creating MPD Configuration file Aug 29 10:49:18 deskplayer sudo[3037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 10:49:18 deskplayer sudo[3037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:18 deskplayer sudo[3037]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:18 deskplayer sudo[3040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 10:49:18 deskplayer sudo[3040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:18 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 10:49:18 deskplayer volumio[2754]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 10:49:18 deskplayer volumio[2754]: info: [1787993358774] CoreMusicLibrary::Adding element Medienserver Aug 29 10:49:18 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:18 deskplayer sudo[3040]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:18 deskplayer volumio[2754]: info: UPNP Browser: Client initialized successfully Aug 29 10:49:18 deskplayer sudo[3043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 10:49:18 deskplayer sudo[3043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:19 deskplayer volumio[2754]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:19 deskplayer volumio[2754]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 10:49:19 deskplayer volumio[2754]: info: [1787993359430] CoreMusicLibrary::Adding element Last_100 Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 10:49:19 deskplayer volumio[2754]: info: [1787993359435] CoreMusicLibrary::Adding element Webradio Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 10:49:19 deskplayer volumio[2754]: info: Initializing BBC Radios Aug 29 10:49:19 deskplayer volumio[2754]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 10:49:19 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:20 deskplayer volumio[2754]: info: Creating Spotify config file Aug 29 10:49:20 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:20 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Aug 29 10:49:20 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:20 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:20 deskplayer go-librespot[3071]: go-librespot daemon starting... Aug 29 10:49:21 deskplayer go-librespot[3072]: time="2026-08-29T10:49:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:22 deskplayer volumio[2754]: info: AutoStart - onStart - waiting for system ready state Aug 29 10:49:22 deskplayer volumio[2754]: info: AutoStart - Polling config: interval=5000ms, maxAttempts=60 Aug 29 10:49:22 deskplayer volumio[2754]: info: AutoStart - Maximum wait time: 300 seconds Aug 29 10:49:22 deskplayer volumio[2754]: info: AutoStart - Startup volume enabled, level=50 Aug 29 10:49:22 deskplayer volumio[2754]: info: AutoStart - Check #1/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 10:49:23 deskplayer go-librespot[3072]: time="2026-08-29T10:49:23+02:00" level=info msg="zeroconf server listening on port 39709" Aug 29 10:49:23 deskplayer go-librespot[3072]: time="2026-08-29T10:49:23+02:00" level=info msg="using built-in mDNS responder" Aug 29 10:49:23 deskplayer volumio[2754]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 10:49:23 deskplayer volumio[2754]: info: [1787993363121] CoreMusicLibrary::Adding element Podcast Aug 29 10:49:23 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:23 deskplayer volumio[2754]: Cannot find translation for source Podcast Aug 29 10:49:23 deskplayer volumio[2754]: info: Cannot retrieve data for calling home Aug 29 10:49:23 deskplayer sudo[3087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start pirate_port.service Aug 29 10:49:23 deskplayer sudo[3087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:23 deskplayer sudo[3087]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:24 deskplayer volumio-remote-updater[600]: [2026-08-29 10:49:24] [connect] Successful connection Aug 29 10:49:25 deskplayer volumio[2754]: 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: 9 Aug 29 10:49:26 deskplayer volumio[2754]: info: pirate_port service started Aug 29 10:49:26 deskplayer volumio[2754]: info: MPD Permissions set Aug 29 10:49:26 deskplayer volumio[2754]: info: MPD Permissions set Aug 29 10:49:26 deskplayer volumio[2754]: 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: 9 Aug 29 10:49:27 deskplayer volumio[2754]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 29 10:49:27 deskplayer volumio[2754]: info: Spotify config file written Aug 29 10:49:27 deskplayer volumio[2754]: 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: 11 Aug 29 10:49:27 deskplayer volumio-remote-updater[600]: [2026-08-29 10:49:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1787993364 101 Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer sudo[3109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 10:49:27 deskplayer sudo[3109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 10:49:27 deskplayer systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 10:49:27 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:27 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 10:49:27 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 10:49:27 deskplayer go-librespot[3121]: go-librespot daemon starting... Aug 29 10:49:27 deskplayer sudo[3109]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:27 deskplayer volumio[2754]: info: No need to fix Spotify hosts Aug 29 10:49:27 deskplayer go-librespot[3124]: time="2026-08-29T10:49:27+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:27 deskplayer go-librespot[3124]: time="2026-08-29T10:49:27+02:00" level=debug msg="app state loaded" Aug 29 10:49:28 deskplayer go-librespot[3124]: time="2026-08-29T10:49:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:28 deskplayer volumio[2754]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Aug 29 10:49:28 deskplayer volumio[2754]: info: AutoStart - Check #2/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 10:49:28 deskplayer volumio[2754]: info: New Spotify access tokenBQDwViHTK1... Aug 29 10:49:28 deskplayer volumio[2754]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 10:49:29 deskplayer systemd[1]: mpd.service: Deactivated successfully. Aug 29 10:49:29 deskplayer systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 10:49:29 deskplayer systemd[1]: mpd.service: Consumed 12.942s CPU time. Aug 29 10:49:29 deskplayer systemd[1]: mpd.socket: Deactivated successfully. Aug 29 10:49:29 deskplayer systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 10:49:29 deskplayer systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 10:49:29 deskplayer systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 10:49:29 deskplayer systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+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 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+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 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+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 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+02:00" level=info msg="zeroconf server listening on port 40495" Aug 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:29 deskplayer go-librespot[3124]: time="2026-08-29T10:49:29+02:00" level=debug msg="obtained new client token: AAGPI8AzQoL+11ZI8B1e8GTRvFrdLyv0kmqoRVBVPz5iAECV8HhgJtNWNFAiO0/8035pOobzguJdeNgzRsxqlYFakkGdhnLMCXWvQ3WTY55cBSRcNvhmJOkMVCzlCWP3uSWsiKDkHbg9Dc7NQtlJTWzBIgr9szH/vmYqQbKKztZJCOJmnUlSAEtbFiQv40IBhXyQInV8RsZ0wrkLcZrFXKJBqc4SY7oJIBxMy0wUkMvpF1TZUb6q9Tsk" Aug 29 10:49:30 deskplayer go-librespot[3124]: time="2026-08-29T10:49:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:30 deskplayer volumio[2754]: info: Starting Shairport Sync Aug 29 10:49:30 deskplayer go-librespot[3124]: time="2026-08-29T10:49:30+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:30 deskplayer go-librespot[3124]: time="2026-08-29T10:49:30+02:00" level=debug msg="completed challenge" Aug 29 10:49:30 deskplayer volumio[2754]: info: Starting Shairport Sync Aug 29 10:49:30 deskplayer go-librespot[3124]: time="2026-08-29T10:49:30+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:30 deskplayer volumio[2754]: info: Starting Shairport Sync Aug 29 10:49:30 deskplayer sudo[3144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 10:49:30 deskplayer sudo[3144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:30 deskplayer sudo[3141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 10:49:30 deskplayer sudo[3142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 10:49:30 deskplayer systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 10:49:30 deskplayer systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 10:49:30 deskplayer sudo[3142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:30 deskplayer systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 10:49:30 deskplayer sudo[3137]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 10:49:30 deskplayer systemd[1]: shairport-sync.service: Consumed 2.201s CPU time. Aug 29 10:49:30 deskplayer sudo[3141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:30 deskplayer go-librespot[3124]: time="2026-08-29T10:49:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:30 deskplayer systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 10:49:30 deskplayer sudo[3137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 10:49:30 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:30 deskplayer sudo[3144]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:30 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:30 deskplayer systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 10:49:30 deskplayer systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 10:49:30 deskplayer systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 10:49:30 deskplayer systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 10:49:30 deskplayer sudo[3142]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:30 deskplayer sudo[3137]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:30 deskplayer sudo[3141]: pam_unix(sudo:session): session closed for user root Aug 29 10:49:30 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:30 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:30 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:30 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:30 deskplayer volumio[2754]: info: Shairport-Sync Started Aug 29 10:49:30 deskplayer volumio[2754]: Error adding Membership: Error: addMembership EINVAL Aug 29 10:49:30 deskplayer volumio[2754]: info: Shairport-Sync Started Aug 29 10:49:30 deskplayer volumio[2754]: info: Shairport-Sync Started Aug 29 10:49:31 deskplayer volumio[2754]: info: CoreCommandRouter::volumioGetState Aug 29 10:49:31 deskplayer volumio[2754]: info: CorePlayQueue::getTrack 0 Aug 29 10:49:31 deskplayer volumio[2754]: SPOTIFY: User informations: {"account_id":"w8s8Q2MOh8","country":"AT","display_name":"stekst","email":"herbert.geier@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/stekst"},"followers":{"href":null,"total":6},"href":"https://api.spotify.com/v1/users/stekst","id":"stekst","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464925005_8906164299408226_6672725636641885714_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=107&ccb=1-7&_nc_sid=08baa4&_nc_ohc=96nGI65eMcAQ7kNvwENnyZo&_nc_oc=AdoldEbb-ua5P-D6nxgKiLChrTUlP6ILm-lEgVWWdFLjHcDzrYE-nVxL2O5bEJrbiD4nf2dy2iiz-ZFn0Vti6dWx&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=KCaRNhDEv1glM_ildpa08Q&_nc_tpa=Q5bMBQKIchRIgJMJWGNyK7FtNsfI7ph3yOzbyRXnn1AX4c45RQpDuuDBVfTRVO0kx-DsNf4rnVXQ&oh=00_AQLOjPCFOXIwOYj1gmAiWI3Gf70YGsDn9avAIMjnWaAwiQ&oe=6A98552B","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464925005_8906164299408226_6672725636641885714_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=107&ccb=1-7&_nc_sid=28885b&_nc_ohc=96nGI65eMcAQ7kNvwENnyZo&_nc_oc=AdoldEbb-ua5P-D6nxgKiLChrTUlP6ILm-lEgVWWdFLjHcDzrYE-nVxL2O5bEJrbiD4nf2dy2iiz-ZFn0Vti6dWx&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=KCaRNhDEv1glM_ildpa08Q&_nc_tpa=Q5bMBQL6qk9gu451O7W253LfRCsfBhGt-YaQswl0ee3SBsLRhPECgzghpeILKByqIwoevGZaCL_Y&oh=00_AQL_qTx_tHYJQse2WKpWlYTEL8j6ieCvhtxHjNHC-znbcw&oe=6A98552B","width":64}],"product":"premium","type":"user","uri":"spotify:user:stekst"} Aug 29 10:49:31 deskplayer volumio[2754]: info: Spotify Successfully logged in Aug 29 10:49:31 deskplayer volumio[2754]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 10:49:31 deskplayer volumio[2754]: info: [1787993371124] CoreMusicLibrary::Adding element Spotify Aug 29 10:49:31 deskplayer volumio[2754]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 10:49:31 deskplayer volumio[2754]: Cannot find translation for source Podcast Aug 29 10:49:31 deskplayer volumio[2754]: Cannot find translation for source Spotify Aug 29 10:49:31 deskplayer pirate_port[1714]: [2026-08-29T08:49:31.904Z] [ERROR] (IconGenerator.js:426) Failed to create icon 'ok': Unknown icon type: ok Aug 29 10:49:31 deskplayer pirate_port[1714]: [2026-08-29T08:49:31.923Z] [ERROR] (ScreenRenderer.js:2104) showInfoScreen failed: Unknown icon type: ok Aug 29 10:49:32 deskplayer volumio[2754]: info: go-librespot daemon successfully initialized Aug 29 10:49:33 deskplayer volumio[2754]: info: AutoStart - Check #3/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 10:49:33 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 10:49:33 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:33 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:33 deskplayer go-librespot[3181]: go-librespot daemon starting... Aug 29 10:49:34 deskplayer go-librespot[3182]: time="2026-08-29T10:49:34+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:34 deskplayer go-librespot[3182]: time="2026-08-29T10:49:34+02:00" level=debug msg="app state loaded" Aug 29 10:49:34 deskplayer go-librespot[3182]: time="2026-08-29T10:49:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+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 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+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 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+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 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=info msg="zeroconf server listening on port 36831" Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:35 deskplayer volumio[2754]: info: Initializing connection to go-librespot Websocket Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=debug msg="obtained new client token: AAGNyncv9bk880g3aD1dTpyQCNyKz3ms/RkyxLrK+G/DmQi+vteBUDicqgYMQ5+AJmAaEmXRB/lZmrMfRA1yS6lYC5mlQxN+LNeN80cINmebXKtJ4HvyRbYaF/bkxLMl1y/2cQ4VuCBGBGVnXRuCPKuxpA0henO6QfebhNV7xxp3peVfAfTZMiy11qS2QGbouaca5FFETv789mEzMXEx9SvC2ioKzCNtrZmX+mj0b+dwj3EJv19YlzDv" Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=debug msg="new websocket client" Aug 29 10:49:35 deskplayer volumio[2754]: info: Connection to go-librespot Websocket established Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:35 deskplayer go-librespot[3182]: time="2026-08-29T10:49:35+02:00" level=debug msg="completed challenge" Aug 29 10:49:36 deskplayer go-librespot[3182]: time="2026-08-29T10:49:36+02:00" level=info msg="authenticated AP" username="st**st" Aug 29 10:49:36 deskplayer go-librespot[3182]: time="2026-08-29T10:49:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 10:49:36 deskplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 10:49:36 deskplayer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 10:49:36 deskplayer volumio[2754]: info: Connection to go-librespot Websocket closed Aug 29 10:49:38 deskplayer volumio[2754]: info: AutoStart - Check #4/60 - VOLUMIO_SYSTEM_STATUS = starting Aug 29 10:49:38 deskplayer volumio[2754]: info: Getting Spotify volume Aug 29 10:49:39 deskplayer volumio[2754]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 10:49:39 deskplayer volumio[2754]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 10:49:39 deskplayer volumio[2754]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 10:49:39 deskplayer volumio[2754]: errno: -111, Aug 29 10:49:39 deskplayer volumio[2754]: code: 'ECONNREFUSED', Aug 29 10:49:39 deskplayer volumio[2754]: syscall: 'connect', Aug 29 10:49:39 deskplayer volumio[2754]: address: '127.0.0.1', Aug 29 10:49:39 deskplayer volumio[2754]: port: 9879, Aug 29 10:49:39 deskplayer volumio[2754]: response: undefined Aug 29 10:49:39 deskplayer volumio[2754]: } Aug 29 10:49:39 deskplayer volumio[2754]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 10:49:39 deskplayer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 10:49:39 deskplayer systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:39 deskplayer systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 10:49:39 deskplayer go-librespot[3218]: go-librespot daemon starting... Aug 29 10:49:39 deskplayer go-librespot[3219]: time="2026-08-29T10:49:39+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 10:49:39 deskplayer go-librespot[3219]: time="2026-08-29T10:49:39+02:00" level=debug msg="app state loaded" Aug 29 10:49:39 deskplayer go-librespot[3219]: time="2026-08-29T10:49:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+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 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+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 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+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 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=info msg="zeroconf server listening on port 44575" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 10:49:40 deskplayer sudo[3230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 10:48' Aug 29 10:49:40 deskplayer sudo[3230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=debug msg="obtained new client token: AAFocjbONDDwb/NeRBpkG4Lj4C18aBCudWpCWSMm1eanARq7REdFQ+7C9FHdCDUL/n9q2BvGKIN8b3b3OtbIpPFBSDfjyjpQXM6tr6UK5OuwaZA8zuwgJacJgnXLqCRcMOCyrsm1shosTYt8T6lQTB2dfJFuU9JXmUws2C52Uqx0UX87Hz7pLz4UdozgWPGr1wla6qn3ARNNCNIE/oIWQo+fLRUnE6l16GeE6WID4zFm8lOsY8wF59y+" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=debug msg="completed keyexchange" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=debug msg="completed challenge" Aug 29 10:49:40 deskplayer go-librespot[3219]: time="2026-08-29T10:49:40+02:00" level=info msg="authenticated AP" username="st**st" 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"