Jul 10 19:46:24 rpi4-ws800 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Jul 10 19:46:24 rpi4-ws800 dbus-daemon[683]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.57' (uid=0 pid=3124 comm="timedatectl show --property=NTPSynchronized --valu")
Jul 10 19:46:24 rpi4-ws800 systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Jul 10 19:46:24 rpi4-ws800 dbus-daemon[683]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jul 10 19:46:24 rpi4-ws800 systemd[1]: Started systemd-timedated.service - Time & Date Service.
Jul 10 19:46:24 rpi4-ws800 setdatetime-helper.sh[3123]: Time is not synchronized. Attempting to sync...
Jul 10 19:46:25 rpi4-ws800 sudo[3132]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 10 Jul 2025 17:46:25 GMT#015'
Jul 10 19:46:25 rpi4-ws800 sudo[3132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jul 10 19:46:25 rpi4-ws800 setdatetime-helper.sh[3133]: Thu Jul 10 19:46:25 CEST 2025
Jul 10 19:46:25 rpi4-ws800 systemd-journald[356]: Time jumped backwards, rotating.
Jul 10 19:46:25 rpi4-ws800 setdatetime-helper.sh[3123]: Time synchronized successfully.
Jul 10 19:46:25 rpi4-ws800 sudo[3132]: pam_unix(sudo:session): session closed for user root
Jul 10 19:46:25 rpi4-ws800 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Jul 10 19:46:25 rpi4-ws800 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Jul 10 19:46:54 rpi4-ws800 systemd[1]: systemd-timedated.service: Deactivated successfully.
Jul 10 19:47:22 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: info: Received OAUTH Data
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: info: Executing Spotify Oauth Login
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: info: Saving Spotify Refresh Token
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: SPOTIFY: BQAZwCYGpySy0ocnzdlchIswK_tQmDSiz0t7h3gbGFQnJcv_ibDH7eRH9Vn6fPBT7D9yVQb0C0TS4JiJXseSmBvg7becNMpE5kI1XrMCENykiUjCjFu_Aargx9kx8grw7U6rH4LVToZ_p1IVBr1YU8KaS0QCgE_KJDAsZNA9n2aeHHYm2LEavbzs1EQpwIsAYAxkx5EkB7k1WDWmgwFV7Um6YwUinQWho3lQUnUKfzpokomQfr8PVlxMrRo7Rrq7TzQG6CRsQKKyJS41j-AYDfUojV2Xj87nMqI6-zr5uFJB4V2EmKKJ3eAVpWPos4Skg6N7rWUBDfMUL4PQpixuelYMXE_KKttB6zJCHWOPoCZaWL-ozPSueYwkhC1L
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: info: New Spotify access token = BQAZwCYGpySy0ocnzdlchIswK_tQmDSiz0t7h3gbGFQnJcv_ibDH7eRH9Vn6fPBT7D9yVQb0C0TS4JiJXseSmBvg7becNMpE5kI1XrMCENykiUjCjFu_Aargx9kx8grw7U6rH4LVToZ_p1IVBr1YU8KaS0QCgE_KJDAsZNA9n2aeHHYm2LEavbzs1EQpwIsAYAxkx5EkB7k1WDWmgwFV7Um6YwUinQWho3lQUnUKfzpokomQfr8PVlxMrRo7Rrq7TzQG6CRsQKKyJS41j-AYDfUojV2Xj87nMqI6-zr5uFJB4V2EmKKJ3eAVpWPos4Skg6N7rWUBDfMUL4PQpixuelYMXE_KKttB6zJCHWOPoCZaWL-ozPSueYwkhC1L
Jul 10 19:47:26 rpi4-ws800 volumio[1126]: info: Spotify credentials grant success - running version from March 24, 2019
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: SPOTIFY: User informations: {"country":"NL","display_name":"Marco","email":"m.botermans@home.nl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/z4ujt0w8jsm3yt93kz6hrseoy"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/z4ujt0w8jsm3yt93kz6hrseoy","id":"z4ujt0w8jsm3yt93kz6hrseoy","images":[],"product":"premium","type":"user","uri":"spotify:user:z4ujt0w8jsm3yt93kz6hrseoy"}
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: Creating Spotify config file
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: Spotify config file written
Jul 10 19:47:27 rpi4-ws800 sudo[3224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 10 19:47:27 rpi4-ws800 sudo[3224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 10 19:47:27 rpi4-ws800 sudo[3226]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 10 19:47:27 rpi4-ws800 sudo[3226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 10 19:47:27 rpi4-ws800 sudo[3229]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 10 19:47:27 rpi4-ws800 sudo[3229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 10 19:47:27 rpi4-ws800 sudo[3226]: pam_unix(sudo:session): session closed for user root
Jul 10 19:47:27 rpi4-ws800 sudo[3229]: pam_unix(sudo:session): session closed for user root
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: Connection to go-librespot Websocket closed
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Jul 10 19:47:27 rpi4-ws800 systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jul 10 19:47:27 rpi4-ws800 sudo[3224]: pam_unix(sudo:session): session closed for user root
Jul 10 19:47:27 rpi4-ws800 go-librespot[3235]: go-librespot daemon starting...
Jul 10 19:47:27 rpi4-ws800 dbus-daemon[683]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.59' (uid=0 pid=3233 comm="timedatectl show --property=NTPSynchronized --valu")
Jul 10 19:47:27 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:27+02:00" level=info msg="running go-librespot 0.2.0"
Jul 10 19:47:27 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:27+02:00" level=debug msg="app state loaded"
Jul 10 19:47:27 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:27+02:00" level=debug msg="stored credentials not found"
Jul 10 19:47:27 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:27+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: SPOTIFY: BQDzV1sX8-kUwDnlMrGAoYd7LYAlEcxW0ObIpGgU1o1DXdGXI_nT11yWaBVfgXvnYZxLwt--GXmPb4hEkb6Np8TT6-rOx5IiJa8VbvCEh3nASRyxAjuq85wCMdoLz6jvAiIfizP-yKd_RWxLq3YxGA17sgesVldP0MBGskzdCI67Rnrl6bfNBPEBYUrjd_PEzdtXWTKvQE0_M8WIpIYrKRssFXF7qbxYbtvtwPvn17rw3TuL8JPlMm4QdES37irdew8g7agYWyfF7snvZ3U0sBalydngaeQDr3wyblHpzKOc_ix-I8o5FPEASU-yYML7ZBsEbKFBK5qFgkIgq3eAND2Dq0r3pQRk3UAKXLV48wyTVk5_dioHJnFHUeYP
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: New Spotify access token = BQDzV1sX8-kUwDnlMrGAoYd7LYAlEcxW0ObIpGgU1o1DXdGXI_nT11yWaBVfgXvnYZxLwt--GXmPb4hEkb6Np8TT6-rOx5IiJa8VbvCEh3nASRyxAjuq85wCMdoLz6jvAiIfizP-yKd_RWxLq3YxGA17sgesVldP0MBGskzdCI67Rnrl6bfNBPEBYUrjd_PEzdtXWTKvQE0_M8WIpIYrKRssFXF7qbxYbtvtwPvn17rw3TuL8JPlMm4QdES37irdew8g7agYWyfF7snvZ3U0sBalydngaeQDr3wyblHpzKOc_ix-I8o5FPEASU-yYML7ZBsEbKFBK5qFgkIgq3eAND2Dq0r3pQRk3UAKXLV48wyTVk5_dioHJnFHUeYP
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: Spotify credentials grant success - running version from March 24, 2019
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: SPOTIFY: User informations: {"country":"NL","display_name":"Marco","email":"m.botermans@home.nl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/z4ujt0w8jsm3yt93kz6hrseoy"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/z4ujt0w8jsm3yt93kz6hrseoy","id":"z4ujt0w8jsm3yt93kz6hrseoy","images":[],"product":"premium","type":"user","uri":"spotify:user:z4ujt0w8jsm3yt93kz6hrseoy"}
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: Spotify Successfully logged in
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: [1752169647457] CoreMusicLibrary::Adding element Spotify
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source 80s80s Radio
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source Radio Paradise
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source Randomizer
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source QOBUZ
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source TIDAL
Jul 10 19:47:27 rpi4-ws800 volumio[1126]: Cannot find translation for source Spotify
Jul 10 19:47:27 rpi4-ws800 dbus-daemon[683]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jul 10 19:47:27 rpi4-ws800 systemd[1]: Started systemd-timedated.service - Time & Date Service.
Jul 10 19:47:27 rpi4-ws800 setdatetime-helper.sh[3232]: Time is not synchronized. Attempting to sync...
Jul 10 19:47:27 rpi4-ws800 sudo[3249]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 10 Jul 2025 17:47:28 GMT#015'
Jul 10 19:47:27 rpi4-ws800 sudo[3249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jul 10 19:47:28 rpi4-ws800 setdatetime-helper.sh[3250]: Thu Jul 10 19:47:28 CEST 2025
Jul 10 19:47:28 rpi4-ws800 sudo[3249]: pam_unix(sudo:session): session closed for user root
Jul 10 19:47:28 rpi4-ws800 setdatetime-helper.sh[3232]: Time synchronized successfully.
Jul 10 19:47:28 rpi4-ws800 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Jul 10 19:47:28 rpi4-ws800 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Jul 10 19:47:28 rpi4-ws800 volumio[1126]: verbose: New Socket.io Connection to 192.168.1.27 from 192.168.1.106 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15
Jul 10 19:47:28 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jul 10 19:47:28 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Jul 10 19:47:28 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Jul 10 19:47:28 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:28+02:00" level=info msg="zeroconf server listening on port 36191"
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetVisibleSources
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Received Get System Info
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Discovery: Getting this device information
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Listing playlists
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Received Get System Info
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Discovery: Getting this device information
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: error: FusionDsp - failed to read local file: Error: ENOENT: no such file or directory, scandir '/data/INTERNAL/FusionDsp/presets//EQ3'
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Initializing connection to go-librespot Websocket
Jul 10 19:47:30 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:30+02:00" level=debug msg="new websocket client"
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Connection to go-librespot Websocket established
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: go-librespot daemon successfully initialized
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Received Get System Info
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: Discovery: Getting this device information
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:30 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 10 19:47:31 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:31+02:00" level=debug msg="obtained new client token: AABt+v/BFGIbjAvEgCvLzZJtqWHa8ocedAWQcKrdZqFvdjTggBMI8HwPtcnp6hp+SW/B8LxBrGaUI08RUe0zMtF/3j5y1j7SB09zxjrGwAjqGnLZAk66/HTTUPi/oUAKvqHXZiDhoa6LSXdTtJX8By6z8Q9McGF3T1f308qEFcjQgbY0hYFqfeNP12ls3tPGKAQP9nJe4Q/lr6BblqimIUOLPh2Ep6VbBraNjO8M8DjmK5lbKhwJnsc/gCs="
Jul 10 19:47:31 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Jul 10 19:47:31 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Jul 10 19:47:31 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: info: Getting Spotify volume
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::volumioGetState
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: info: Initializing connection to go-librespot Websocket
Jul 10 19:47:33 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:33+02:00" level=debug msg="new websocket client"
Jul 10 19:47:33 rpi4-ws800 volumio[1126]: info: Connection to go-librespot Websocket established
Jul 10 19:47:34 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:34+02:00" level=debug msg="completed keyexchange"
Jul 10 19:47:34 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:34+02:00" level=debug msg="completed challenge"
Jul 10 19:47:34 rpi4-ws800 volumio[1126]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object]
Jul 10 19:47:34 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings
Jul 10 19:47:34 rpi4-ws800 volumio[1126]: info: Creating Spotify config file
Jul 10 19:47:34 rpi4-ws800 volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 10 19:47:34 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:34+02:00" level=info msg="authenticated AP as z4ujt0w8jsm3yt93kz6hrseoy"
Jul 10 19:47:34 rpi4-ws800 go-librespot[3236]: time="2025-07-10T19:47:34+02:00" level=info msg="authenticated Login5 as z4ujt0w8jsm3yt93kz6hrseoy"
Jul 10 19:47:35 rpi4-ws800 volumio[1126]: info: Spotify config file written
Jul 10 19:47:35 rpi4-ws800 sudo[3267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 10 19:47:35 rpi4-ws800 sudo[3267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 10 19:47:35 rpi4-ws800 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Jul 10 19:47:36 rpi4-ws800 systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: info: Connection to go-librespot Websocket closed
Jul 10 19:47:36 rpi4-ws800 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: Error: socket hang up
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: at connResetException (node:internal/errors:720:14)
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: at Socket.socketOnEnd (node:_http_client:519:23)
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: at Socket.emit (node:events:526:35)
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: at endReadableNT (node:internal/streams/readable:1376:12)
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: code: 'ECONNRESET',
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: response: undefined
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: }
Jul 10 19:47:36 rpi4-ws800 volumio[1126]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 10 19:47:36 rpi4-ws800 sudo[3267]: pam_unix(sudo:session): session closed for user root
Jul 10 19:47:36 rpi4-ws800 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jul 10 19:47:36 rpi4-ws800 go-librespot[3269]: go-librespot daemon starting...
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=info msg="running go-librespot 0.2.0"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="app state loaded"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=info msg="zeroconf server listening on port 46037"
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="obtained new client token: AACzWu55p8ZUtLrJPstmOPcBRKG1wwtk9IM2JJEFJhMbeUHn7wRkf4yA5RE7M/DKifymoiGMQnFScjY6C0/JpXXNiHrRyLnvOzcP6xPlLb3LvoEdoV/WdlOyHX5pMr9/G1eMZJAkgijp9tI9ixBFkPQf+Bj2PsDXr9wnzq7UzRTWYtfHxM+6JlDQhQL32RvogG1it7uviFGmvfXjgNZQF6XylOT0EYVK6RvfWijZU8j+axoBFJNVNN8q"
Jul 10 19:47:36 rpi4-ws800 sudo[3292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-10 19:46'
Jul 10 19:47:36 rpi4-ws800 sudo[3292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 10 19:47:36 rpi4-ws800 go-librespot[3282]: time="2025-07-10T19:47:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
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="4f980d5cf693b4272997a2fa2da8bb8036ddf1ab"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Jul 5 02:50:33 UTC 2025"
VOLUMIO_VERSION="4.015"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="d42ab79cc13d24482826e04fda2e8350"