Mar 28 20:16:26 car-pc volumio[1299]: info: Received OAUTH Data Mar 28 20:16:26 car-pc volumio[1299]: info: Executing Spotify Oauth Login Mar 28 20:16:26 car-pc volumio[1299]: info: Saving Spotify Refresh Token Mar 28 20:16:26 car-pc volumio[1299]: info: New Spotify access tokenBQDKmTyNVK... Mar 28 20:16:26 car-pc volumio[1299]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 20:16:27 car-pc volumio[1299]: SPOTIFY: User informations: {"country":"DE","display_name":"A.L","email":"loewen.alexander@freenet.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/huca3xjelcunjmufs54gqdlfd"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/huca3xjelcunjmufs54gqdlfd","id":"huca3xjelcunjmufs54gqdlfd","images":[],"product":"free","type":"user","uri":"spotify:user:huca3xjelcunjmufs54gqdlfd"} Mar 28 20:16:27 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:27 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:27 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:27 car-pc sudo[4243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:27 car-pc sudo[4243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:27 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:27 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:27 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:27 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:27 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:27 car-pc sudo[4243]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:27 car-pc volumio[1299]: info: New Spotify access tokenBQBwUjtaTP... Mar 28 20:16:27 car-pc go-librespot[4245]: go-librespot daemon starting... Mar 28 20:16:27 car-pc volumio[1299]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="app state loaded" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="stored credentials not found" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:27 car-pc volumio[1299]: SPOTIFY: User informations: {"country":"DE","display_name":"A.L","email":"loewen.alexander@freenet.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/huca3xjelcunjmufs54gqdlfd"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/huca3xjelcunjmufs54gqdlfd","id":"huca3xjelcunjmufs54gqdlfd","images":[],"product":"free","type":"user","uri":"spotify:user:huca3xjelcunjmufs54gqdlfd"} Mar 28 20:16:27 car-pc volumio[1299]: info: Spotify Successfully logged in Mar 28 20:16:27 car-pc volumio[1299]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 20:16:27 car-pc volumio[1299]: info: [1774725387483] CoreMusicLibrary::Adding element Spotify Mar 28 20:16:27 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 20:16:27 car-pc volumio[1299]: Cannot find translation for source Spotify Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01: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]" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01: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]" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01: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]" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=info msg="zeroconf server listening on port 45835" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="obtained new client token: AACGUp22lcrVnX+1I3aHH+YAOd4b+nPk994HlwxDXj+ahOZTwTaN8WEN/4FYmDK+bsRB74yZ5ztRfqN/3mhw8dt8EQqObP7YUvFOnJLxVnm+apIdM9p1EYlcgUdYptCKV++MdlpQ3nH5HnWb34bCEyfyK+NFqhvzItgW1drhYrD9GFYoVFPACzwsL3rZmAkUg79S0XuuNCnx0eq5y9oykfUkhjXnXfVPni+mYbY/oxfYgqe2yIkbCIeKDg==" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="completed keyexchange" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=debug msg="completed challenge" Mar 28 20:16:27 car-pc go-librespot[4248]: time="2026-03-28T20:16:27+01:00" level=info msg="authenticated AP" username="hu*********************fd" Mar 28 20:16:27 car-pc volumio[1299]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:28 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 20:16:28 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 20:16:29 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 20:16:29 car-pc volumio[1299]: info: Received Get System Info Mar 28 20:16:29 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 20:16:29 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 20:16:29 car-pc volumio[1299]: info: Discovery: Getting this device information Mar 28 20:16:29 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:29 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:29 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 20:16:30 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:30 car-pc go-librespot[4248]: time="2026-03-28T20:16:30+01:00" level=debug msg="new websocket client" Mar 28 20:16:30 car-pc volumio[1299]: info: Connection to go-librespot Websocket established Mar 28 20:16:30 car-pc volumio[1299]: info: go-librespot daemon successfully initialized Mar 28 20:16:31 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 20:16:31 car-pc volumio[1299]: info: Received Get System Info Mar 28 20:16:31 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 20:16:31 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 20:16:31 car-pc volumio[1299]: info: Discovery: Getting this device information Mar 28 20:16:31 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:31 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:31 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=info msg="authenticated Login5" username="hu*********************fd" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="stored credentials" username="hu*********************fd" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="initializing zeroconf session" username="hu*********************fd" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="dealer connection opened" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=trace msg="starting dealer recv loop" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=trace msg="received accesspoint ping" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="received connection id: OGVjYmYyOWEtOWNh...QkMxREM5RDIwNQ==" Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=trace msg="received accesspoint pong ack" Mar 28 20:16:33 car-pc volumio[1299]: info: Getting Spotify volume Mar 28 20:16:33 car-pc volumio[1299]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 28 20:16:33 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:33 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:33 car-pc volumio[1299]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Mar 28 20:16:33 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="new websocket client" Mar 28 20:16:33 car-pc volumio[1299]: info: Connection to go-librespot Websocket established Mar 28 20:16:33 car-pc go-librespot[4248]: time="2026-03-28T20:16:33+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 20:16:33 car-pc volumio[1299]: info: Spotify volume: 100 Mar 28 20:16:36 car-pc volumio[1299]: info: Getting Spotify volume Mar 28 20:16:36 car-pc volumio[1299]: info: Spotify volume: 100 Mar 28 20:16:36 car-pc volumio[1299]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 28 20:16:36 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:36 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:36 car-pc volumio[1299]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Mar 28 20:16:36 car-pc volumio[1299]: SPOTIFY: SPOTIFY VOLUME 100 Mar 28 20:16:36 car-pc volumio[1299]: SPOTIFY: VOLUMIO VOLUME 20 Mar 28 20:16:36 car-pc volumio[1299]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 20:16:36 car-pc volumio[1299]: info: Setting Spotify Volume from Volumio: 20 Mar 28 20:16:37 car-pc volumio[1299]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Mar 28 20:16:37 car-pc volumio[1299]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 20:16:37 car-pc go-librespot[4248]: time="2026-03-28T20:16:37+01:00" level=debug msg="update volume requested to 13107/65535" Mar 28 20:16:38 car-pc go-librespot[4248]: time="2026-03-28T20:16:38+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 20:16:38 car-pc go-librespot[4248]: time="2026-03-28T20:16:38+01:00" level=trace msg="emitting websocket event: volume" Mar 28 20:16:38 car-pc volumio[1299]: SPOTIFY: received: {"type":"volume","data":{"value":20,"max":100}} Mar 28 20:16:38 car-pc volumio[1299]: SPOTIFY: RECEIVED SPOTIFY VOLUME 20 Mar 28 20:16:38 car-pc volumio[1299]: SPOTIFY: received: {"type":"volume","data":{"value":20,"max":100}} Mar 28 20:16:38 car-pc volumio[1299]: SPOTIFY: RECEIVED SPOTIFY VOLUME 20 Mar 28 20:16:42 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:42 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:42 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:42 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:42 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:42 car-pc sudo[4276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:42 car-pc sudo[4276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:42 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:42 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:42 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:42 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:42 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:42 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:42 car-pc go-librespot[4278]: go-librespot daemon starting... Mar 28 20:16:42 car-pc sudo[4276]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=debug msg="app state loaded" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01: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]" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01: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]" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01: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]" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=info msg="zeroconf server listening on port 46129" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:42 car-pc go-librespot[4279]: time="2026-03-28T20:16:42+01:00" level=debug msg="obtained new client token: AAA43gglneYWndQV3RVLJEBI/GyAPSM9fq7htwd5J5aMgvRvFsZ0DdfbGEOSMouErjfrnmEn5Blxj+HSqTaiAIBHS8dB0Ux5L0Hx40dgUWAgyGcyfmnWTyNZlV78SnpuijBRYp+2WPcX9j/p1l7Zkh7/CcuXV61E9wgqEVTGii+00/m32u1wRKkAmt5ZA9teAIHHN4EUjukKsIxIWpRc+F1he0t5iyi4sPy+TKX5eiG+qFNSetOtMzfAMg==" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="completed keyexchange" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="completed challenge" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=info msg="authenticated AP" username="hu*********************fd" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=info msg="authenticated Login5" username="hu*********************fd" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="initializing zeroconf session" username="hu*********************fd" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="dealer connection opened" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=trace msg="starting dealer recv loop" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=trace msg="received accesspoint ping" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="received connection id: M2JkNmY5MzItNjdi...NEFCNUVBODhDMQ==" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=trace msg="received accesspoint pong ack" Mar 28 20:16:43 car-pc go-librespot[4279]: time="2026-03-28T20:16:43+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 20:16:44 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:44 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:44 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:44 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:44 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:44 car-pc sudo[4289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:44 car-pc sudo[4289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:44 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:44 car-pc systemd[1]: go-librespot-daemon.service: Killing process 4284 (go-librespot) with signal SIGKILL. Mar 28 20:16:44 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:44 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:44 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:44 car-pc go-librespot[4291]: go-librespot daemon starting... Mar 28 20:16:44 car-pc sudo[4289]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=debug msg="app state loaded" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01: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]" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01: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]" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01: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]" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=info msg="zeroconf server listening on port 46503" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:44 car-pc go-librespot[4292]: time="2026-03-28T20:16:44+01:00" level=debug msg="obtained new client token: AACh9YodeUhx6Tk0XDYSkd2tetTuqcMr6q7GR3eFyAioZAmpz/qB1HkrXjLjha6qHxk8shLbHsGMG236P0v0LWwmvrw8066J7/Ad+lyA58VLKcq1T6tN/YAR2ohF9kWC9LUkCw2hhByxq27wX4B/4fR1vnlSTJKAr5V+YTxHDykwG6SKIJ5O4CcMX48VGxM6wvcCvyc+BnhPU94c3bRdyAvJmyRBzHVBDYglbeeU2DaEigdnGnzUpm3/ZA==" Mar 28 20:16:45 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:45 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:45 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:45 car-pc sudo[4302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:45 car-pc sudo[4302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:45 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:45 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:45 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:45 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:45 car-pc go-librespot[4304]: go-librespot daemon starting... Mar 28 20:16:45 car-pc sudo[4302]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="app state loaded" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:45 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="new websocket client" Mar 28 20:16:45 car-pc volumio[1299]: info: Connection to go-librespot Websocket established Mar 28 20:16:45 car-pc volumio[1299]: info: go-librespot daemon successfully initialized Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01: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]" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01: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]" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01: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]" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=info msg="zeroconf server listening on port 39243" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 20:16:45 car-pc volumio[1299]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 28 20:16:45 car-pc volumio[1299]: info: Received Get System Version Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 20:16:45 car-pc volumio[1299]: info: Received Get System Info Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 20:16:45 car-pc volumio[1299]: info: Discovery: Getting this device information Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:45 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:45 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="obtained new client token: AAB9tdNYaBK+ek02MP7VKfPyR/bTABCbZ6Gmp30+2oMW5d6dnRa7mZvCil+cJ91ICbSvk8qEn1SfL2Qas7QZB2k2B16pPxyRkti/EDLVoHnTprcyp2YQkBczMunBRAjNVQTrSr4lyaivhBzTN4asqxZqQvX19Cu8ksMpV2qXgrYcWfwKmsFYHbzTFcy/GXqQZYO0xNF5v8NJdAxzLIA+y/wXe4Wt3ujgrX4nJ9SenAdsWeB+gFixcRUk7w==" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="completed keyexchange" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=debug msg="completed challenge" Mar 28 20:16:45 car-pc go-librespot[4319]: time="2026-03-28T20:16:45+01:00" level=info msg="authenticated AP" username="hu*********************fd" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=info msg="authenticated Login5" username="hu*********************fd" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="initializing zeroconf session" username="hu*********************fd" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="dealer connection opened" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=trace msg="starting dealer recv loop" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=trace msg="received accesspoint ping" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="received connection id: MGQ2MDhmMjctMGQ5...MzAyRERFMTNDMw==" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=trace msg="received accesspoint pong ack" Mar 28 20:16:46 car-pc go-librespot[4319]: time="2026-03-28T20:16:46+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 20:16:47 car-pc volumio[1299]: info: go-librespot daemon successfully initialized Mar 28 20:16:48 car-pc volumio[1299]: info: go-librespot daemon successfully initialized Mar 28 20:16:48 car-pc volumio[1299]: info: Getting Spotify volume Mar 28 20:16:48 car-pc volumio[1299]: info: Spotify volume: 100 Mar 28 20:16:48 car-pc volumio[1299]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 28 20:16:48 car-pc volumio[1299]: info: CoreCommandRouter::volumioGetState Mar 28 20:16:48 car-pc volumio[1299]: info: CorePlayQueue::getTrack 0 Mar 28 20:16:48 car-pc volumio[1299]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Mar 28 20:16:48 car-pc volumio[1299]: SPOTIFY: SPOTIFY VOLUME 100 Mar 28 20:16:48 car-pc volumio[1299]: SPOTIFY: VOLUMIO VOLUME 20 Mar 28 20:16:48 car-pc volumio[1299]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 20:16:48 car-pc volumio[1299]: info: Setting Spotify Volume from Volumio: 20 Mar 28 20:16:48 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:48 car-pc go-librespot[4319]: time="2026-03-28T20:16:48+01:00" level=debug msg="new websocket client" Mar 28 20:16:48 car-pc volumio[1299]: info: Connection to go-librespot Websocket established Mar 28 20:16:49 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:49 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:49 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:49 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:49 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:49 car-pc sudo[4329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:49 car-pc sudo[4329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:49 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:49 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:49 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:49 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:49 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:49 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:49 car-pc go-librespot[4331]: go-librespot daemon starting... Mar 28 20:16:49 car-pc sudo[4329]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="app state loaded" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01: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]" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01: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]" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01: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]" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="zeroconf server listening on port 37451" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="obtained new client token: AABB8sav+Hg1Z1Yp7YQ58Lt3NmFg0cCq8JIe4W9S2BRvhzvTgiGRYHylaxAtSQLS0leq0/IFKRnLPVlw1k57e867yclyppuQVlX0pQOXZyM5i5885TFOc7k6mYlCcSMKUmsal/AnKl5y+Nf96e4PGo5GRGfuVJ3Ah/j68tUs8CH7UtLn6XgB0SKyYOD1bQHBve6CAuo5XDSG8qidOD3j4/tirkvVfQhnR+H7OzB5ivmAAclruqp6741TlA==" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="completed keyexchange" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="completed challenge" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="authenticated AP" username="hu*********************fd" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=info msg="authenticated Login5" username="hu*********************fd" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="initializing zeroconf session" username="hu*********************fd" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="dealer connection opened" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=trace msg="received accesspoint ping" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=trace msg="starting dealer recv loop" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=debug msg="received connection id: MjJhMzU2ZDktNTRm...NkQ5N0VFRUQ5OQ==" Mar 28 20:16:49 car-pc go-librespot[4332]: time="2026-03-28T20:16:49+01:00" level=trace msg="received accesspoint pong ack" Mar 28 20:16:50 car-pc volumio[1299]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Mar 28 20:16:50 car-pc volumio[1299]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 20:16:50 car-pc go-librespot[4332]: time="2026-03-28T20:16:50+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 20:16:50 car-pc go-librespot[4332]: time="2026-03-28T20:16:50+01:00" level=debug msg="update volume requested to 13107/65535" Mar 28 20:16:50 car-pc go-librespot[4332]: time="2026-03-28T20:16:50+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 20:16:50 car-pc go-librespot[4332]: time="2026-03-28T20:16:50+01:00" level=trace msg="emitting websocket event: volume" Mar 28 20:16:50 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:50 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:50 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:50 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:50 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:50 car-pc sudo[4342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:50 car-pc sudo[4342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:50 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:50 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:50 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:50 car-pc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:50 car-pc go-librespot[4344]: go-librespot daemon starting... Mar 28 20:16:50 car-pc sudo[4342]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="app state loaded" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 20:16:50 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="new websocket client" Mar 28 20:16:50 car-pc volumio[1299]: info: Connection to go-librespot Websocket established Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01: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]" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01: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]" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01: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]" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=info msg="zeroconf server listening on port 37151" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="obtained new client token: AABF9ji9W+y7r+b8MSijClWe7iTTCBoMZkmGIpoqb9wOFFvBBzUdrRe3R7uxIHGCaFqP5qUkjiZAhE2938uwxZK/7dHs8hfEtxUPcnXlcUQ1xRzoiXwvVmn2/8VEL7ir7h+krWQ/jKbZQdNqyVbIBfL4r7oP6T/fjjQnjkWDRTbamm77EP3M59TW5Gcd64jSGsYSJHB17IrWC73I0KXBWJCttXFUDm/8Wz8WPozEgMZaqfuQspCxBtQiBg==" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="completed keyexchange" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=debug msg="completed challenge" Mar 28 20:16:50 car-pc go-librespot[4345]: time="2026-03-28T20:16:50+01:00" level=info msg="authenticated AP" username="hu*********************fd" Mar 28 20:16:51 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:51 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:51 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:51 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:51 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:51 car-pc sudo[4355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc sudo[4355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:51 car-pc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Killing process 4350 (go-librespot) with signal SIGKILL. Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 20:16:51 car-pc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:51 car-pc volumio[1299]: info: Connection to go-librespot Websocket closed Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Mar 28 20:16:51 car-pc systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:51 car-pc sudo[4355]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:51 car-pc volumio[1299]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc volumio[1299]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 20:16:51 car-pc volumio[1299]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 20:16:51 car-pc volumio[1299]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 20:16:51 car-pc volumio[1299]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 20:16:51 car-pc volumio[1299]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc volumio[1299]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 20:16:51 car-pc volumio[1299]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 20:16:51 car-pc volumio[1299]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 20:16:51 car-pc volumio[1299]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 20:16:51 car-pc volumio[1299]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 20:16:51 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 20:16:51 car-pc volumio[1299]: info: Creating Spotify config file Mar 28 20:16:51 car-pc volumio[1299]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 20:16:51 car-pc volumio[1299]: info: Spotify config file written Mar 28 20:16:51 car-pc sudo[4358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc sudo[4358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Mar 28 20:16:51 car-pc systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Mar 28 20:16:51 car-pc systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Mar 28 20:16:51 car-pc sudo[4358]: pam_unix(sudo:session): session closed for user root Mar 28 20:16:51 car-pc volumio[1299]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc volumio[1299]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 20:16:51 car-pc volumio[1299]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 20:16:51 car-pc volumio[1299]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 20:16:51 car-pc volumio[1299]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 20:16:51 car-pc volumio[1299]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 20:16:51 car-pc volumio[1299]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 20:16:51 car-pc volumio[1299]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 20:16:51 car-pc volumio[1299]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 20:16:51 car-pc volumio[1299]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 20:16:51 car-pc volumio[1299]: info: Initializing connection to go-librespot Websocket Mar 28 20:16:51 car-pc volumio[1299]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 20:16:51 car-pc volumio[1299]: info: Getting Spotify volume Mar 28 20:16:51 car-pc volumio[1299]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 20:16:51 car-pc volumio[1299]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 20:16:51 car-pc volumio[1299]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 28 20:16:51 car-pc volumio[1299]: errno: -111, Mar 28 20:16:51 car-pc volumio[1299]: code: 'ECONNREFUSED', Mar 28 20:16:51 car-pc volumio[1299]: syscall: 'connect', Mar 28 20:16:51 car-pc volumio[1299]: address: '127.0.0.1', Mar 28 20:16:51 car-pc volumio[1299]: port: 9879, Mar 28 20:16:51 car-pc volumio[1299]: response: undefined Mar 28 20:16:51 car-pc volumio[1299]: } Mar 28 20:16:51 car-pc volumio[1299]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 20:16:52 car-pc sudo[4374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 20:15' Mar 28 20:16:52 car-pc sudo[4374]: 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"