Jun 05 15:36:01 volumio volumio[1085]: info: PLUGIN START: music_services_shield Jun 05 15:36:01 volumio sudo[6090]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Jun 05 15:36:01 volumio sudo[6090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:36:02 volumio sudo[6090]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:02 volumio volumio[1085]: info: Done. Jun 05 15:36:02 volumio sudo[6110]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh Jun 05 15:36:02 volumio sudo[6110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:36:03 volumio systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal Jun 05 15:36:03 volumio systemd[1]: Starting musicservicesshield.service - Shield Volumio Music Services in the User CPU Set... Jun 05 15:36:04 volumio bash[6128]: cset: --> shielding system active with Jun 05 15:36:04 volumio bash[6128]: cset: "system" cpuset of CPUSPEC(1-3) with 149 tasks running Jun 05 15:36:04 volumio bash[6128]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Jun 05 15:36:04 volumio systemd[1]: Finished musicservicesshield.service - Shield Volumio Music Services in the User CPU Set. Jun 05 15:36:04 volumio systemd[1]: Reloading. Jun 05 15:36:04 volumio systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal Jun 05 15:36:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 05 15:36:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jun 05 15:36:05 volumio sudo[6110]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:05 volumio volumio[1085]: info: succeeded Jun 05 15:36:07 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:07 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:17 volumio volumio[1085]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/Systeminfo/volumio/bookworm/armhf Jun 05 15:36:17 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:17 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:17 volumio volumio[1085]: info: Listing playlists Jun 05 15:36:17 volumio volumio[1085]: info: Listing playlists Jun 05 15:36:23 volumio volumio[1085]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/Systeminfo/volumio/bookworm/armhf Jun 05 15:36:23 volumio volumio[1085]: info: Folder /tmp/plugins removed Jun 05 15:36:23 volumio volumio[1085]: info: Check plugin dependencies Jun 05 15:36:23 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 05 15:36:23 volumio volumio[1085]: info: Checking if plugin already exists Jun 05 15:36:23 volumio volumio[1085]: info: Rename folder Jun 05 15:36:23 volumio volumio[1085]: info: Folder /tmp/downloaded_plugin.zip removed Jun 05 15:36:23 volumio volumio[1085]: info: Move to category Jun 05 15:36:24 volumio volumio[1085]: info: Checking if install.sh is present Jun 05 15:36:24 volumio volumio[1085]: info: Executing install.sh Jun 05 15:36:24 volumio sudo[6193]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/Systeminfo/install.sh Jun 05 15:36:24 volumio sudo[6193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:36:24 volumio volumio[1085]: info: Installing systeminfo Jun 05 15:36:24 volumio volumio[1085]: info: Configuration file doesn't exist, nothing to do Jun 05 15:36:24 volumio sudo[6198]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/user_interface/Systeminfo/c/hw_params_arm /data/plugins/user_interface/Systeminfo/hw_params Jun 05 15:36:24 volumio sudo[6198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 05 15:36:24 volumio volumio[1085]: info: Detected cpu architecture as armv7l Jun 05 15:36:24 volumio sudo[6198]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:24 volumio sudo[6200]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/Systeminfo/hw_params Jun 05 15:36:24 volumio sudo[6200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 05 15:36:24 volumio sudo[6200]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:24 volumio sudo[6202]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/Systeminfo/firmware.sh Jun 05 15:36:24 volumio sudo[6202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 05 15:36:24 volumio sudo[6202]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:24 volumio sudo[6193]: pam_unix(sudo:session): session closed for user root Jun 05 15:36:24 volumio volumio[1085]: Plugin install end detected on script Jun 05 15:36:24 volumio volumio[1085]: info: Install script completed Jun 05 15:36:24 volumio volumio[1085]: info: Adding reference to registry Jun 05 15:36:24 volumio volumio[1085]: info: Done installing plugin. Jun 05 15:36:24 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 15:36:24 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 05 15:36:24 volumio volumio[1085]: info: Folder /tmp/plugins removed Jun 05 15:36:24 volumio volumio[1085]: info: Folder /tmp/downloaded_plugin.zip removed Jun 05 15:36:24 volumio volumio[1085]: info: Folder /data/temp removed Jun 05 15:36:25 volumio volumio[1085]: info: Enabling plugin Systeminfo Jun 05 15:36:25 volumio volumio[1085]: info: Loading plugin "Systeminfo"... Jun 05 15:36:26 volumio volumio[1085]: info: PLUGIN START: Systeminfo Jun 05 15:36:26 volumio volumio[1085]: info: Done. Jun 05 15:36:27 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:27 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:31 volumio nmbd[910]: [2025/06/05 15:36:31.124066, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jun 05 15:36:31 volumio nmbd[910]: Packet send failed to 169.254.255.255(138) ERRNO=Network is unreachable Jun 05 15:36:37 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:37 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:37 volumio volumio[1085]: info: Listing playlists Jun 05 15:36:37 volumio volumio[1085]: info: Listing playlists Jun 05 15:36:41 volumio volumio[1085]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 15:36:47 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:47 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:57 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:36:57 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:36:57 volumio volumio[1085]: info: Listing playlists Jun 05 15:36:57 volumio volumio[1085]: info: Listing playlists Jun 05 15:37:04 volumio volumio[1085]: info: Received OAUTH Data Jun 05 15:37:04 volumio volumio[1085]: info: Executing Spotify Oauth Login Jun 05 15:37:04 volumio volumio[1085]: info: Saving Spotify Refresh Token Jun 05 15:37:04 volumio volumio[1085]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 05 15:37:04 volumio volumio[1085]: SPOTIFY: BQDjcC_A9631wRDDHZfbwcCQKqatDRgIUycIjaV8FHbBK8jEsf1wqhcqVu20Qc0fmbpnXaRFAYKPwiLX4r7Ov17qcnU_5arCcSRs5WYbVB90tWYJMHVt9HMSJxT_VD7oVOCuOJFk4tVA1eNAljk_FfV6jEU4oTaomzBWsxi8uH8mm66YpzjC4MBW_lBtUAmAwuZEQyLn1LKgECeaJ2vlWf8A603IPBCuMlZHfrRkfZdZxsLH5ydyy6haRStimWFbUX7hWdavlJMLwbs9chjlDPKtqFU Jun 05 15:37:04 volumio volumio[1085]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 05 15:37:04 volumio volumio[1085]: info: New Spotify access token = BQDjcC_A9631wRDDHZfbwcCQKqatDRgIUycIjaV8FHbBK8jEsf1wqhcqVu20Qc0fmbpnXaRFAYKPwiLX4r7Ov17qcnU_5arCcSRs5WYbVB90tWYJMHVt9HMSJxT_VD7oVOCuOJFk4tVA1eNAljk_FfV6jEU4oTaomzBWsxi8uH8mm66YpzjC4MBW_lBtUAmAwuZEQyLn1LKgECeaJ2vlWf8A603IPBCuMlZHfrRkfZdZxsLH5ydyy6haRStimWFbUX7hWdavlJMLwbs9chjlDPKtqFU Jun 05 15:37:04 volumio volumio[1085]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 05 15:37:04 volumio volumio[1085]: SPOTIFY: User informations: {"country":"GB","display_name":"abc9999993","email":"abcattell91@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/abc9999993"},"followers":{"href":null,"total":12},"href":"https://api.spotify.com/v1/users/abc9999993","id":"abc9999993","images":[],"product":"premium","type":"user","uri":"spotify:user:abc9999993"} Jun 05 15:37:04 volumio volumio[1085]: info: Creating Spotify config file Jun 05 15:37:04 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 15:37:04 volumio volumio[1085]: info: Spotify config file written Jun 05 15:37:05 volumio sudo[6267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 05 15:37:05 volumio sudo[6267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:37:05 volumio volumio[1085]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 05 15:37:05 volumio volumio[1085]: SPOTIFY: BQDXst4FyZqkXmwvFQBFHlY0vxG5ecpbV1XV8jXPi1Dt-4M8BYSQqDb1zcK1j90i6sqL7dRMljNfA7Zb-hSf523z7fO0Sgnb5H1El7PSg2aQXpqiOA1Sap3l1YEew6svpF-3X1qUOxGNLw8IS5sHViuFofqBTZgfikonyjgRasxllkxhZ1hn0BOUL6gbL02MLDdKwwuRdxDTH9QOXbGDhia_6it3tHn6Kda5jWLLuOLDsJANSv_XG9Ex11_MwoOV-1SyJ2M3CIvya_oz8fJFIrzaOMs Jun 05 15:37:05 volumio volumio[1085]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 05 15:37:05 volumio volumio[1085]: info: New Spotify access token = BQDXst4FyZqkXmwvFQBFHlY0vxG5ecpbV1XV8jXPi1Dt-4M8BYSQqDb1zcK1j90i6sqL7dRMljNfA7Zb-hSf523z7fO0Sgnb5H1El7PSg2aQXpqiOA1Sap3l1YEew6svpF-3X1qUOxGNLw8IS5sHViuFofqBTZgfikonyjgRasxllkxhZ1hn0BOUL6gbL02MLDdKwwuRdxDTH9QOXbGDhia_6it3tHn6Kda5jWLLuOLDsJANSv_XG9Ex11_MwoOV-1SyJ2M3CIvya_oz8fJFIrzaOMs Jun 05 15:37:05 volumio volumio[1085]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 05 15:37:05 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 05 15:37:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jun 05 15:37:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jun 05 15:37:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 05 15:37:05 volumio volumio[1085]: info: Connection to go-librespot Websocket closed Jun 05 15:37:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 05 15:37:05 volumio sudo[6267]: pam_unix(sudo:session): session closed for user root Jun 05 15:37:05 volumio go-librespot[6272]: go-librespot daemon starting... Jun 05 15:37:05 volumio dbus-daemon[598]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.84' (uid=0 pid=6270 comm="timedatectl show --property=NTPSynchronized --valu") Jun 05 15:37:05 volumio volumio[1085]: SPOTIFY: User informations: {"country":"GB","display_name":"abc9999993","email":"abcattell91@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/abc9999993"},"followers":{"href":null,"total":12},"href":"https://api.spotify.com/v1/users/abc9999993","id":"abc9999993","images":[],"product":"premium","type":"user","uri":"spotify:user:abc9999993"} Jun 05 15:37:05 volumio volumio[1085]: info: Spotify Successfully logged in Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 15:37:05 volumio volumio[1085]: info: [1749134225223] CoreMusicLibrary::Adding element Spotify Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 15:37:05 volumio volumio[1085]: Cannot find translation for source YouTube2 Jun 05 15:37:05 volumio volumio[1085]: Cannot find translation for source YouTube Music Jun 05 15:37:05 volumio volumio[1085]: Cannot find translation for source Spotify Jun 05 15:37:05 volumio go-librespot[6273]: time="2025-06-05T15:37:05+01:00" level=info msg="running go-librespot 0.2.0" Jun 05 15:37:05 volumio go-librespot[6273]: time="2025-06-05T15:37:05+01:00" level=debug msg="app state loaded" Jun 05 15:37:05 volumio go-librespot[6273]: time="2025-06-05T15:37:05+01:00" level=debug msg="stored credentials not found" Jun 05 15:37:05 volumio go-librespot[6273]: time="2025-06-05T15:37:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 05 15:37:05 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 05 15:37:05 volumio sudo[6282]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 05 15:37:05 volumio sudo[6282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:37:05 volumio sudo[6282]: pam_unix(sudo:session): session closed for user root Jun 05 15:37:05 volumio sudo[6285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 05 15:37:05 volumio sudo[6285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:37:05 volumio sudo[6285]: pam_unix(sudo:session): session closed for user root Jun 05 15:37:05 volumio volumio[1085]: verbose: New Socket.io Connection to 192.168.1.150 from 192.168.1.233 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:139.0) Gecko/20100101 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 6 Jun 05 15:37:05 volumio dbus-daemon[598]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 05 15:37:05 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 05 15:37:05 volumio setdatetime-helper.sh[6269]: Time is not synchronized. Attempting to sync... Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::volumioGetVisibleSources Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:05 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 05 15:37:05 volumio volumio[1085]: info: Received Get System Info Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 15:37:05 volumio volumio[1085]: info: Discovery: Getting this device information Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:05 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:05 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:05 volumio volumio[1085]: info: Listing playlists Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 05 15:37:05 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 15:37:07 volumio volumio[1085]: info: Received Get System Info Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 15:37:07 volumio volumio[1085]: info: Discovery: Getting this device information Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:07 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 05 15:37:07 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:07 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:08 volumio volumio[1085]: info: Initializing connection to go-librespot Websocket Jun 05 15:37:08 volumio go-librespot[6273]: time="2025-06-05T15:37:08+01:00" level=debug msg="new websocket client" Jun 05 15:37:08 volumio volumio[1085]: info: Connection to go-librespot Websocket established Jun 05 15:37:08 volumio volumio[1085]: info: go-librespot daemon successfully initialized Jun 05 15:37:08 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 15:37:08 volumio volumio[1085]: info: Received Get System Info Jun 05 15:37:08 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 15:37:08 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 15:37:08 volumio volumio[1085]: info: Discovery: Getting this device information Jun 05 15:37:08 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:08 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:08 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 15:37:10 volumio go-librespot[6273]: time="2025-06-05T15:37:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 05 15:37:10 volumio go-librespot[6273]: time="2025-06-05T15:37:10+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 05 15:37:10 volumio go-librespot[6273]: time="2025-06-05T15:37:10+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 05 15:37:10 volumio go-librespot[6273]: time="2025-06-05T15:37:10+01:00" level=info msg="zeroconf server listening on port 38891" Jun 05 15:37:10 volumio sudo[6292]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 05 Jun 2025 14:37:12 GMT#015' Jun 05 15:37:10 volumio sudo[6292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 05 15:37:12 volumio setdatetime-helper.sh[6293]: Thu Jun 5 15:37:12 BST 2025 Jun 05 15:37:12 volumio sudo[6292]: pam_unix(sudo:session): session closed for user root Jun 05 15:37:12 volumio setdatetime-helper.sh[6269]: Time synchronized successfully. Jun 05 15:37:12 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 05 15:37:12 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 05 15:37:12 volumio volumio[1085]: info: Getting Spotify volume Jun 05 15:37:12 volumio volumio[1085]: info: Initializing connection to go-librespot Websocket Jun 05 15:37:12 volumio go-librespot[6273]: time="2025-06-05T15:37:12+01:00" level=debug msg="new websocket client" Jun 05 15:37:12 volumio volumio[1085]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 05 15:37:12 volumio volumio[1085]: info: Connection to go-librespot Websocket established Jun 05 15:37:12 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:12 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:12 volumio volumio[1085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 15:37:15 volumio volumio[1085]: info: Getting Spotify volume Jun 05 15:37:15 volumio volumio[1085]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 05 15:37:15 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:15 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:15 volumio volumio[1085]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 05 15:37:16 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 05 15:37:16 volumio go-librespot[6273]: time="2025-06-05T15:37:16+01:00" level=debug msg="obtained new client token: AAACWCEZnzrxiS9IlwO+whakVDfFSFa1O9ZB3l0cjWbclgdBscObgLxQjgiUzLt2vbhrbh7VNIcT8k7lNvCksZl8F1FLwWzMdFH1RgIrEfQRnF3tVamBuJoXnVXQZ2YNWJ1M//FQgPG7kd0mk3oi/iVD++cBFeXh1oV5pVdI+7nZ13WF99ymmIJWNNLFPgPvSx6lblRO93QJ+HxNF+KpIQl7GE/f+h/6Nr29Tb59XMmG+Ar1OdlnO+hm" Jun 05 15:37:18 volumio volumio[1085]: info: CoreCommandRouter::volumioGetState Jun 05 15:37:18 volumio volumio[1085]: info: CorePlayQueue::getTrack 0 Jun 05 15:37:18 volumio volumio[1085]: info: Listing playlists Jun 05 15:37:18 volumio volumio[1085]: info: Listing playlists Jun 05 15:37:21 volumio go-librespot[6273]: time="2025-06-05T15:37:21+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jun 05 15:37:21 volumio go-librespot[6273]: time="2025-06-05T15:37:21+01:00" level=debug msg="completed keyexchange" Jun 05 15:37:21 volumio go-librespot[6273]: time="2025-06-05T15:37:21+01:00" level=debug msg="completed challenge" Jun 05 15:37:21 volumio go-librespot[6273]: time="2025-06-05T15:37:21+01:00" level=info msg="authenticated AP as abc9999993" Jun 05 15:37:23 volumio volumio[1085]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jun 05 15:37:23 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jun 05 15:37:23 volumio volumio[1085]: info: Creating Spotify config file Jun 05 15:37:23 volumio volumio[1085]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 15:37:23 volumio volumio[1085]: info: Spotify config file written Jun 05 15:37:23 volumio sudo[6324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 05 15:37:23 volumio sudo[6324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 05 15:37:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jun 05 15:37:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 6278 (go-librespot) with signal SIGKILL. Jun 05 15:37:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jun 05 15:37:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 05 15:37:23 volumio volumio[1085]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 15:37:23 volumio volumio[1085]: Error: socket hang up Jun 05 15:37:23 volumio volumio[1085]: at connResetException (node:internal/errors:720:14) Jun 05 15:37:23 volumio volumio[1085]: at Socket.socketOnEnd (node:_http_client:519:23) Jun 05 15:37:23 volumio volumio[1085]: at Socket.emit (node:events:526:35) Jun 05 15:37:23 volumio volumio[1085]: at endReadableNT (node:internal/streams/readable:1376:12) Jun 05 15:37:23 volumio volumio[1085]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jun 05 15:37:23 volumio volumio[1085]: code: 'ECONNRESET', Jun 05 15:37:23 volumio volumio[1085]: response: undefined Jun 05 15:37:23 volumio volumio[1085]: } Jun 05 15:37:23 volumio volumio[1085]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 15:37:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 05 15:37:23 volumio go-librespot[6326]: go-librespot daemon starting... Jun 05 15:37:23 volumio sudo[6324]: pam_unix(sudo:session): session closed for user root Jun 05 15:37:23 volumio go-librespot[6338]: time="2025-06-05T15:37:23+01:00" level=info msg="running go-librespot 0.2.0" Jun 05 15:37:23 volumio go-librespot[6338]: time="2025-06-05T15:37:23+01:00" level=debug msg="app state loaded" Jun 05 15:37:23 volumio go-librespot[6338]: time="2025-06-05T15:37:23+01:00" level=debug msg="stored credentials not found" Jun 05 15:37:23 volumio go-librespot[6338]: time="2025-06-05T15:37:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 05 15:37:24 volumio sudo[6348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-05 15:36' Jun 05 15:37:24 volumio sudo[6348]: 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="a42e8353c03f8616e137cf760ea618e88c395461" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Jun 2 16:20:51 UTC 2025" VOLUMIO_VERSION="4.010" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f51ec0ad91e50bdfdb863e902a9e8fa2"