Jan 27 10:35:20 volumio volumio[1295]: verbose: New Socket.io Connection to 192.168.1.49:3000 from 192.168.1.41 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 27 10:35:20 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:35:20 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:35:20 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:35:20 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:35:20 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:35:20 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:35:21 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:35:21 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:35:21 volumio volumio[1295]: verbose: New Socket.io Connection to 192.168.1.49:3000 from 192.168.1.41 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:35:21 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:35:21 volumio wpa_supplicant[1225]: TDLS: Creating peer entry for c6:14:fa:c4:4d:f8 Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:35:23 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:35:23 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:35:23 volumio volumio[1295]: verbose: New Socket.io Connection to 192.168.1.49:3000 from 192.168.1.41 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 27 10:35:23 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 27 10:35:44 volumio systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Jan 27 10:35:44 volumio systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Jan 27 10:35:44 volumio systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Jan 27 10:35:44 volumio systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Jan 27 10:36:30 volumio volumio[1295]: info: Received OAUTH Data Jan 27 10:36:30 volumio volumio[1295]: info: Executing Spotify Oauth Login Jan 27 10:36:30 volumio volumio[1295]: info: Saving Spotify Refresh Token Jan 27 10:36:30 volumio volumio[1295]: info: New Spotify access tokenBQCxAnawbR... Jan 27 10:36:30 volumio volumio[1295]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 10:36:30 volumio sudo[4375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 10:36:30 volumio sudo[4375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:30 volumio sudo[4375]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:30 volumio sudo[4377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 10:36:30 volumio sudo[4377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:30 volumio sudo[4377]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:30 volumio volumio[1295]: SPOTIFY: User informations: {"country":"KZ","display_name":"Terranouf","email":"terranouf@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/o0ycq3q2ceuag4kvqlf2dvb0c"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/o0ycq3q2ceuag4kvqlf2dvb0c","id":"o0ycq3q2ceuag4kvqlf2dvb0c","images":[],"product":"free","type":"user","uri":"spotify:user:o0ycq3q2ceuag4kvqlf2dvb0c"} Jan 27 10:36:30 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:30 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:30 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:31 volumio sudo[4381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:31 volumio sudo[4381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:31 volumio systemd[1]: go-librespot-daemon.service: Killing process 4065 (go-librespot) with signal SIGKILL. Jan 27 10:36:31 volumio volumio[1295]: verbose: New Socket.io Connection to 192.168.1.49 from 192.168.1.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 27 10:36:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:31 volumio volumio[1295]: info: Connection to go-librespot Websocket closed Jan 27 10:36:31 volumio volumio[1295]: info: Connection to go-librespot Websocket closed Jan 27 10:36:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:31 volumio sudo[4381]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:31 volumio go-librespot[4383]: go-librespot daemon starting... Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=debug msg="app state loaded" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=debug msg="stored credentials not found" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 10:36:31 volumio volumio[1295]: info: New Spotify access tokenBQAir_0qHA... Jan 27 10:36:31 volumio volumio[1295]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::volumioGetVisibleSources Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:31 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 27 10:36:31 volumio volumio[1295]: info: Received Get System Info Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:36:31 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:31 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:31 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:31 volumio volumio[1295]: info: Listing playlists Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06: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]" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06: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]" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06: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]" Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=info msg="zeroconf server listening on port 46087" Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 27 10:36:31 volumio volumio[1295]: SPOTIFY: User informations: {"country":"KZ","display_name":"Terranouf","email":"terranouf@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/o0ycq3q2ceuag4kvqlf2dvb0c"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/o0ycq3q2ceuag4kvqlf2dvb0c","id":"o0ycq3q2ceuag4kvqlf2dvb0c","images":[],"product":"free","type":"user","uri":"spotify:user:o0ycq3q2ceuag4kvqlf2dvb0c"} Jan 27 10:36:31 volumio volumio[1295]: info: Spotify Successfully logged in Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 10:36:31 volumio volumio[1295]: info: [1769531791825] CoreMusicLibrary::Adding element Spotify Jan 27 10:36:31 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 10:36:31 volumio volumio[1295]: Cannot find translation for source Calm Radio Jan 27 10:36:31 volumio volumio[1295]: Cannot find translation for source 80s80s Radio Jan 27 10:36:31 volumio volumio[1295]: Cannot find translation for source Radio Paradise Jan 27 10:36:31 volumio volumio[1295]: Cannot find translation for source YouTube Music Jan 27 10:36:31 volumio volumio[1295]: Cannot find translation for source Spotify Jan 27 10:36:31 volumio go-librespot[4385]: time="2026-01-27T10:36:31-06:00" level=debug msg="obtained new client token: AADG3uCll/YK1YzfzzClL5ood9X/Zl80Dfm1ZTBdJnt/1gGw4IkFwgrQy7O57F5VD6YTPZW9/IlPeOqJruoE+f1BiYoH30mC2jpuBs04GRynA2+gf4em9VD7VWJM85uh70uyzIXC8eJk3evqReNenxzo8+WxruXyI+Hh+rGOiQY9QxnWSg82FmpnYFNeAvSUw9HTm8W2K+tHyRo/JYFCKpKA0vZXT4dkwP2aLcI9omssdESEzuYTyS0r" Jan 27 10:36:32 volumio go-librespot[4385]: time="2026-01-27T10:36:32-06:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 27 10:36:32 volumio go-librespot[4385]: time="2026-01-27T10:36:32-06:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 10:36:32 volumio wpa_supplicant[1225]: TDLS: Dialog Token in TPK M1 12 Jan 27 10:36:32 volumio wpa_supplicant[1225]: nl80211: kernel reports: key addition failed Jan 27 10:36:32 volumio wpa_supplicant[1225]: TDLS: Failed to set TPK to the driver Jan 27 10:36:32 volumio go-librespot[4385]: time="2026-01-27T10:36:32-06:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 27 10:36:32 volumio volumio[1295]: info: Received Get System Info Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:36:32 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:36:32 volumio go-librespot[4385]: time="2026-01-27T10:36:32-06:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:32 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:36:32 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 27 10:36:32 volumio go-librespot[4385]: time="2026-01-27T10:36:32-06:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 10:36:33 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 27 10:36:33 volumio go-librespot[4385]: time="2026-01-27T10:36:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 27 10:36:33 volumio go-librespot[4385]: time="2026-01-27T10:36:33-06:00" level=debug msg="completed keyexchange" Jan 27 10:36:33 volumio go-librespot[4385]: time="2026-01-27T10:36:33-06:00" level=debug msg="completed challenge" Jan 27 10:36:34 volumio volumio[1295]: info: Initializing connection to go-librespot Websocket Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="new websocket client" Jan 27 10:36:34 volumio volumio[1295]: info: Connection to go-librespot Websocket established Jan 27 10:36:34 volumio volumio[1295]: info: go-librespot daemon successfully initialized Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=info msg="authenticated AP" username="o0*********************0c" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=info msg="authenticated Login5" username="o0*********************0c" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="stored credentials" username="o0*********************0c" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="initializing zeroconf session" username="o0*********************0c" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="dealer connection opened" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=trace msg="starting accesspoint recv loop" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=trace msg="starting dealer recv loop" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=trace msg="received accesspoint ping" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 27 10:36:34 volumio go-librespot[4385]: time="2026-01-27T10:36:34-06:00" level=debug msg="received connection id: N2ExNTZkZTctMmE0...RkMwOUMwMEQzMQ==" Jan 27 10:36:35 volumio go-librespot[4385]: time="2026-01-27T10:36:35-06:00" level=trace msg="received accesspoint pong ack" Jan 27 10:36:35 volumio go-librespot[4385]: time="2026-01-27T10:36:35-06:00" level=debug msg="put connect state because NEW_DEVICE" Jan 27 10:36:37 volumio volumio[1295]: info: Getting Spotify volume Jan 27 10:36:37 volumio volumio[1295]: info: Spotify volume: 100 Jan 27 10:36:37 volumio volumio[1295]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jan 27 10:36:37 volumio volumio[1295]: info: Initializing connection to go-librespot Websocket Jan 27 10:36:37 volumio go-librespot[4385]: time="2026-01-27T10:36:37-06:00" level=debug msg="new websocket client" Jan 27 10:36:37 volumio volumio[1295]: info: Connection to go-librespot Websocket established Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:37 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:37 volumio volumio[1295]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Jan 27 10:36:37 volumio volumio[1295]: SPOTIFY: SPOTIFY VOLUME 100 Jan 27 10:36:37 volumio volumio[1295]: SPOTIFY: VOLUMIO VOLUME 49 Jan 27 10:36:37 volumio volumio[1295]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 27 10:36:37 volumio volumio[1295]: info: Setting Spotify Volume from Volumio: 49 Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 27 10:36:37 volumio volumio[1295]: info: Received Get System Info Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:36:37 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:37 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:37 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:36:38 volumio volumio[1295]: SPOTIFY: SETTING SPOTIFY VOLUME 49 Jan 27 10:36:38 volumio volumio[1295]: info: Sending Spotify command with payload to local API: /player/volume Jan 27 10:36:38 volumio go-librespot[4385]: time="2026-01-27T10:36:38-06:00" level=debug msg="update volume requested to 32112/65535" Jan 27 10:36:38 volumio go-librespot[4385]: time="2026-01-27T10:36:38-06:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 27 10:36:38 volumio go-librespot[4385]: time="2026-01-27T10:36:38-06:00" level=trace msg="emitting websocket event: volume" Jan 27 10:36:38 volumio volumio[1295]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Jan 27 10:36:38 volumio volumio[1295]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Jan 27 10:36:38 volumio volumio[1295]: SPOTIFY: received: {"type":"volume","data":{"value":49,"max":100}} Jan 27 10:36:38 volumio volumio[1295]: SPOTIFY: RECEIVED SPOTIFY VOLUME 49 Jan 27 10:36:40 volumio volumio[1295]: info: Getting Spotify volume Jan 27 10:36:40 volumio volumio[1295]: info: Spotify volume: 49 Jan 27 10:36:40 volumio volumio[1295]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jan 27 10:36:40 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:40 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:40 volumio volumio[1295]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Jan 27 10:36:41 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 27 10:36:49 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:49 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:49 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:49 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:49 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:49 volumio sudo[4444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:49 volumio sudo[4444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:49 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:49 volumio volumio[1295]: info: Connection to go-librespot Websocket closed Jan 27 10:36:49 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:49 volumio volumio[1295]: info: Connection to go-librespot Websocket closed Jan 27 10:36:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:49 volumio sudo[4444]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:49 volumio go-librespot[4446]: go-librespot daemon starting... Jan 27 10:36:49 volumio go-librespot[4447]: time="2026-01-27T10:36:49-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:49 volumio go-librespot[4447]: time="2026-01-27T10:36:49-06:00" level=debug msg="app state loaded" Jan 27 10:36:49 volumio go-librespot[4447]: time="2026-01-27T10:36:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06: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-gae2.spotify.com:80]" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=info msg="zeroconf server listening on port 36667" Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 27 10:36:50 volumio volumio[1295]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 27 10:36:50 volumio volumio[1295]: info: Received Get System Version Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 10:36:50 volumio volumio[1295]: info: Received Get System Info Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 27 10:36:50 volumio volumio[1295]: info: Discovery: Getting this device information Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::volumioGetState Jan 27 10:36:50 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:50 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=debug msg="obtained new client token: AABL5xF5P87gtRgU4HbM5NY+W+AUQRUepeKbEMtwR032QO53RWY8TOTPrn0+CMy/UB3TZxsolO9do33zc7/WwjoZ5QXucsfK4k6+ACnFKQqYr1HubcMXqWFllcNdR55I+UjqN80sNGmwnxapaxUAHu9rdFkOIuXbJORLBU8hTPVamJHHqMapt4JGXOir6SWOWJfKBFzaAUdStqX3/7TcK+YDM8iPeNwry6GvoQHPIOq0oa6rBCYXg9Rr" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 27 10:36:50 volumio go-librespot[4447]: time="2026-01-27T10:36:50-06:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 10:36:51 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:51 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:51 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:51 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:51 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:51 volumio sudo[4457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:51 volumio sudo[4457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:51 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:51 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:51 volumio go-librespot[4459]: go-librespot daemon starting... Jan 27 10:36:51 volumio sudo[4457]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=debug msg="app state loaded" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=info msg="zeroconf server listening on port 46425" Jan 27 10:36:51 volumio go-librespot[4460]: time="2026-01-27T10:36:51-06:00" level=debug msg="obtained new client token: AACitZfnKNQ19JUqzp0zHeD9xRKSPPKJBBe1PXhUnqGQtADBZYy5tq251KWimIcJLW1E7+ANkuA/7ST+HL0Y8XAry/ZE0Hsf468rtRDhb25VmTj1gW9incbQ1Bl96LN8QpaizwpZxJ4baT3z1HtYyFVnE5NHBtOJ54/yjSCydlV5mGRya54/5MDzYrlOeJYDv3ip6TVSzbLCUadSs3luVSfYAbSiuwmedCyJJ0OGrMdU/EzRmieAb7c6" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="completed keyexchange" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="completed challenge" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=info msg="authenticated AP" username="o0*********************0c" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=info msg="authenticated Login5" username="o0*********************0c" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="initializing zeroconf session" username="o0*********************0c" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="dealer connection opened" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=trace msg="starting accesspoint recv loop" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=trace msg="starting dealer recv loop" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=trace msg="received accesspoint ping" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=debug msg="received connection id: M2E5MDcxYjEtM2I4...MENEODZEMkI5Nw==" Jan 27 10:36:52 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:52 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:52 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:52 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:52 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:52 volumio go-librespot[4460]: time="2026-01-27T10:36:52-06:00" level=trace msg="received accesspoint pong ack" Jan 27 10:36:52 volumio sudo[4471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:52 volumio sudo[4471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:52 volumio volumio[1295]: info: Initializing connection to go-librespot Websocket Jan 27 10:36:52 volumio volumio[1295]: info: Connection to go-librespot Websocket established Jan 27 10:36:52 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:52 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:52 volumio volumio[1295]: info: Connection to go-librespot Websocket closed Jan 27 10:36:52 volumio volumio[1295]: info: go-librespot daemon successfully initialized Jan 27 10:36:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:52 volumio go-librespot[4473]: go-librespot daemon starting... Jan 27 10:36:52 volumio sudo[4471]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:52 volumio go-librespot[4474]: time="2026-01-27T10:36:52-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:52 volumio go-librespot[4474]: time="2026-01-27T10:36:52-06:00" level=debug msg="app state loaded" Jan 27 10:36:53 volumio go-librespot[4474]: time="2026-01-27T10:36:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:53 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:53 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:53 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:53 volumio sudo[4482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio sudo[4482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio go-librespot[4485]: go-librespot daemon starting... Jan 27 10:36:53 volumio sudo[4482]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:53 volumio go-librespot[4486]: time="2026-01-27T10:36:53-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:53 volumio go-librespot[4486]: time="2026-01-27T10:36:53-06:00" level=debug msg="app state loaded" Jan 27 10:36:53 volumio go-librespot[4486]: time="2026-01-27T10:36:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:53 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:53 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:53 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:53 volumio sudo[4495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio sudo[4495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Killing process 4493 (n/a) with signal SIGKILL. Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio go-librespot[4498]: go-librespot daemon starting... Jan 27 10:36:53 volumio sudo[4495]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:53 volumio go-librespot[4499]: time="2026-01-27T10:36:53-06:00" level=info msg="running go-librespot 0.6.2" Jan 27 10:36:53 volumio go-librespot[4499]: time="2026-01-27T10:36:53-06:00" level=debug msg="app state loaded" Jan 27 10:36:53 volumio go-librespot[4499]: time="2026-01-27T10:36:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 10:36:53 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:53 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:53 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:53 volumio sudo[4507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio sudo[4507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 10:36:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 27 10:36:53 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio sudo[4507]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:53 volumio volumio[1295]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:53 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:53 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:53 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:53 volumio volumio[1295]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:53 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:53 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:53 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:53 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:53 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:53 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:53 volumio sudo[4511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio sudo[4511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 27 10:36:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 27 10:36:53 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:53 volumio sudo[4511]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:53 volumio volumio[1295]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:53 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:53 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:53 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:53 volumio volumio[1295]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:53 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:53 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:53 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:53 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:53 volumio volumio[1295]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 27 10:36:53 volumio volumio[1295]: info: Creating Spotify config file Jan 27 10:36:53 volumio volumio[1295]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 10:36:53 volumio volumio[1295]: info: Spotify config file written Jan 27 10:36:54 volumio sudo[4514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 10:36:54 volumio sudo[4514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 10:36:54 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 27 10:36:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 27 10:36:54 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 27 10:36:54 volumio sudo[4514]: pam_unix(sudo:session): session closed for user root Jan 27 10:36:54 volumio volumio[1295]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:54 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:54 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:54 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:54 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:54 volumio volumio[1295]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 27 10:36:54 volumio volumio[1295]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 27 10:36:54 volumio volumio[1295]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 27 10:36:54 volumio volumio[1295]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 27 10:36:54 volumio volumio[1295]: followed by "systemctl start go-librespot-daemon.service" again. Jan 27 10:36:54 volumio volumio[1295]: info: go-librespot daemon successfully initialized Jan 27 10:36:54 volumio volumio[1295]: info: CoreCommandRouter::volumioPlay Jan 27 10:36:54 volumio volumio[1295]: info: CoreStateMachine::play index undefined Jan 27 10:36:54 volumio volumio[1295]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 27 10:36:54 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:54 volumio volumio[1295]: info: CoreStateMachine::startPlaybackTimer Jan 27 10:36:54 volumio volumio[1295]: info: CorePlayQueue::getTrack 3 Jan 27 10:36:54 volumio volumio[1295]: info: [1769531814724] ControllerSpotify::clearAddPlayTrack Jan 27 10:36:54 volumio volumio[1295]: info: Sending Spotify command with payload to local API: /player/play Jan 27 10:36:54 volumio volumio[1295]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:36:55 volumio volumio[1295]: info: Getting Spotify volume Jan 27 10:36:55 volumio volumio[1295]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:36:55 volumio volumio[1295]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 10:36:55 volumio volumio[1295]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 10:36:55 volumio volumio[1295]: errno: -111, Jan 27 10:36:55 volumio volumio[1295]: code: 'ECONNREFUSED', Jan 27 10:36:55 volumio volumio[1295]: syscall: 'connect', Jan 27 10:36:55 volumio volumio[1295]: address: '127.0.0.1', Jan 27 10:36:55 volumio volumio[1295]: port: 9879, Jan 27 10:36:55 volumio volumio[1295]: response: undefined Jan 27 10:36:55 volumio volumio[1295]: } Jan 27 10:36:55 volumio volumio[1295]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 10:36:56 volumio sudo[4546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 10:35' Jan 27 10:36:56 volumio sudo[4546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:38:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="00e933ebe3692ad8aea9910d2289bf23"