Dec 05 20:03:00 volumio go-librespot[1505]: time="2025-12-05T20:03:00+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:00 volumio go-librespot[1505]: time="2025-12-05T20:03:00+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:00 volumio volumio[1215]: info: Updating MyVolumio device info Dec 05 20:03:00 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:00 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:00 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:00 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":74,"max":100}} Dec 05 20:03:00 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 74 Dec 05 20:03:00 volumio volumio[1215]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 20:03:01 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 20:03:01 volumio volumio[1215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 05 20:03:02 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:02 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:03 volumio volumio[1215]: info: MYVOLUMIO: Adding device Dec 05 20:03:03 volumio volumio[1215]: info: MYVOLUMIO: Evaluating Server Dec 05 20:03:03 volumio go-librespot[1505]: time="2025-12-05T20:03:03+01:00" level=trace msg="sent dealer ping" Dec 05 20:03:03 volumio go-librespot[1505]: time="2025-12-05T20:03:03+01:00" level=trace msg="received dealer pong" Dec 05 20:03:04 volumio volumio[1215]: info: Setting Geolocation for MyVolumio to eu4 Dec 05 20:03:04 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:04 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:04 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:05 volumio sudo[1724]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 20:03:05 volumio sudo[1724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:05 volumio sudo[1724]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:06 volumio volumio[1215]: info: Updating MyVolumio device info Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 05 20:03:06 volumio sudo[1727]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 20:03:06 volumio sudo[1727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:06 volumio sudo[1727]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:06 volumio volumio[1215]: verbose: New Socket.io Connection to 192.168.0.102 from 192.168.0.33 UA: Mozilla/5.0 (Linux; Android 15; 23124RA7EO Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::volumioGetBrowseSources Dec 05 20:03:06 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 20:03:07 volumio volumio[1215]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 20:03:07 volumio go-librespot[1505]: time="2025-12-05T20:03:07+01:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:03:08 volumio sudo[1735]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 20:03:08 volumio sudo[1735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:08 volumio sudo[1733]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 20:03:08 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:08 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:08 volumio sudo[1735]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:08 volumio volumio[1215]: verbose: New Socket.io Connection to 192.168.0.102 from 192.168.0.33 UA: Mozilla/5.0 (Linux; Android 15; 23124RA7EO Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:09 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 20:03:09 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:09 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:09 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:09 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:09 volumio volumio[1215]: info: Listing playlists Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 20:03:09 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:03:10 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:10 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:10 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:03:10 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:10 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:10 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:10 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:10 volumio volumio[1215]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 05 20:03:11 volumio volumio[1215]: info: Completed starting MyVolumio Plugin Dec 05 20:03:11 volumio volumio[1215]: [Metrics] CommandRouter: 66s 71.65ms Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::volumiosetStartupVolume Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 20:03:11 volumio volumio[1215]: info: VolumeController:: Setting startup Volume 90 Dec 05 20:03:11 volumio volumio[1215]: info: VolumeController::SetAlsaVolume90 Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::Close All Modals sent Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::Close All Modals sent Dec 05 20:03:11 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:11 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:11 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 05 20:03:11 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Dec 05 20:03:11 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 74 Dec 05 20:03:11 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 90 Dec 05 20:03:11 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 20:03:11 volumio volumio[1215]: info: Setting Spotify Volume from Volumio: 90 Dec 05 20:03:12 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 05 20:03:12 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 05 20:03:12 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 05 20:03:12 volumio volumio[1215]: info: Version has changed, forcing UI Reload Dec 05 20:03:12 volumio volumio[1215]: info: CoreCommandRouter::Reload Ui Dec 05 20:03:13 volumio sudo[1764]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 20:03:13 volumio sudo[1764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:13 volumio sudo[1764]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:13 volumio volumio[1215]: SPOTIFY: SETTING SPOTIFY VOLUME 90 Dec 05 20:03:13 volumio volumio[1215]: info: Sending Spotify command with payload to local API: /player/volume Dec 05 20:03:13 volumio sudo[1766]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 20:03:13 volumio sudo[1766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 20:03:13 volumio sudo[1766]: pam_unix(sudo:session): session closed for user root Dec 05 20:03:13 volumio go-librespot[1505]: time="2025-12-05T20:03:13+01:00" level=debug msg="update volume requested to 58981/65535" Dec 05 20:03:13 volumio go-librespot[1505]: time="2025-12-05T20:03:13+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:13 volumio go-librespot[1505]: time="2025-12-05T20:03:13+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:13 volumio volumio[1215]: verbose: New Socket.io Connection to 192.168.0.102 from 192.168.0.33 UA: Mozilla/5.0 (Linux; Android 15; 23124RA7EO Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 05 20:03:13 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":90,"max":100}} Dec 05 20:03:13 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 90 Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:14 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 20:03:14 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:14 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:14 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:14 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:14 volumio volumio[1215]: info: Listing playlists Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 20:03:14 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:03:15 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:15 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:15 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:03:15 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:15 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:15 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:15 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:16 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 05 20:03:16 volumio go-librespot[1505]: time="2025-12-05T20:03:16+01:00" level=debug msg="update volume requested to 58326/65535" Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:17 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":89,"max":100}} Dec 05 20:03:17 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 89 Dec 05 20:03:17 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 89 Dec 05 20:03:17 volumio volumio[1215]: info: VolumeController::SetAlsaVolume89 Dec 05 20:03:17 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:17 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:17 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:17 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:17 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 89 Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=debug msg="update volume requested to 57670/65535" Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:17 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":88,"max":100}} Dec 05 20:03:17 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 88 Dec 05 20:03:17 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 88 Dec 05 20:03:17 volumio volumio[1215]: info: VolumeController::SetAlsaVolume88 Dec 05 20:03:17 volumio go-librespot[1505]: time="2025-12-05T20:03:17+01:00" level=debug msg="update volume requested to 57015/65535" Dec 05 20:03:17 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:17 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:17 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:17 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":87,"max":100}} Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 87 Dec 05 20:03:18 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 87 Dec 05 20:03:18 volumio volumio[1215]: info: VolumeController::SetAlsaVolume87 Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="update volume requested to 55049/65535" Dec 05 20:03:18 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:18 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="update volume requested to 53083/65535" Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 87 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 88 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Dec 05 20:03:18 volumio volumio[1215]: info: BOOT COMPLETED Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":84,"max":100}} Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 84 Dec 05 20:03:18 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 84 Dec 05 20:03:18 volumio volumio[1215]: info: VolumeController::SetAlsaVolume84 Dec 05 20:03:18 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:18 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":81,"max":100}} Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 81 Dec 05 20:03:18 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 81 Dec 05 20:03:18 volumio volumio[1215]: info: VolumeController::SetAlsaVolume81 Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="update volume requested to 52427/65535" Dec 05 20:03:18 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:18 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:18 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 81 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 84 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 20:03:18 volumio volumio[1215]: info: Setting Spotify Volume from Volumio: 84 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 81 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 84 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 81 Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 05 20:03:18 volumio volumio[1215]: info: Setting Spotify Volume from Volumio: 81 Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:18 volumio go-librespot[1505]: time="2025-12-05T20:03:18+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Dec 05 20:03:18 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Dec 05 20:03:18 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 80 Dec 05 20:03:18 volumio volumio[1215]: info: VolumeController::SetAlsaVolume80 Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="update volume requested to 51772/65535" Dec 05 20:03:19 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:19 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="update volume requested to 49806/65535" Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Dec 05 20:03:19 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 79 Dec 05 20:03:19 volumio volumio[1215]: info: VolumeController::SetAlsaVolume79 Dec 05 20:03:19 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:19 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="update volume requested to 49151/65535" Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 79 Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 80 Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":76,"max":100}} Dec 05 20:03:19 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 76 Dec 05 20:03:19 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 76 Dec 05 20:03:19 volumio volumio[1215]: info: VolumeController::SetAlsaVolume76 Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:19 volumio go-librespot[1505]: time="2025-12-05T20:03:19+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:19 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:19 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:19 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=debug msg="update volume requested to 48495/65535" Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":75,"max":100}} Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 75 Dec 05 20:03:20 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 75 Dec 05 20:03:20 volumio volumio[1215]: info: VolumeController::SetAlsaVolume75 Dec 05 20:03:20 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:20 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: SPOTIFY VOLUME 75 Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: VOLUMIO VOLUME 76 Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: SETTING SPOTIFY VOLUME 81 Dec 05 20:03:20 volumio volumio[1215]: info: Sending Spotify command with payload to local API: /player/volume Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":74,"max":100}} Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 74 Dec 05 20:03:20 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 74 Dec 05 20:03:20 volumio volumio[1215]: info: VolumeController::SetAlsaVolume74 Dec 05 20:03:20 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:20 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=debug msg="update volume requested to 53083/65535" Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 05 20:03:20 volumio go-librespot[1505]: time="2025-12-05T20:03:20+01:00" level=trace msg="emitting websocket event: volume" Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: received: {"type":"volume","data":{"value":81,"max":100}} Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED SPOTIFY VOLUME 81 Dec 05 20:03:20 volumio volumio[1215]: info: Setting Volumio Volume from Spotify: 81 Dec 05 20:03:20 volumio volumio[1215]: info: VolumeController::SetAlsaVolume81 Dec 05 20:03:20 volumio volumio[1215]: info: CoreStateMachine::pushState Dec 05 20:03:20 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 20:03:20 volumio volumio[1215]: info: CoreCommandRouter::volumioPushState Dec 05 20:03:20 volumio volumio[1215]: SPOTIFY: RECEIVED VOLUMIO VOLUME 81 Dec 05 20:03:23 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 05 20:03:24 volumio volumio[1215]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 20:03:24 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 05 20:03:25 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 05 20:03:25 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 05 20:03:26 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Dec 05 20:03:26 volumio volumio[1215]: info: Received Get System Version Dec 05 20:03:26 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 20:03:28 volumio upmpdcli[1817]: writing RSA key Dec 05 20:03:29 volumio volumio-remote-updater[701]: Test mode disabled Dec 05 20:03:29 volumio volumio-remote-updater[701]: Alpha mode disabled Dec 05 20:03:29 volumio volumio-remote-updater[701]: Alpha legacy test mode disabled Dec 05 20:03:29 volumio volumio[1215]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 05 20:03:29 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::Close All Modals sent Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 20:03:31 volumio volumio[1215]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 05 20:03:31 volumio volumio[1215]: info: Received Get System Version Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 20:03:31 volumio volumio[1215]: info: Received Get System Info Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 20:03:31 volumio volumio[1215]: info: Discovery: Getting this device information Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::volumioGetState Dec 05 20:03:31 volumio volumio[1215]: info: CorePlayQueue::getTrack 0 Dec 05 20:03:31 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 20:03:32 volumio go-librespot[1505]: time="2025-12-05T20:03:32+01:00" level=debug msg="fetched chunk 7/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:03:33 volumio go-librespot[1505]: time="2025-12-05T20:03:33+01:00" level=trace msg="sent dealer ping" Dec 05 20:03:33 volumio go-librespot[1505]: time="2025-12-05T20:03:33+01:00" level=trace msg="received dealer pong" Dec 05 20:03:36 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:03:36 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 20:03:45 volumio go-librespot[1505]: time="2025-12-05T20:03:45+01:00" level=debug msg="fetched chunk 8/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:03:55 volumio volumio[1215]: info: Starting Uninstall of plugin user_interface - now_playing Dec 05 20:03:59 volumio go-librespot[1505]: time="2025-12-05T20:03:59+01:00" level=debug msg="fetched chunk 9/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:04:03 volumio go-librespot[1505]: time="2025-12-05T20:04:03+01:00" level=trace msg="sent dealer ping" Dec 05 20:04:03 volumio go-librespot[1505]: time="2025-12-05T20:04:03+01:00" level=trace msg="received dealer pong" Dec 05 20:04:07 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:04:07 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 20:04:10 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:10 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:10 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:10 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:10 volumio volumio[1215]: Require stack: Dec 05 20:04:10 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:10 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:10 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:10 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:10 volumio volumio[1215]: Require stack: Dec 05 20:04:10 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:10 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:10 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:10 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:10 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:10 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:10 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:10 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:10 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:10 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:10 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:10 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:10 volumio volumio[1215]: info: Done. Dec 05 20:04:11 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:12 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:12 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:12 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:12 volumio volumio[1215]: Require stack: Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:12 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:12 volumio volumio[1215]: Require stack: Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:12 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:12 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:12 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:12 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:12 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:12 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:12 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:12 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:12 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:12 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:12 volumio go-librespot[1505]: time="2025-12-05T20:04:12+01:00" level=debug msg="fetched chunk 10/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:04:12 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:12 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:12 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:12 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:12 volumio volumio[1215]: Require stack: Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:12 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:12 volumio volumio[1215]: Require stack: Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:12 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:12 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:12 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:12 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:12 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:12 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:12 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:12 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:12 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:12 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:12 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:13 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:13 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:13 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:13 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:13 volumio volumio[1215]: Require stack: Dec 05 20:04:13 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:13 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:13 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:13 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:13 volumio volumio[1215]: Require stack: Dec 05 20:04:13 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:13 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:13 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:13 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:13 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:13 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:13 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:13 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:13 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:13 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:13 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:13 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:13 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:14 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:14 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:14 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:14 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:14 volumio volumio[1215]: Require stack: Dec 05 20:04:14 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:14 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:14 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:14 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:14 volumio volumio[1215]: Require stack: Dec 05 20:04:14 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:14 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:14 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:14 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:14 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:14 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:14 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:14 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:14 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:14 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:14 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:14 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:14 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:14 volumio volumio[1215]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 20:04:16 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 20:04:16 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 20:04:18 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:18 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:18 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:18 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:18 volumio volumio[1215]: Require stack: Dec 05 20:04:18 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:18 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:18 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:18 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:18 volumio volumio[1215]: Require stack: Dec 05 20:04:18 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:18 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:18 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:18 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:18 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:18 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:18 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:18 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:18 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:18 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:18 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:18 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:18 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:19 volumio volumio[1215]: info: Starting Uninstall of plugin user_interface - now_playing Dec 05 20:04:19 volumio volumio[1215]: info: Uninstalling plugin now_playing Dec 05 20:04:24 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:24 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:24 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:24 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:24 volumio volumio[1215]: Require stack: Dec 05 20:04:24 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:24 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:24 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:24 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:24 volumio volumio[1215]: Require stack: Dec 05 20:04:24 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:24 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:24 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:24 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:24 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:24 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:24 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:24 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:24 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:24 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:24 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:24 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:24 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:25 volumio go-librespot[1505]: time="2025-12-05T20:04:25+01:00" level=debug msg="fetched chunk 11/12, size: 524288" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:04:26 volumio volumio[1215]: info: Starting Uninstall of plugin user_interface - now_playing Dec 05 20:04:26 volumio volumio[1215]: info: Uninstalling plugin now_playing Dec 05 20:04:28 volumio volumio[1215]: info: Enabling plugin now_playing Dec 05 20:04:28 volumio volumio[1215]: info: Loading plugin "now_playing"... Dec 05 20:04:28 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:28 volumio volumio[1215]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:28 volumio volumio[1215]: Require stack: Dec 05 20:04:28 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:28 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:28 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:28 volumio volumio[1215]: error: Stack trace: Error: Cannot find module '/data/plugins//user_interface/now_playing/./dist/index.js' Dec 05 20:04:28 volumio volumio[1215]: Require stack: Dec 05 20:04:28 volumio volumio[1215]: - /volumio/app/pluginmanager.js Dec 05 20:04:28 volumio volumio[1215]: - /volumio/app/index.js Dec 05 20:04:28 volumio volumio[1215]: - /volumio/index.js Dec 05 20:04:28 volumio volumio[1215]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Dec 05 20:04:28 volumio volumio[1215]: at Module._load (node:internal/modules/cjs/loader:901:27) Dec 05 20:04:28 volumio volumio[1215]: at Module.require (node:internal/modules/cjs/loader:1115:19) Dec 05 20:04:28 volumio volumio[1215]: at require (node:internal/modules/helpers:130:18) Dec 05 20:04:28 volumio volumio[1215]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Dec 05 20:04:28 volumio volumio[1215]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 05 20:04:28 volumio volumio[1215]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 05 20:04:28 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:28 volumio volumio[1215]: error: !!!! WARNING !!!! Dec 05 20:04:28 volumio volumio[1215]: info: Error: TypeError: Cannot read properties of null (reading 'printToastMessage') Dec 05 20:04:33 volumio go-librespot[1505]: time="2025-12-05T20:04:33+01:00" level=trace msg="received accesspoint ping" Dec 05 20:04:33 volumio go-librespot[1505]: time="2025-12-05T20:04:33+01:00" level=trace msg="received accesspoint pong ack" Dec 05 20:04:33 volumio go-librespot[1505]: time="2025-12-05T20:04:33+01:00" level=trace msg="sent dealer ping" Dec 05 20:04:33 volumio go-librespot[1505]: time="2025-12-05T20:04:33+01:00" level=trace msg="received dealer pong" Dec 05 20:04:36 volumio volumio[1215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 05 20:04:38 volumio go-librespot[1505]: time="2025-12-05T20:04:38+01:00" level=debug msg="fetched chunk 12/12, size: 354598" uri="spotify:track:0f7sFuSS6GiZEnNA9AHMsJ" Dec 05 20:04:40 volumio volumio[1215]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/download/now_playing/1.0.1/volumio/bookworm/armhf Dec 05 20:04:40 volumio volumio[1215]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 20:04:40 volumio volumio[1215]: TypeError: Cannot read properties of null (reading 'broadcastMessage') Dec 05 20:04:40 volumio volumio[1215]: at /volumio/app/index.js:1534:32 Dec 05 20:04:40 volumio volumio[1215]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Dec 05 20:04:40 volumio volumio[1215]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Dec 05 20:04:40 volumio volumio[1215]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Dec 05 20:04:40 volumio volumio[1215]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Dec 05 20:04:40 volumio volumio[1215]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Dec 05 20:04:40 volumio volumio[1215]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1453:22) Dec 05 20:04:40 volumio volumio[1215]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1220:47) Dec 05 20:04:40 volumio volumio[1215]: at Socket.emit (node:events:514:28) Dec 05 20:04:40 volumio volumio[1215]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 05 20:04:40 volumio volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 05 20:04:40 volumio volumio[1215]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 20:04:47 volumio sudo[1965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 20:03' Dec 05 20:04:47 volumio sudo[1965]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"