May 29 11:21:01 testing volumio[1281]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
May 29 11:21:01 testing volumio[1281]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
May 29 11:21:01 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 11:21:01 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 11:21:01 testing volumio[1281]: info: Starting MyVolumio Remote Streaming Endpoints
May 29 11:21:01 testing volumio[1281]: info: MyVolumio not started
May 29 11:21:01 testing volumio[1281]: info: Initializing device activation check
May 29 11:21:01 testing volumio[1281]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
May 29 11:21:01 testing volumio[1281]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
May 29 11:21:04 testing volumio[1281]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
May 29 11:21:04 testing volumio[1281]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
May 29 11:21:04 testing volumio[1281]: info: Streaming services startup
May 29 11:21:04 testing volumio[1281]: info: Starting Streaming Daemon
May 29 11:21:05 testing sudo[1615]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 29 11:21:05 testing sudo[1615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:05 testing volumio[1281]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
May 29 11:21:05 testing sudo[1615]: pam_unix(sudo:session): session closed for user root
May 29 11:21:05 testing volumio[1281]: error: Cannot start Volumio Streaming Daemon
May 29 11:21:05 testing volumio[1281]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 29 11:21:05 testing volumio[1281]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 29 11:21:08 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 11:21:08 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 11:21:08 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:21:08 testing volumio-remote-updater[572]: No test mode
May 29 11:21:08 testing volumio-remote-updater[572]: Alpha test mode enabled
May 29 11:21:08 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 29 11:21:08 testing volumio[1281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\nUpdater 1.8.12
\nRelease channel selector
\n
\nFIXES
\n\nUpstream Realtek modules
\nForce updater static libs
\n\n","title":"Update v4.004","updateavailable":true}
May 29 11:21:09 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 11:21:10 testing sudo[1630]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 29 11:21:10 testing sudo[1630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:10 testing sudo[1630]: pam_unix(sudo:session): session closed for user root
May 29 11:21:10 testing sudo[1632]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 29 11:21:10 testing sudo[1632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:11 testing sudo[1632]: pam_unix(sudo:session): session closed for user root
May 29 11:21:11 testing volumio[1281]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.7 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::volumioGetVisibleSources
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:11 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 29 11:21:11 testing volumio[1281]: info: Received Get System Info
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:11 testing systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
May 29 11:21:11 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:11 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:11 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:11 testing volumio[1281]: info: Listing playlists
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 29 11:21:11 testing dbus-daemon[561]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.24' (uid=0 pid=1636 comm="timedatectl show --property=NTPSynchronized --valu")
May 29 11:21:11 testing systemd[1]: Starting systemd-timedated.service - Time & Date Service...
May 29 11:21:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 29 11:21:12 testing dbus-daemon[561]: [system] Successfully activated service 'org.freedesktop.timedate1'
May 29 11:21:12 testing systemd[1]: Started systemd-timedated.service - Time & Date Service.
May 29 11:21:12 testing setdatetime-helper.sh[1635]: Time is not synchronized. Attempting to sync...
May 29 11:21:12 testing sudo[1654]:     root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 29 May 2025 15:21:12 GMT#015'
May 29 11:21:12 testing sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 11:21:12 testing setdatetime-helper.sh[1659]: Thu May 29 11:21:12 EDT 2025
May 29 11:21:12 testing systemd-journald[330]: Time jumped backwards, rotating.
May 29 11:21:12 testing systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
May 29 11:21:12 testing setdatetime-helper.sh[1635]: Time synchronized successfully.
May 29 11:21:12 testing sudo[1654]: pam_unix(sudo:session): session closed for user root
May 29 11:21:12 testing systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
May 29 11:21:12 testing sudo[1663]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 29 11:21:12 testing sudo[1665]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 29 11:21:12 testing sudo[1665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:12 testing sudo[1663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:12 testing sudo[1665]: pam_unix(sudo:session): session closed for user root
May 29 11:21:12 testing sudo[1663]: pam_unix(sudo:session): session closed for user root
May 29 11:21:12 testing volumio[1281]: verbose: New Socket.io Connection to 192.168.1.106 from 192.168.1.7 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::volumioGetVisibleSources
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:12 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 29 11:21:12 testing volumio[1281]: info: Received Get System Info
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:12 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:12 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:12 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:12 testing volumio[1281]: info: Listing playlists
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 29 11:21:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 29 11:21:13 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:13 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 29 11:21:14 testing volumio[1281]: info: Received Get System Info
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:14 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:14 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:14 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
May 29 11:21:15 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 29 11:21:15 testing volumio[1281]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
May 29 11:21:16 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:16 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:16 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: wizard , setOnboardingWizardFalse
May 29 11:21:17 testing volumio-remote-updater[572]: No test mode
May 29 11:21:17 testing volumio-remote-updater[572]: Alpha test mode enabled
May 29 11:21:17 testing volumio-remote-updater[572]: No test mode
May 29 11:21:17 testing volumio-remote-updater[572]: Alpha test mode enabled
May 29 11:21:17 testing volumio[1281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\nUpdater 1.8.12
\nRelease channel selector
\n
\nFIXES
\n\nUpstream Realtek modules
\nForce updater static libs
\n\n","title":"Update v4.004","updateavailable":true}
May 29 11:21:17 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 11:21:18 testing volumio-remote-updater[572]: No test mode
May 29 11:21:18 testing volumio-remote-updater[572]: Alpha test mode enabled
May 29 11:21:18 testing volumio-remote-updater[572]: No test mode
May 29 11:21:18 testing volumio-remote-updater[572]: Alpha test mode enabled
May 29 11:21:18 testing volumio[1281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\nUpdater 1.8.12
\nRelease channel selector
\n
\nFIXES
\n\nUpstream Realtek modules
\nForce updater static libs
\n\n","title":"Update v4.004","updateavailable":true}
May 29 11:21:18 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 11:21:18 testing volumio[1281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\nUpdater 1.8.12
\nRelease channel selector
\n
\nFIXES
\n\nUpstream Realtek modules
\nForce updater static libs
\n\n","title":"Update v4.004","updateavailable":true}
May 29 11:21:18 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 11:21:18 testing volumio[1281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\nUpdater 1.8.12
\nRelease channel selector
\n
\nFIXES
\n\nUpstream Realtek modules
\nForce updater static libs
\n\n","title":"Update v4.004","updateavailable":true}
May 29 11:21:18 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::volumioGetBrowseSources
May 29 11:21:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 11:21:21 testing volumio[1281]: info: Update: [object Object]
May 29 11:21:21 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , checkSystemIntegrity
May 29 11:21:21 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 11:21:22 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
May 29 11:21:23 testing volumio[1281]: info: CoreCommandRouter::Close All Modals sent
May 29 11:21:23 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , setTOSAccepted
May 29 11:21:24 testing volumio[1281]: error: MyVolumio Plugin failed to authenticate in a timely fashion
May 29 11:21:24 testing volumio[1281]: info: Completed starting MyVolumio Plugin
May 29 11:21:24 testing volumio[1281]:  [Metrics]  CommandRouter:  58s 205.66ms 
May 29 11:21:24 testing volumio[1281]: info: CoreCommandRouter::volumiosetStartupVolume
May 29 11:21:24 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 11:21:24 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 11:21:24 testing volumio[1281]: info: CoreCommandRouter::Close All Modals sent
May 29 11:21:24 testing volumio[1281]: info: CoreCommandRouter::Close All Modals sent
May 29 11:21:25 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
May 29 11:21:25 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
May 29 11:21:25 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 29 11:21:30 testing volumio[1281]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
May 29 11:21:30 testing volumio[1281]: info: Received Get System Version
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 11:21:30 testing volumio[1281]: info: Received Get System Info
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:30 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:30 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:31 testing volumio[1281]: info: BOOT COMPLETED
May 29 11:21:41 testing systemd[1]: systemd-timedated.service: Deactivated successfully.
May 29 11:21:54 testing sudo[1749]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 29 11:21:54 testing sudo[1749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:54 testing sudo[1751]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 29 11:21:54 testing sudo[1749]: pam_unix(sudo:session): session closed for user root
May 29 11:21:54 testing sudo[1751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:21:54 testing sudo[1751]: pam_unix(sudo:session): session closed for user root
May 29 11:21:55 testing volumio[1281]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.7 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: Received Get System Info
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:55 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetVisibleSources
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 29 11:21:55 testing volumio[1281]: info: Received Get System Info
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:21:55 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:21:55 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:21:55 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:21:55 testing volumio[1281]: info: Listing playlists
May 29 11:21:56 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 29 11:21:59 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , setTestSystem
May 29 11:21:59 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , checkUpdates
May 29 11:21:59 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:21:59 testing volumio-remote-updater[572]: PROGRESS: 0, STATUS: "Starting update", ETA: "6m"
May 29 11:21:59 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , notifyProgress
May 29 11:21:59 testing volumio-remote-updater[1755]: /bin/rm: cannot remove '/imgpart/rck*': No such file or directory
May 29 11:21:59 testing volumio-remote-updater[1755]: /bin/rm: cannot remove '/imgpart/*.part': No such file or directory
May 29 11:21:59 testing volumio-remote-updater[1755]: /bin/rm: cannot remove '/imgpart/*.zs-old': No such file or directory
May 29 11:21:59 testing volumio-remote-updater[572]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
May 29 11:22:00 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 29 11:22:00 testing volumio-remote-updater[572]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
May 29 11:22:00 testing volumio-remote-updater[572]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
May 29 11:22:00 testing volumio-remote-updater[572]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
May 29 11:22:00 testing volumio[1281]: info: Killing processes that might interfere with OTA Updates
May 29 11:22:00 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:00 testing volumio[1281]: updateProgress
May 29 11:22:00 testing sudo[1775]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall matchbox-keyboard
May 29 11:22:00 testing sudo[1775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:22:00 testing sudo[1777]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall matchbox-window-manager
May 29 11:22:00 testing sudo[1777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:22:00 testing volumio[1281]: {
May 29 11:22:00 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:00 testing volumio[1281]:   eta: '5m',
May 29 11:22:00 testing volumio[1281]:   progress: 5,
May 29 11:22:00 testing volumio[1281]:   status: 'Preparing update'
May 29 11:22:00 testing volumio[1281]: }
May 29 11:22:00 testing sudo[1775]: pam_unix(sudo:session): session closed for user root
May 29 11:22:00 testing volumio[1281]: error: Cannot kill process: Error: Command failed: /usr/bin/sudo /usr/bin/killall matchbox-keyboard
May 29 11:22:00 testing volumio[1281]: matchbox-keyboard: no process found
May 29 11:22:00 testing sudo[1777]: pam_unix(sudo:session): session closed for user root
May 29 11:22:00 testing volumio[1281]: error: Cannot kill process: Error: Command failed: /usr/bin/sudo /usr/bin/killall matchbox-window-manager
May 29 11:22:00 testing volumio[1281]: matchbox-window-manager: no process found
May 29 11:22:02 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:02 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:02 testing volumio[1281]: updateProgress
May 29 11:22:02 testing volumio[1281]: {
May 29 11:22:02 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:02 testing volumio[1281]:   eta: '5m',
May 29 11:22:02 testing volumio[1281]:   progress: 10,
May 29 11:22:02 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:02 testing volumio[1281]: }
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:03 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:03 testing volumio[1281]: updateProgress
May 29 11:22:03 testing volumio[1281]: {
May 29 11:22:03 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:03 testing volumio[1281]:   eta: '5m',
May 29 11:22:03 testing volumio[1281]:   progress: 10,
May 29 11:22:03 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:03 testing volumio[1281]: }
May 29 11:22:04 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:04 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:04 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:04 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:04 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:04 testing volumio[1281]: updateProgress
May 29 11:22:04 testing volumio[1281]: {
May 29 11:22:04 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:04 testing volumio[1281]:   eta: '5m',
May 29 11:22:04 testing volumio[1281]:   progress: 10,
May 29 11:22:04 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:04 testing volumio[1281]: }
May 29 11:22:04 testing upmpdcli[1804]: writing RSA key
May 29 11:22:05 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
May 29 11:22:05 testing volumio-remote-updater[572]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:05 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:05 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:05 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:05 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:05 testing volumio[1281]: updateProgress
May 29 11:22:05 testing volumio[1281]: {
May 29 11:22:05 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:05 testing volumio[1281]:   eta: '5m',
May 29 11:22:05 testing volumio[1281]:   progress: 11,
May 29 11:22:05 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:05 testing volumio[1281]: }
May 29 11:22:07 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:07 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:07 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:07 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:07 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:07 testing volumio[1281]: updateProgress
May 29 11:22:07 testing volumio[1281]: {
May 29 11:22:07 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:07 testing volumio[1281]:   eta: '5m',
May 29 11:22:07 testing volumio[1281]:   progress: 11,
May 29 11:22:07 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:07 testing volumio[1281]: }
May 29 11:22:08 testing volumio-remote-updater[572]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:08 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:08 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:08 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:08 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:08 testing volumio[1281]: updateProgress
May 29 11:22:08 testing volumio[1281]: {
May 29 11:22:08 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:08 testing volumio[1281]:   eta: '5m',
May 29 11:22:08 testing volumio[1281]:   progress: 12,
May 29 11:22:08 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:08 testing volumio[1281]: }
May 29 11:22:09 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:09 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:09 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:09 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:10 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:10 testing volumio[1281]: updateProgress
May 29 11:22:10 testing volumio[1281]: {
May 29 11:22:10 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:10 testing volumio[1281]:   eta: '5m',
May 29 11:22:10 testing volumio[1281]:   progress: 12,
May 29 11:22:10 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:10 testing volumio[1281]: }
May 29 11:22:11 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:11 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:11 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:11 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:11 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:11 testing volumio[1281]: updateProgress
May 29 11:22:11 testing volumio[1281]: {
May 29 11:22:11 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:11 testing volumio[1281]:   eta: '5m',
May 29 11:22:11 testing volumio[1281]:   progress: 12,
May 29 11:22:11 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:11 testing volumio[1281]: }
May 29 11:22:12 testing volumio-remote-updater[572]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:12 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:12 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:12 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:12 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:12 testing volumio[1281]: updateProgress
May 29 11:22:12 testing volumio[1281]: {
May 29 11:22:12 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:12 testing volumio[1281]:   eta: '5m',
May 29 11:22:12 testing volumio[1281]:   progress: 13,
May 29 11:22:12 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:12 testing volumio[1281]: }
May 29 11:22:13 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:13 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:13 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:13 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:13 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:13 testing volumio[1281]: updateProgress
May 29 11:22:13 testing volumio[1281]: {
May 29 11:22:13 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:13 testing volumio[1281]:   eta: '5m',
May 29 11:22:13 testing volumio[1281]:   progress: 13,
May 29 11:22:13 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:13 testing volumio[1281]: }
May 29 11:22:13 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:13 testing volumio[1281]: updateProgress
May 29 11:22:13 testing volumio[1281]: {
May 29 11:22:13 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:13 testing volumio[1281]:   eta: '5m',
May 29 11:22:13 testing volumio[1281]:   progress: 13,
May 29 11:22:13 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:13 testing volumio[1281]: }
May 29 11:22:15 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:15 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:15 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:15 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:15 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:15 testing volumio[1281]: updateProgress
May 29 11:22:15 testing volumio[1281]: {
May 29 11:22:15 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:15 testing volumio[1281]:   eta: '5m',
May 29 11:22:15 testing volumio[1281]:   progress: 13,
May 29 11:22:15 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:15 testing volumio[1281]: }
May 29 11:22:16 testing volumio-remote-updater[572]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:16 testing volumio-remote-updater[572]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:16 testing volumio-remote-updater[572]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:16 testing volumio-remote-updater[572]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:16 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:16 testing volumio[1281]: updateProgress
May 29 11:22:16 testing volumio[1281]: {
May 29 11:22:16 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:16 testing volumio[1281]:   eta: '5m',
May 29 11:22:16 testing volumio[1281]:   progress: 14,
May 29 11:22:16 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:16 testing volumio[1281]: }
May 29 11:22:17 testing volumio-remote-updater[572]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:17 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:17 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:17 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:17 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:17 testing volumio[1281]: updateProgress
May 29 11:22:17 testing volumio[1281]: {
May 29 11:22:17 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:17 testing volumio[1281]:   eta: '5m',
May 29 11:22:17 testing volumio[1281]:   progress: 15,
May 29 11:22:17 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:17 testing volumio[1281]: }
May 29 11:22:19 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:19 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:19 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:19 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:19 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:19 testing volumio[1281]: updateProgress
May 29 11:22:19 testing volumio[1281]: {
May 29 11:22:19 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:19 testing volumio[1281]:   eta: '5m',
May 29 11:22:19 testing volumio[1281]:   progress: 15,
May 29 11:22:19 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:19 testing volumio[1281]: }
May 29 11:22:20 testing volumio-remote-updater[572]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:20 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:20 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:20 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:20 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:20 testing volumio[1281]: updateProgress
May 29 11:22:20 testing volumio[1281]: {
May 29 11:22:20 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:20 testing volumio[1281]:   eta: '5m',
May 29 11:22:20 testing volumio[1281]:   progress: 16,
May 29 11:22:20 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:20 testing volumio[1281]: }
May 29 11:22:21 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:21 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:21 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:21 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:21 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:21 testing volumio[1281]: updateProgress
May 29 11:22:21 testing volumio[1281]: {
May 29 11:22:21 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:21 testing volumio[1281]:   eta: '5m',
May 29 11:22:21 testing volumio[1281]:   progress: 16,
May 29 11:22:21 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:21 testing volumio[1281]: }
May 29 11:22:23 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:23 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:23 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:23 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:23 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:23 testing volumio[1281]: updateProgress
May 29 11:22:23 testing volumio[1281]: {
May 29 11:22:23 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:23 testing volumio[1281]:   eta: '5m',
May 29 11:22:23 testing volumio[1281]:   progress: 16,
May 29 11:22:23 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:23 testing volumio[1281]: }
May 29 11:22:24 testing volumio-remote-updater[572]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:24 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:24 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:24 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:24 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:24 testing volumio[1281]: updateProgress
May 29 11:22:24 testing volumio[1281]: {
May 29 11:22:24 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:24 testing volumio[1281]:   eta: '5m',
May 29 11:22:24 testing volumio[1281]:   progress: 17,
May 29 11:22:24 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:24 testing volumio[1281]: }
May 29 11:22:26 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:26 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:26 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:26 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:26 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:26 testing volumio[1281]: updateProgress
May 29 11:22:26 testing volumio[1281]: {
May 29 11:22:26 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:26 testing volumio[1281]:   eta: '5m',
May 29 11:22:26 testing volumio[1281]:   progress: 17,
May 29 11:22:26 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:26 testing volumio[1281]: }
May 29 11:22:28 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:28 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:28 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:28 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:28 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:28 testing volumio[1281]: updateProgress
May 29 11:22:28 testing volumio[1281]: {
May 29 11:22:28 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:28 testing volumio[1281]:   eta: '5m',
May 29 11:22:28 testing volumio[1281]:   progress: 17,
May 29 11:22:28 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:28 testing volumio[1281]: }
May 29 11:22:29 testing volumio-remote-updater[572]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:29 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:29 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:29 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:29 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:29 testing volumio[1281]: updateProgress
May 29 11:22:29 testing volumio[1281]: {
May 29 11:22:29 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:29 testing volumio[1281]:   eta: '5m',
May 29 11:22:29 testing volumio[1281]:   progress: 18,
May 29 11:22:29 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:29 testing volumio[1281]: }
May 29 11:22:30 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:30 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:30 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:30 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:30 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:30 testing volumio[1281]: updateProgress
May 29 11:22:30 testing volumio[1281]: {
May 29 11:22:30 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:30 testing volumio[1281]:   eta: '5m',
May 29 11:22:30 testing volumio[1281]:   progress: 18,
May 29 11:22:30 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:30 testing volumio[1281]: }
May 29 11:22:32 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:32 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:32 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:32 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:32 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:32 testing volumio[1281]: updateProgress
May 29 11:22:32 testing volumio[1281]: {
May 29 11:22:32 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:32 testing volumio[1281]:   eta: '5m',
May 29 11:22:32 testing volumio[1281]:   progress: 18,
May 29 11:22:32 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:32 testing volumio[1281]: }
May 29 11:22:33 testing volumio-remote-updater[572]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:33 testing volumio-remote-updater[572]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:33 testing volumio-remote-updater[572]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:33 testing volumio-remote-updater[572]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:33 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:33 testing volumio[1281]: updateProgress
May 29 11:22:33 testing volumio[1281]: {
May 29 11:22:33 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:33 testing volumio[1281]:   eta: '5m',
May 29 11:22:33 testing volumio[1281]:   progress: 19,
May 29 11:22:33 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:33 testing volumio[1281]: }
May 29 11:22:34 testing volumio-remote-updater[572]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:34 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:34 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:34 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:34 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:34 testing volumio[1281]: updateProgress
May 29 11:22:34 testing volumio[1281]: {
May 29 11:22:34 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:34 testing volumio[1281]:   eta: '5m',
May 29 11:22:34 testing volumio[1281]:   progress: 20,
May 29 11:22:34 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:34 testing volumio[1281]: }
May 29 11:22:36 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:36 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:36 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:36 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:36 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:36 testing volumio[1281]: updateProgress
May 29 11:22:36 testing volumio[1281]: {
May 29 11:22:36 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:36 testing volumio[1281]:   eta: '5m',
May 29 11:22:36 testing volumio[1281]:   progress: 20,
May 29 11:22:36 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:36 testing volumio[1281]: }
May 29 11:22:37 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:37 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:37 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:37 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:37 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:37 testing volumio[1281]: updateProgress
May 29 11:22:37 testing volumio[1281]: {
May 29 11:22:37 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:37 testing volumio[1281]:   eta: '5m',
May 29 11:22:37 testing volumio[1281]:   progress: 20,
May 29 11:22:37 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:37 testing volumio[1281]: }
May 29 11:22:38 testing volumio-remote-updater[572]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:38 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:38 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:38 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:38 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:38 testing volumio[1281]: updateProgress
May 29 11:22:38 testing volumio[1281]: {
May 29 11:22:38 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:38 testing volumio[1281]:   eta: '5m',
May 29 11:22:38 testing volumio[1281]:   progress: 21,
May 29 11:22:38 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:38 testing volumio[1281]: }
May 29 11:22:40 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:40 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:40 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:40 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:40 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:40 testing volumio[1281]: updateProgress
May 29 11:22:40 testing volumio[1281]: {
May 29 11:22:40 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:40 testing volumio[1281]:   eta: '5m',
May 29 11:22:40 testing volumio[1281]:   progress: 21,
May 29 11:22:40 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:40 testing volumio[1281]: }
May 29 11:22:41 testing volumio-remote-updater[572]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:41 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:41 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:41 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:41 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:41 testing volumio[1281]: updateProgress
May 29 11:22:41 testing volumio[1281]: {
May 29 11:22:41 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:41 testing volumio[1281]:   eta: '5m',
May 29 11:22:41 testing volumio[1281]:   progress: 22,
May 29 11:22:41 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:41 testing volumio[1281]: }
May 29 11:22:42 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:42 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:42 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:42 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:42 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:42 testing volumio[1281]: updateProgress
May 29 11:22:42 testing volumio[1281]: {
May 29 11:22:42 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:42 testing volumio[1281]:   eta: '5m',
May 29 11:22:42 testing volumio[1281]:   progress: 22,
May 29 11:22:42 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:42 testing volumio[1281]: }
May 29 11:22:43 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
May 29 11:22:43 testing volumio[1281]: info: MyVolumio login type: Token
May 29 11:22:44 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:44 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:44 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:44 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:44 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:44 testing volumio[1281]: updateProgress
May 29 11:22:44 testing volumio[1281]: {
May 29 11:22:44 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:44 testing volumio[1281]:   eta: '5m',
May 29 11:22:44 testing volumio[1281]:   progress: 22,
May 29 11:22:44 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:44 testing volumio[1281]: }
May 29 11:22:45 testing volumio-remote-updater[572]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:45 testing volumio-remote-updater[572]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:45 testing volumio-remote-updater[572]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:45 testing volumio-remote-updater[572]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:45 testing volumio[1281]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
May 29 11:22:45 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:45 testing volumio[1281]: updateProgress
May 29 11:22:45 testing volumio[1281]: {
May 29 11:22:45 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:45 testing volumio[1281]:   eta: '5m',
May 29 11:22:45 testing volumio[1281]:   progress: 23,
May 29 11:22:45 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:45 testing volumio[1281]: }
May 29 11:22:46 testing volumio-remote-updater[572]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:46 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:46 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:46 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:46 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:46 testing volumio[1281]: updateProgress
May 29 11:22:46 testing volumio[1281]: {
May 29 11:22:46 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:46 testing volumio[1281]:   eta: '5m',
May 29 11:22:46 testing volumio[1281]:   progress: 24,
May 29 11:22:46 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:46 testing volumio[1281]: }
May 29 11:22:50 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:50 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:50 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:50 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:50 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:50 testing volumio[1281]: updateProgress
May 29 11:22:50 testing volumio[1281]: {
May 29 11:22:50 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:50 testing volumio[1281]:   eta: '5m',
May 29 11:22:50 testing volumio[1281]:   progress: 24,
May 29 11:22:50 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:50 testing volumio[1281]: }
May 29 11:22:50 testing sudo[1868]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 29 11:22:50 testing sudo[1868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:22:50 testing sudo[1870]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 29 11:22:50 testing sudo[1870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:22:50 testing sudo[1868]: pam_unix(sudo:session): session closed for user root
May 29 11:22:50 testing sudo[1870]: pam_unix(sudo:session): session closed for user root
May 29 11:22:50 testing volumio[1281]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.7 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
May 29 11:22:50 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:50 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: Received Get System Info
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:22:51 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetVisibleSources
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 29 11:22:51 testing volumio[1281]: info: Received Get System Info
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:22:51 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: Listing playlists
May 29 11:22:51 testing volumio[1281]: info: Received Get System Info
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 29 11:22:51 testing volumio[1281]: info: Discovery: Getting this device information
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:51 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 29 11:22:51 testing volumio[1281]: info: MyVolumio token set successfully
May 29 11:22:51 testing volumio[1281]: info: MYVOLUMIO: Adding device
May 29 11:22:51 testing volumio[1281]: info: MYVOLUMIO: Evaluating Server
May 29 11:22:51 testing systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
May 29 11:22:51 testing volumio[1281]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
May 29 11:22:51 testing volumio[1281]: updateProgress
May 29 11:22:51 testing volumio[1281]: {
May 29 11:22:51 testing volumio[1281]:   downloadSpeed: '',
May 29 11:22:51 testing volumio[1281]:   eta: '5m',
May 29 11:22:51 testing volumio[1281]:   progress: 25,
May 29 11:22:51 testing volumio[1281]:   status: 'Creating backup'
May 29 11:22:51 testing volumio[1281]: }
May 29 11:22:51 testing dbus-daemon[561]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.26' (uid=0 pid=1882 comm="timedatectl show --property=NTPSynchronized --valu")
May 29 11:22:51 testing systemd[1]: Starting systemd-timedated.service - Time & Date Service...
May 29 11:22:52 testing dbus-daemon[561]: [system] Successfully activated service 'org.freedesktop.timedate1'
May 29 11:22:52 testing systemd[1]: Started systemd-timedated.service - Time & Date Service.
May 29 11:22:52 testing setdatetime-helper.sh[1881]: Time is not synchronized. Attempting to sync...
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing sudo[1905]:     root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 29 May 2025 15:22:52 GMT#015'
May 29 11:22:52 testing sudo[1905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 11:22:52 testing setdatetime-helper.sh[1906]: Thu May 29 11:22:52 EDT 2025
May 29 11:22:52 testing systemd-journald[330]: Time jumped backwards, rotating.
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:52 testing sudo[1905]: pam_unix(sudo:session): session closed for user root
May 29 11:22:52 testing setdatetime-helper.sh[1881]: Time synchronized successfully.
May 29 11:22:52 testing systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
May 29 11:22:52 testing systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
May 29 11:22:52 testing volumio[1281]: info: MyVolumio Plan changed: premium
May 29 11:22:52 testing volumio[1281]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
May 29 11:22:52 testing volumio[1281]: info: Removing browser output: myVolumio user plan is not superstar
May 29 11:22:52 testing volumio[1281]: info: Removing audio output:
May 29 11:22:52 testing volumio[1281]: info: MYVOLUMIO: Adding device
May 29 11:22:52 testing volumio[1281]: info: MYVOLUMIO: Evaluating Server
May 29 11:22:52 testing volumio[1281]: info: CoreCommandRouter::volumioGetState
May 29 11:22:52 testing volumio[1281]: info: CorePlayQueue::getTrack 0
May 29 11:22:52 testing volumio[1281]: error: Failed to ping endpoint as1.myvolumio.org : unknown error
May 29 11:22:52 testing volumio[1281]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 29 11:22:52 testing volumio[1281]: Error: Unable to resolve or reject the same promise twice
May 29 11:22:52 testing volumio[1281]:     at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43)
May 29 11:22:52 testing volumio[1281]:     at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371)
May 29 11:22:52 testing volumio[1281]:     at Socket.emit (node:events:514:28)
May 29 11:22:52 testing volumio[1281]:     at addChunk (node:internal/streams/readable:343:12)
May 29 11:22:52 testing volumio[1281]:     at readableAddChunk (node:internal/streams/readable:316:9)
May 29 11:22:52 testing volumio[1281]:     at Readable.push (node:internal/streams/readable:253:10)
May 29 11:22:52 testing volumio[1281]:     at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)
May 29 11:22:52 testing volumio[1281]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 29 11:22:54 testing volumio-remote-updater[572]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:54 testing volumio-remote-updater[572]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:54 testing volumio-remote-updater[572]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:54 testing volumio-remote-updater[572]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:55 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
May 29 11:22:57 testing sudo[1955]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-29 11:21'
May 29 11:22:57 testing sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 11:22:57 testing volumio-remote-updater[1968]: /bin/cp: cannot stat '/imgpart/volumio_factory.sqsh': No such file or directory
May 29 11:22:57 testing volumio-remote-updater[1972]: /bin/rm: cannot remove '/imgpart/volumio_factory.sqsh': No such file or directory
May 29 11:22:57 testing volumio-remote-updater[572]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025"
VOLUMIO_VERSION="0.069"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"