Aug 29 22:43:04 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:04 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:05 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:05 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:08 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:08 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:24 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:24 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:25 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:25 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:28 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:28 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:39 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:39 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:47 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:47.612+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s Aug 29 22:43:48 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:48 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:49 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:49 volumio volumio[1140]: info: Listing playlists Aug 29 22:43:49 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:49.905+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=http://pushupdates.volumio.org duration=2.291512595s Aug 29 22:43:50 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:50.847+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=3.235042517s Aug 29 22:43:50 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:50.852+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=3.236184804s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.813+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://www.googleapis.com duration=4.200980209s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.814+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=4.197921264s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.814+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://securetoken.googleapis.com duration=4.200649169s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.815+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://database.volumio.cloud duration=4.20224312s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.815+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=4.201332135s Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.817+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://functions.volumio.cloud duration=4.2042278s Aug 29 22:43:51 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 22:43:51 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:51.819+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://functions.volumio.cloud duration=4.203738114s Aug 29 22:43:51 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 22:43:51 volumio volumio[1140]: info: Discovery: Getting this device information Aug 29 22:43:51 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:51 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:43:51 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 22:43:52 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:52.774+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=http://cddb.volumio.org duration=5.15922533s Aug 29 22:43:52 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:52.775+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=http://plugins.volumio.org duration=5.160863552s Aug 29 22:43:52 volumio volumio[1140]: verbose: New Socket.io Connection to 192.168.1.216:3000 from 192.168.1.201 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Aug 29 22:43:52 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 22:43:52 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 22:43:54 volumio volumio5-onboarding[1494]: time=2026-08-29T22:43:54.712+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" latency=145.386967ms timeout=10s endpoint=https://google.com duration=7.10013781s Aug 29 22:43:57 volumio volumio[1140]: info: Received OAUTH Data Aug 29 22:43:57 volumio volumio[1140]: info: Executing Spotify Oauth Login Aug 29 22:43:57 volumio volumio[1140]: info: Saving Spotify Refresh Token Aug 29 22:43:57 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:43:57 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:44:00 volumio volumio[1140]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 22:44:00 volumio volumio[1140]: SPOTIFY: BQAAJGooM7sHfnCCtAE8Fp0he9dfJ2JsseMJFT6h8lOpZRDMkUNb6kMrChFGmQBzMxW2rMExwGfA0XzhrTkmonVRfPzdhWCacwq_vb0ehPiFnXs98H_dtMC8Lbq5n3OiFf4mS6d6hsZhNfys5OfYyDi_ZPA8mqH3SdAthVa43cy5GlKLd8FB6wUKbLV7mXvtmFsnAaliKJqZY429Yu0--qDTBUvUGyfq4ISQ2fPwh7VJcPZ-F_6TZq8P7Nd-oxhNiqaZh861f2Ca7ACwXnB6J8ez0jD2_uMEeKdIBn2PZ3Ot8cgdsj2ax-3mKqo Aug 29 22:44:00 volumio volumio[1140]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 22:44:00 volumio volumio[1140]: info: New Spotify access token = BQAAJGooM7sHfnCCtAE8Fp0he9dfJ2JsseMJFT6h8lOpZRDMkUNb6kMrChFGmQBzMxW2rMExwGfA0XzhrTkmonVRfPzdhWCacwq_vb0ehPiFnXs98H_dtMC8Lbq5n3OiFf4mS6d6hsZhNfys5OfYyDi_ZPA8mqH3SdAthVa43cy5GlKLd8FB6wUKbLV7mXvtmFsnAaliKJqZY429Yu0--qDTBUvUGyfq4ISQ2fPwh7VJcPZ-F_6TZq8P7Nd-oxhNiqaZh861f2Ca7ACwXnB6J8ez0jD2_uMEeKdIBn2PZ3Ot8cgdsj2ax-3mKqo Aug 29 22:44:00 volumio volumio[1140]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 22:44:01 volumio sudo[28308]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 22:44:01 volumio sudo[28308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:44:01 volumio sudo[28308]: pam_unix(sudo:session): session closed for user root Aug 29 22:44:01 volumio sudo[28310]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 22:44:01 volumio sudo[28310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:44:01 volumio sudo[28310]: pam_unix(sudo:session): session closed for user root Aug 29 22:44:01 volumio volumio[1140]: verbose: New Socket.io Connection to 192.168.1.216 from 192.168.1.201 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:44:01 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 22:44:01 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 22:44:03 volumio volumio[1140]: info: Aug 29 22:44:03 volumio volumio[1140]: ---------------------------- MPD announces state update: player Aug 29 22:44:03 volumio volumio[1140]: info: ControllerMpd::getState Aug 29 22:44:03 volumio volumio[1140]: verbose: ControllerMpd::sendMpdCommand status Aug 29 22:44:03 volumio volumio[1140]: error: MPD returned error for command status: Failed to open audio output Aug 29 22:44:03 volumio volumio[1140]: verbose: ControllerMpd::sendMpdCommand clearerror Aug 29 22:44:03 volumio volumio[1140]: info: sendMpdCommand status took 7 milliseconds Aug 29 22:44:03 volumio volumio[1140]: verbose: ControllerMpd::parseState Aug 29 22:44:03 volumio volumio[1140]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 22:44:03 volumio volumio[1140]: info: sendMpdCommand clearerror took 8 milliseconds Aug 29 22:44:03 volumio volumio[1140]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 29 22:44:03 volumio volumio[1140]: verbose: ControllerMpd::parseTrackInfo Aug 29 22:44:03 volumio volumio[1140]: info: ControllerMpd::pushState Aug 29 22:44:03 volumio volumio[1140]: info: CoreCommandRouter::servicePushState Aug 29 22:44:03 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:44:03 volumio volumio[1140]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":107954,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"791 Kbps","isStreaming":false,"title":"A Song for You","artist":"Andy Williams","album":"Andy Williams' Greatest Hits, Vol. 2","uri":"NAS/Media/Music/Andy Williams/Andy Williams' Greatest Hits, Vol. 2/11 Andy Williams - A Song for You.flac","trackType":"flac"} Aug 29 22:44:03 volumio volumio[1140]: verbose: CURRENT POSITION 10 Aug 29 22:44:03 volumio volumio[1140]: info: CoreStateMachine::syncState stateService pause Aug 29 22:44:03 volumio volumio[1140]: info: CoreStateMachine::syncState currentStatus play Aug 29 22:44:03 volumio volumio[1140]: info: CoreStateMachine::pushState Aug 29 22:44:03 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:44:03 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 22:44:03 volumio volumio[1140]: info: CoreCommandRouter::volumioPushState Aug 29 22:44:03 volumio volumio[1140]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 22:44:03 volumio volumio5-onboarding[1494]: time=2026-08-29T22:44:03.424+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" state=STATUS_PLAYING positionMs=108049 volume=100 Aug 29 22:44:03 volumio volumio5-onboarding[1494]: time=2026-08-29T22:44:03.425+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.201:54941,00:00:00:00:00:00%06 @ 0x1c660c0" id="mnt/NAS/Media/Music/Andy Williams/Andy Williams' Greatest Hits, Vol. 2/11 Andy Williams - A Song for You.flac" title="A Song for You" Aug 29 22:44:03 volumio volumio[1140]: info: ------------------------------ 31ms Aug 29 22:44:03 volumio volumio[1140]: SPOTIFY: User informations: {"account_id":"Hr75x6mOHF","country":"ZA","display_name":"Wizard$123","email":"lyndonownhouse@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/e41xi49c91p98txhookh6jdm1"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/e41xi49c91p98txhookh6jdm1","id":"e41xi49c91p98txhookh6jdm1","images":[],"product":"premium","type":"user","uri":"spotify:user:e41xi49c91p98txhookh6jdm1"} Aug 29 22:44:03 volumio volumio[1140]: info: Creating Spotify config file Aug 29 22:44:03 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 22:44:03 volumio volumio[1140]: info: Spotify config file written Aug 29 22:44:03 volumio sudo[28329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 22:44:03 volumio sudo[28329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 22:44:03 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 22:44:03 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 22:44:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 22:44:03 volumio go-librespot[28331]: go-librespot daemon starting... Aug 29 22:44:03 volumio sudo[28329]: pam_unix(sudo:session): session closed for user root Aug 29 22:44:03 volumio go-librespot[28332]: time="2026-08-29T22:44:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 22:44:03 volumio go-librespot[28332]: time="2026-08-29T22:44:03+02:00" level=debug msg="app state loaded" Aug 29 22:44:03 volumio go-librespot[28332]: time="2026-08-29T22:44:03+02:00" level=debug msg="stored credentials not found" Aug 29 22:44:03 volumio go-librespot[28332]: time="2026-08-29T22:44:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 22:44:03 volumio volumio[1140]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 22:44:03 volumio volumio[1140]: SPOTIFY: BQBFGjxKBMv7nKz4lF7AhdsCKi8M89t4XbNvqOjwPNnPKhqWyiLtZpK2BWeqC9-nhqvk5n8PUYvm8WHex6LUIrsb8_lquNPXZHx8TnSM-8tXQzDLPVMY0papBhv6coEyFDe9Z8insnzMGQOrP7oEDbgOTvZHsNh7rJdo9kvt9NbjFPh0W9sGAN0Jnp_YgrZPm927qLcO2P8CjDB0Bn3jMt8nrGIKkLjWZziC-qR8cFLSA5JTx3j629TrSpnSGTgYUxfCoozn6Tladzs2BYH0Ul0vkjkMlc9_bSZj0qe9uSrbnhYWE3FxDy8HLxk Aug 29 22:44:03 volumio volumio[1140]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 22:44:03 volumio volumio[1140]: info: New Spotify access token = BQBFGjxKBMv7nKz4lF7AhdsCKi8M89t4XbNvqOjwPNnPKhqWyiLtZpK2BWeqC9-nhqvk5n8PUYvm8WHex6LUIrsb8_lquNPXZHx8TnSM-8tXQzDLPVMY0papBhv6coEyFDe9Z8insnzMGQOrP7oEDbgOTvZHsNh7rJdo9kvt9NbjFPh0W9sGAN0Jnp_YgrZPm927qLcO2P8CjDB0Bn3jMt8nrGIKkLjWZziC-qR8cFLSA5JTx3j629TrSpnSGTgYUxfCoozn6Tladzs2BYH0Ul0vkjkMlc9_bSZj0qe9uSrbnhYWE3FxDy8HLxk Aug 29 22:44:03 volumio volumio[1140]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=info msg="zeroconf server listening on port 42739" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 22:44:04 volumio volumio[1140]: SPOTIFY: User informations: {"account_id":"Hr75x6mOHF","country":"ZA","display_name":"Wizard$123","email":"lyndonownhouse@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/e41xi49c91p98txhookh6jdm1"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/e41xi49c91p98txhookh6jdm1","id":"e41xi49c91p98txhookh6jdm1","images":[],"product":"premium","type":"user","uri":"spotify:user:e41xi49c91p98txhookh6jdm1"} Aug 29 22:44:04 volumio volumio[1140]: info: Spotify Successfully logged in Aug 29 22:44:04 volumio volumio[1140]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 22:44:04 volumio volumio[1140]: info: [1788036244227] CoreMusicLibrary::Adding element Spotify Aug 29 22:44:04 volumio volumio[1140]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 22:44:04 volumio volumio[1140]: Cannot find translation for source Spotify Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="obtained new client token: AAHRwzd8YIs8X/zGhaqy1PEzBUfYWb/cuKeOCfXNWkmtr5Xjf7ofXXxioJbwr7t8C3JAoelVZU08gd8ef0DY900SzGynnwxGMrrS6pYOFy/cKVyo62esaTygEuSK1PTQOmkWS+zCT24LsJmG5dc4HBQm5LDGV0U3jMlsL3/7VP6Xy2fQRrdldCXk8IvVZXZWl1qt4wvnu8o7qr3ICXilmAFHweAPy9nm9ouZS6tUKzRynvNUmA89LjrWmQ==" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="completed keyexchange" Aug 29 22:44:04 volumio go-librespot[28332]: time="2026-08-29T22:44:04+02:00" level=debug msg="completed challenge" Aug 29 22:44:05 volumio go-librespot[28332]: time="2026-08-29T22:44:05+02:00" level=info msg="authenticated AP" username="e4*********************m1" Aug 29 22:44:05 volumio go-librespot[28332]: time="2026-08-29T22:44:05+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 22:44:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 22:44:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 22:44:06 volumio volumio[1140]: info: go-librespot daemon successfully initialized Aug 29 22:44:07 volumio volumio[1140]: info: CoreCommandRouter::volumioGetState Aug 29 22:44:07 volumio volumio[1140]: info: CorePlayQueue::getTrack 10 Aug 29 22:44:07 volumio volumio[1140]: info: Listing playlists Aug 29 22:44:07 volumio volumio[1140]: info: Listing playlists Aug 29 22:44:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 22:44:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 22:44:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 22:44:08 volumio go-librespot[28343]: go-librespot daemon starting... Aug 29 22:44:08 volumio go-librespot[28344]: time="2026-08-29T22:44:08+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 22:44:08 volumio go-librespot[28344]: time="2026-08-29T22:44:08+02:00" level=debug msg="app state loaded" Aug 29 22:44:08 volumio go-librespot[28344]: time="2026-08-29T22:44:08+02:00" level=debug msg="stored credentials not found" Aug 29 22:44:08 volumio go-librespot[28344]: time="2026-08-29T22:44:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=info msg="zeroconf server listening on port 32919" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="obtained new client token: AAEbYXsx3FeFamjeU/NB/zRlGi1mjVU/6QVls8f4K09D+ncCOF+sEIYgIUd+JbgAaVnaGI/dAUBwsfTbFm30JQBBPDO519A9XHZ9WmEYdMa2c9ga1ThWVQQiQvRBrs7U7nzUrshkx9Sk7K3p4AWqUOppZoX+SdMP+Yqw7qfZ7jOYh8xU4AUoxFhNiusyPjrLpSR/3ibwq+GckKx7HWGdZbiu54pnRYypJv+VMEqbL39Nx3j7vdI6rViU/A==" Aug 29 22:44:09 volumio volumio[1140]: info: Initializing connection to go-librespot Websocket Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="new websocket client" Aug 29 22:44:09 volumio volumio[1140]: info: Connection to go-librespot Websocket established Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="completed keyexchange" Aug 29 22:44:09 volumio go-librespot[28344]: time="2026-08-29T22:44:09+02:00" level=debug msg="completed challenge" Aug 29 22:44:10 volumio go-librespot[28344]: time="2026-08-29T22:44:10+02:00" level=info msg="authenticated AP" username="e4*********************m1" Aug 29 22:44:10 volumio go-librespot[28344]: time="2026-08-29T22:44:10+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 22:44:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 22:44:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 22:44:10 volumio volumio[1140]: info: Connection to go-librespot Websocket closed Aug 29 22:44:12 volumio volumio[1140]: info: Getting Spotify volume Aug 29 22:44:12 volumio volumio[1140]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 22:44:12 volumio volumio[1140]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 22:44:12 volumio volumio[1140]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 22:44:12 volumio volumio[1140]: errno: -111, Aug 29 22:44:12 volumio volumio[1140]: code: 'ECONNREFUSED', Aug 29 22:44:12 volumio volumio[1140]: syscall: 'connect', Aug 29 22:44:12 volumio volumio[1140]: address: '127.0.0.1', Aug 29 22:44:12 volumio volumio[1140]: port: 9879, Aug 29 22:44:12 volumio volumio[1140]: response: undefined Aug 29 22:44:12 volumio volumio[1140]: } Aug 29 22:44:12 volumio volumio[1140]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 22:44:13 volumio sudo[28381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 22:43' Aug 29 22:44:13 volumio sudo[28381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"