Feb 25 18:38:06 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:14 pifi sudo[17897]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 18:38:14 pifi sudo[17897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:14 pifi sudo[17899]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 18:38:14 pifi sudo[17899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:14 pifi sudo[17897]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:14 pifi sudo[17899]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:14 pifi volumio[1238]: verbose: New Socket.io Connection to 10.0.10.69 from 10.0.0.172 UA: Mozilla/5.0 (X11; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 6 Feb 25 18:38:14 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 18:38:14 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 25 18:38:15 pifi sudo[17905]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 18:38:15 pifi sudo[17905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:15 pifi sudo[17905]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:15 pifi sudo[17907]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 18:38:15 pifi sudo[17907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:15 pifi sudo[17907]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:15 pifi volumio[1238]: verbose: New Socket.io Connection to 10.0.10.69 from 10.0.0.172 UA: Mozilla/5.0 (X11; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 6 Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::volumioGetVisibleSources Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 25 18:38:15 pifi volumio[1238]: info: Received Get System Info Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:38:15 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:15 pifi volumio[1238]: info: Listing playlists Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 25 18:38:15 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:16 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 18:38:16 pifi volumio[1238]: info: Received Get System Info Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:38:16 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:38:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 25 18:38:20 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 18:38:20 pifi volumio[1238]: info: Received Get System Info Feb 25 18:38:20 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:38:20 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:38:20 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:38:20 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:20 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:38:25 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 25 18:38:26 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: info: Retrieving Cloud Streaming UI Feb 25 18:38:28 pifi volumio[1238]: info: Getting Tidal Cloud Configuration Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: info: Getting Qobuz Cloud Configuration Feb 25 18:38:28 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: info: Getting Spotify Cloud Configuration Feb 25 18:38:28 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: info: Saving Spotify Acccount Feb 25 18:38:28 pifi volumio[1238]: info: Got Tidal Cloud Configuration Feb 25 18:38:28 pifi volumio[1238]: info: Got it Feb 25 18:38:28 pifi volumio[1238]: info: Got it Feb 25 18:38:28 pifi volumio[1238]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:28 pifi volumio[1238]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:38:28 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 25 18:38:29 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:32 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 25 18:38:33 pifi volumio[1238]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 25 18:38:33 pifi volumio[1238]: info: Received Get System Version Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 18:38:33 pifi volumio[1238]: info: Received Get System Info Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:38:33 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:33 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:38:36 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:38:39 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:40 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:42 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:42 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 25 18:38:42 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Feb 25 18:38:42 pifi sudo[17951]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Feb 25 18:38:42 pifi sudo[17951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi sudo[17957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 25 18:38:42 pifi sudo[17957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi sudo[17957]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17951]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17963]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 25 18:38:42 pifi sudo[17963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Feb 25 18:38:42 pifi sudo[17969]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Feb 25 18:38:42 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Feb 25 18:38:42 pifi sudo[17969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi sudo[17963]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17975]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 18:38:42 pifi sudo[17975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi sudo[17969]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17975]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17979]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 18:38:42 pifi sudo[17979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:42 pifi sudo[17979]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:42 pifi sudo[17983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 18:38:42 pifi sudo[17983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:38:45 pifi sudo[17983]: pam_unix(sudo:session): session closed for user root Feb 25 18:38:46 pifi volumio[1238]: info: Received Get System Info Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:38:46 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 25 18:38:46 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 25 18:38:48 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:49 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Feb 25 18:38:50 pifi volumio[1238]: info: Received Get System Version Feb 25 18:38:50 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: info: Retrieving Cloud Streaming UI Feb 25 18:38:54 pifi volumio[1238]: info: Getting Tidal Cloud Configuration Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: info: Getting Qobuz Cloud Configuration Feb 25 18:38:54 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: info: Getting Spotify Cloud Configuration Feb 25 18:38:54 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: info: Saving Spotify Acccount Feb 25 18:38:54 pifi volumio[1238]: info: Got Tidal Cloud Configuration Feb 25 18:38:54 pifi volumio[1238]: info: Got it Feb 25 18:38:54 pifi volumio[1238]: info: Got it Feb 25 18:38:54 pifi volumio[1238]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:38:54 pifi volumio[1238]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:54 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:38:55 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:38:55 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand update Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: info: Feb 25 18:38:57 pifi volumio[1238]: ---------------------------- MPD announces state update: update Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand update took 5 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::getState Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: info: Feb 25 18:38:57 pifi volumio[1238]: ---------------------------- MPD announces state update: update Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::getState Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: info: Feb 25 18:38:57 pifi volumio[1238]: ---------------------------- MPD announces state update: update Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::getState Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 8 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 6 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 5 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 4 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 4 milliseconds Feb 25 18:38:57 pifi volumio[1238]: info: sendMpdCommand status took 3 milliseconds Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: info: Command Router : Notfying DB Updatetrue Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: info: Command Router : Notfying DB Updatetrue Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::Close All Modals sent Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: info: Command Router : Notfying DB Updatetrue Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::Close All Modals sent Feb 25 18:38:57 pifi volumio[1238]: verbose: ControllerMpd::parseState Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::servicePushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: CorePlayQueue::getTrack 0 Feb 25 18:38:57 pifi volumio[1238]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 18:38:57 pifi volumio[1238]: verbose: CURRENT POSITION 0 Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState stateService stop Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState currentStatus pause Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::servicePushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: CorePlayQueue::getTrack 0 Feb 25 18:38:57 pifi volumio[1238]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 18:38:57 pifi volumio[1238]: verbose: CURRENT POSITION 0 Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState stateService stop Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState currentStatus pause Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: ControllerMpd::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::servicePushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: CorePlayQueue::getTrack 0 Feb 25 18:38:57 pifi volumio[1238]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 25 18:38:57 pifi volumio[1238]: verbose: CURRENT POSITION 0 Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState stateService stop Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::syncState currentStatus pause Feb 25 18:38:57 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:38:57 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:38:57 pifi volumio[1238]: info: ------------------------------ 99ms Feb 25 18:38:57 pifi volumio[1238]: info: ------------------------------ 96ms Feb 25 18:38:57 pifi volumio[1238]: info: ------------------------------ 95ms Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:57 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:38:59 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:00 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:03 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:07 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:10 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:11 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:15 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 18:39:16 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 25 18:39:18 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:20 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:21 pifi volumio[1238]: info: Received OAUTH Data Feb 25 18:39:21 pifi volumio[1238]: info: Executing Spotify Oauth Login Feb 25 18:39:21 pifi volumio[1238]: info: Saving Spotify Refresh Token Feb 25 18:39:21 pifi volumio[1238]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 18:39:21 pifi volumio[1238]: SPOTIFY: BQBStaCA1dE5o9FoLh94lQpvCBIT2dREMM5eicbEZKPrEOFa2QDhRyK0ec1nBgTAQlEhogsbptlVXt2bVYD7k5xsKBCUKc-wbDXrgym_OXabxZXlaBxbPXRuxxO0ptZemUxrr6j35bhI5yvJEWlxtDlrkG7G3-gSz7kEqA9OmzfDs-OnzNS2wmukvuSIH5_uij1kT_BIslp1-L4exKhQo2gtPZlhFt1EmLc4tEFZrZVzTrpICpMxFomaOYJxV_vR6E_XcDDpT9XSOBdQbVWP7RPNV2bFPR0afA Feb 25 18:39:21 pifi volumio[1238]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 18:39:21 pifi volumio[1238]: info: New Spotify access token = BQBStaCA1dE5o9FoLh94lQpvCBIT2dREMM5eicbEZKPrEOFa2QDhRyK0ec1nBgTAQlEhogsbptlVXt2bVYD7k5xsKBCUKc-wbDXrgym_OXabxZXlaBxbPXRuxxO0ptZemUxrr6j35bhI5yvJEWlxtDlrkG7G3-gSz7kEqA9OmzfDs-OnzNS2wmukvuSIH5_uij1kT_BIslp1-L4exKhQo2gtPZlhFt1EmLc4tEFZrZVzTrpICpMxFomaOYJxV_vR6E_XcDDpT9XSOBdQbVWP7RPNV2bFPR0afA Feb 25 18:39:21 pifi volumio[1238]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 18:39:21 pifi sudo[18088]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 18:39:21 pifi sudo[18088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:39:21 pifi sudo[18088]: pam_unix(sudo:session): session closed for user root Feb 25 18:39:21 pifi sudo[18090]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 18:39:21 pifi sudo[18090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:39:21 pifi sudo[18090]: pam_unix(sudo:session): session closed for user root Feb 25 18:39:21 pifi volumio[1238]: verbose: New Socket.io Connection to 10.0.10.69 from 10.0.0.172 UA: Mozilla/5.0 (X11; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 6 Feb 25 18:39:21 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 18:39:22 pifi volumio[1238]: SPOTIFY: User informations: {"country":"AT","display_name":"netkenny","email":"kenny@kurio.at","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/kenny-at"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/kenny-at","id":"kenny-at","images":[],"product":"premium","type":"user","uri":"spotify:user:kenny-at"} Feb 25 18:39:22 pifi volumio[1238]: info: Creating Spotify config file Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 18:39:22 pifi volumio[1238]: info: Spotify config file written Feb 25 18:39:22 pifi sudo[18094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 18:39:22 pifi sudo[18094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 18:39:22 pifi systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 18:39:22 pifi systemd[1]: go-librespot-daemon.service: Killing process 1607 (go-librespot) with signal SIGKILL. Feb 25 18:39:22 pifi systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 18:39:22 pifi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 18:39:22 pifi systemd[1]: go-librespot-daemon.service: Consumed 7min 27.026s CPU time. Feb 25 18:39:22 pifi volumio[1238]: info: Connection to go-librespot Websocket closed Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::volumioGetVisibleSources Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 25 18:39:22 pifi volumio[1238]: info: Received Get System Info Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:39:22 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:22 pifi volumio[1238]: info: Listing playlists Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 25 18:39:22 pifi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 18:39:22 pifi sudo[18094]: pam_unix(sudo:session): session closed for user root Feb 25 18:39:22 pifi go-librespot[18096]: go-librespot daemon starting... Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=info msg="running go-librespot 0.4.0" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="app state loaded" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="stored credentials not found" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 18:39:22 pifi volumio[1238]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 18:39:22 pifi volumio[1238]: SPOTIFY: BQDOe_noel2bSFih8rfDS5NXAS4iXhrL6bUvbbUiKHu0As4b-0MG3CWiou4MEXfFIFom6-7LHYd2lV69knpQOXglAuaiyWksCgM4Vifs42RHTM9QPsZuAVnOYAh-vTDaLivLc_dm482R9Si4M-bB2LgOJL2LJzi_4j9vK0xIo9kMp0u4MOyiYne6skzmx6IkFku7ArUkMgd1sXjmdLqT6g8E05aKhHgoydDfofi7Z6p73O4xO7xluJgCOlKd85ASIhyeOwU4NLigrrwvpncAhyysA3VJxaytJw Feb 25 18:39:22 pifi volumio[1238]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 18:39:22 pifi volumio[1238]: info: New Spotify access token = BQDOe_noel2bSFih8rfDS5NXAS4iXhrL6bUvbbUiKHu0As4b-0MG3CWiou4MEXfFIFom6-7LHYd2lV69knpQOXglAuaiyWksCgM4Vifs42RHTM9QPsZuAVnOYAh-vTDaLivLc_dm482R9Si4M-bB2LgOJL2LJzi_4j9vK0xIo9kMp0u4MOyiYne6skzmx6IkFku7ArUkMgd1sXjmdLqT6g8E05aKhHgoydDfofi7Z6p73O4xO7xluJgCOlKd85ASIhyeOwU4NLigrrwvpncAhyysA3VJxaytJw Feb 25 18:39:22 pifi volumio[1238]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+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]" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+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]" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+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]" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=info msg="zeroconf server listening on port 44903" Feb 25 18:39:22 pifi volumio[1238]: SPOTIFY: User informations: {"country":"AT","display_name":"netkenny","email":"kenny@kurio.at","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/kenny-at"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/kenny-at","id":"kenny-at","images":[],"product":"premium","type":"user","uri":"spotify:user:kenny-at"} Feb 25 18:39:22 pifi volumio[1238]: info: Spotify Successfully logged in Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 18:39:22 pifi volumio[1238]: info: [1772041162353] CoreMusicLibrary::Adding element Spotify Feb 25 18:39:22 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 18:39:22 pifi volumio[1238]: Cannot find translation for source Spotify Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="obtained new client token: AADf5kx+LTsM5dld3jo4uI+95jbw2+AFurHtvXYHPYeHSjtxvLzeknsnsIxLUcj2gXfxivldmTMTBFshezuRbDOc2I1cB3UbtmT2aszzhHokIhOPgsfb+IQx7p0JfSQITJg2X7qwPAvzkIyPhxo2f9+ag8+dcQEDYAvI1wXQ7e8ZEySD7tlMpw4L7e2K6NSLHwurgHW71i289dbXMfV+/92urLe1R5lojAyrWloX2FOtADy6EItCpb8mB6E=" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="completed keyexchange" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="completed challenge" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=info msg="authenticated AP" username="ke****at" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=info msg="authenticated Login5" username="ke****at" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="stored credentials" username="ke****at" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="initializing zeroconf session" username="ke****at" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="dealer connection opened" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=trace msg="starting accesspoint recv loop" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=trace msg="starting dealer recv loop" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=trace msg="received accesspoint ping" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=debug msg="received connection id: MDVhNmMxZGItMmRi...NDRENTgyMEQ3MA==" Feb 25 18:39:22 pifi go-librespot[18097]: time="2026-02-25T18:39:22+01:00" level=trace msg="received accesspoint pong ack" Feb 25 18:39:23 pifi go-librespot[18097]: time="2026-02-25T18:39:23+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 18:39:23 pifi volumio[1238]: info: Received Get System Info Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:39:23 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:23 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="handling transfer player command from b0ef51298cc4f095a2d5870d0c926744f06c6e39" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="resolved context of track" uri="spotify:user:kenny-at:collection" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=trace msg="fetched new page 0 with 1549 items (list: 1549)" uri="spotify:user:kenny-at:collection" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="loading track (paused: false, position: 136547ms)" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1107" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=trace msg="emitting websocket event: will_play" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="selected format OGG_VORBIS_320 (07a9c2c52797c2b4e9c4cdb6f94600bd9a622242)" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=debug msg="requested aes key for file 07a9c2c52797c2b4e9c4cdb6f94600bd9a622242, gid: 127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:24 pifi go-librespot[18097]: time="2026-02-25T18:39:24+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:24 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 25 18:39:24 pifi volumio[1238]: info: Received Get System Info Feb 25 18:39:24 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:39:24 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:39:24 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:39:24 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:24 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:39:25 pifi volumio[1238]: info: Initializing connection to go-librespot Websocket Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="new websocket client" Feb 25 18:39:25 pifi volumio[1238]: info: Connection to go-librespot Websocket established Feb 25 18:39:25 pifi volumio[1238]: info: go-librespot daemon successfully initialized Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched first chunk of 20, total size is 9986200 bytes" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 16/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 15/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 13/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=trace msg="seek to 136547ms (diff: 48ms, samples: 6021722, bytes: 6924141)" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="created new output device" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=info msg="loaded track \"CHAINSAW PARADE\" (paused: false, position: 136547ms, duration: 198857ms, prefetched: false)" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=trace msg="scheduling prefetch in 32s" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=trace msg="emitting websocket event: metadata" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=trace msg="emitting websocket event: active" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="sending successful reply for dealer request" Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:127YGwSPhLRhEesYIEJVT5","name":"CHAINSAW PARADE","artist_names":["SISTO","Prosecute"],"album_name":"CHAINSAW PARADE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029ddc01795233630e540742c8","position":136547,"duration":198857,"release_date":"year:2022 month:1 day:31","track_number":1,"disc_number":1}} Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: received: {"type":"active","data":null} Feb 25 18:39:25 pifi volumio[1238]: info: Aligning Spotify Volume to Volumio Volume Feb 25 18:39:25 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:25 pifi volumio[1238]: info: Setting Spotify Volume from Volumio: 100 Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=trace msg="emitting websocket event: playing" Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:user:kenny-at:collection","uri":"spotify:track:127YGwSPhLRhEesYIEJVT5","resume":false,"play_origin":"collection/songs"}} Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: PUSH STATE SPOTIFY Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: {"status":"play","service":"spop","title":"CHAINSAW PARADE","artist":"SISTO, Prosecute","album":"CHAINSAW PARADE","albumart":"https://i.scdn.co/image/ab67616d00001e029ddc01795233630e540742c8","uri":"spotify:track:127YGwSPhLRhEesYIEJVT5","trackType":"spotify","seek":136547,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 25 18:39:25 pifi volumio[1238]: info: CoreCommandRouter::servicePushState Feb 25 18:39:25 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:39:25 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 18:39:25 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:39:25 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:39:25 pifi go-librespot[18097]: time="2026-02-25T18:39:25+01:00" level=debug msg="fetched chunk 14/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:26 pifi volumio[1238]: SPOTIFY: PUSH STATE SPOTIFY Feb 25 18:39:26 pifi volumio[1238]: SPOTIFY: {"status":"play","service":"spop","title":"CHAINSAW PARADE","artist":"SISTO, Prosecute","album":"CHAINSAW PARADE","albumart":"https://i.scdn.co/image/ab67616d00001e029ddc01795233630e540742c8","uri":"spotify:track:127YGwSPhLRhEesYIEJVT5","trackType":"spotify","seek":136547,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 25 18:39:26 pifi volumio[1238]: info: CoreCommandRouter::servicePushState Feb 25 18:39:26 pifi volumio[1238]: info: CoreStateMachine::pushState Feb 25 18:39:26 pifi volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 25 18:39:26 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:39:27 pifi volumio[1238]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Feb 25 18:39:27 pifi volumio[1238]: info: Sending Spotify command with payload to local API: /player/volume Feb 25 18:39:27 pifi go-librespot[18097]: time="2026-02-25T18:39:27+01:00" level=debug msg="update volume requested to 65535/65535" Feb 25 18:39:27 pifi go-librespot[18097]: time="2026-02-25T18:39:27+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 25 18:39:27 pifi go-librespot[18097]: time="2026-02-25T18:39:27+01:00" level=trace msg="emitting websocket event: volume" Feb 25 18:39:27 pifi volumio[1238]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Feb 25 18:39:27 pifi volumio[1238]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Feb 25 18:39:28 pifi volumio[1238]: info: Getting Spotify volume Feb 25 18:39:28 pifi volumio[1238]: info: Spotify volume: 100 Feb 25 18:39:28 pifi volumio[1238]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 25 18:39:28 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:28 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:39:28 pifi volumio[1238]: info: Initializing connection to go-librespot Websocket Feb 25 18:39:28 pifi go-librespot[18097]: time="2026-02-25T18:39:28+01:00" level=debug msg="new websocket client" Feb 25 18:39:28 pifi volumio[1238]: info: Connection to go-librespot Websocket established Feb 25 18:39:29 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:30 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:31 pifi volumio[1238]: info: Getting Spotify volume Feb 25 18:39:31 pifi volumio[1238]: info: Spotify volume: 100 Feb 25 18:39:31 pifi volumio[1238]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:31 pifi volumio[1238]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 25 18:39:31 pifi volumio[1238]: info: Getting Alsa Cards List without I2S DAC Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 25 18:39:31 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 25 18:39:33 pifi go-librespot[18097]: time="2026-02-25T18:39:33+01:00" level=debug msg="fetched chunk 17/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:35 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:36 pifi volumio[1238]: info: CoreCommandRouter::volumioGetQueue Feb 25 18:39:36 pifi volumio[1238]: info: CoreStateMachine::getQueue Feb 25 18:39:36 pifi volumio[1238]: info: CorePlayQueue::getQueue Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 25 18:39:39 pifi volumio[1238]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 25 18:39:39 pifi volumio[1238]: info: Received Get System Version Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 18:39:39 pifi volumio[1238]: info: Received Get System Info Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 18:39:39 pifi volumio[1238]: info: Discovery: Getting this device information Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:39 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 18:39:40 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:43 pifi volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 25 18:39:43 pifi go-librespot[18097]: time="2026-02-25T18:39:43+01:00" level=debug msg="fetched chunk 18/19, size: 524288" uri="spotify:track:127YGwSPhLRhEesYIEJVT5" Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: info: Retrieving Cloud Streaming UI Feb 25 18:39:44 pifi volumio[1238]: info: Getting Tidal Cloud Configuration Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: info: Getting Qobuz Cloud Configuration Feb 25 18:39:44 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: info: Getting Spotify Cloud Configuration Feb 25 18:39:44 pifi volumio[1238]: info: Asking plugin for UI Config Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: info: Saving Spotify Acccount Feb 25 18:39:44 pifi volumio[1238]: info: Got Tidal Cloud Configuration Feb 25 18:39:44 pifi volumio[1238]: info: Got it Feb 25 18:39:44 pifi volumio[1238]: info: Got it Feb 25 18:39:44 pifi volumio[1238]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 25 18:39:44 pifi volumio[1238]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::volumioGetBrowseSources Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:44 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 25 18:39:47 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Feb 25 18:39:47 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Feb 25 18:39:48 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:50 pifi kernel: nfs: server 10.0.30.4 not responding, timed out Feb 25 18:39:52 pifi volumio[1238]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 25 18:39:52 pifi volumio[1238]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 18:39:52 pifi go-librespot[18097]: time="2026-02-25T18:39:52+01:00" level=trace msg="sent dealer ping" Feb 25 18:39:52 pifi volumio[1238]: Error: dns service error: unknown Feb 25 18:39:52 pifi volumio[1238]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Feb 25 18:39:52 pifi volumio[1238]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Feb 25 18:39:52 pifi volumio[1238]: errorCode: -65537 Feb 25 18:39:52 pifi volumio[1238]: } Feb 25 18:39:52 pifi volumio[1238]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 18:39:52 pifi go-librespot[18097]: time="2026-02-25T18:39:52+01:00" level=trace msg="received dealer pong" Feb 25 18:39:53 pifi sudo[18201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 18:38' Feb 25 18:39:53 pifi sudo[18201]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"