-- Logs begin at Fri 2025-12-19 00:33:43 EST, end at Fri 2025-12-19 05:40:47 EST. --
Dec 19 05:39:07 winonasbackroom dhcpcd[887]: wlan0: hardware address 00:00:00:00:00:00 claims 192.168.51.64
Dec 19 05:39:09 winonasbackroom volumio[1071]: info: UPDATER: Doing automatic update
Dec 19 05:39:09 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , setTestSystem
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: updater_comm , checkUpdates
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: PROGRESS: 0, STATUS: "Starting update", ETA: "6m"
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: /bin/rm: cannot remove '/imgpart/rck*': No such file or directory
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: /bin/rm: cannot remove '/imgpart/*.part': No such file or directory
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: /bin/rm: cannot remove '/imgpart/*.zs-old': No such file or directory
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: Killing processes that might interfere with OTA Updates
Dec 19 05:39:13 winonasbackroom sudo[22460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall matchbox-keyboard
Dec 19 05:39:13 winonasbackroom sudo[22460]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:13 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:13 winonasbackroom sudo[22460]: pam_unix(sudo:session): session closed for user root
Dec 19 05:39:13 winonasbackroom volumio[1071]: {
Dec 19 05:39:13 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:13 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:13 winonasbackroom volumio[1071]: progress: 5,
Dec 19 05:39:13 winonasbackroom volumio[1071]: status: 'Preparing update'
Dec 19 05:39:13 winonasbackroom volumio[1071]: }
Dec 19 05:39:13 winonasbackroom sudo[22463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall matchbox-window-manager
Dec 19 05:39:13 winonasbackroom sudo[22463]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 19 05:39:13 winonasbackroom volumio[1071]: error: Cannot kill process: Error: Command failed: /usr/bin/sudo /usr/bin/killall matchbox-keyboard
Dec 19 05:39:13 winonasbackroom volumio[1071]: matchbox-keyboard: no process found
Dec 19 05:39:13 winonasbackroom sudo[22463]: pam_unix(sudo:session): session closed for user root
Dec 19 05:39:13 winonasbackroom volumio[1071]: error: Cannot kill process: Error: Command failed: /usr/bin/sudo /usr/bin/killall matchbox-window-manager
Dec 19 05:39:13 winonasbackroom volumio[1071]: matchbox-window-manager: no process found
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
Dec 19 05:39:13 winonasbackroom volumio-remote-updater[596]: PROGRESS: 5, STATUS: "Preparing update", ETA: "5m"
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:13 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:13 winonasbackroom volumio[1071]: {
Dec 19 05:39:13 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:13 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:13 winonasbackroom volumio[1071]: progress: 5,
Dec 19 05:39:13 winonasbackroom volumio[1071]: status: 'Preparing update'
Dec 19 05:39:13 winonasbackroom volumio[1071]: }
Dec 19 05:39:13 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:13 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:13 winonasbackroom volumio[1071]: {
Dec 19 05:39:13 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:13 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:13 winonasbackroom volumio[1071]: progress: 5,
Dec 19 05:39:13 winonasbackroom volumio[1071]: status: 'Preparing update'
Dec 19 05:39:13 winonasbackroom volumio[1071]: }
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: hardware address 00:00:00:00:00:00 claims 192.168.51.64
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: 10 second defence failed for 192.168.51.64
Dec 19 05:39:15 winonasbackroom avahi-daemon[600]: Withdrawing address record for 192.168.51.64 on wlan0.
Dec 19 05:39:15 winonasbackroom avahi-daemon[600]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.51.64.
Dec 19 05:39:15 winonasbackroom avahi-daemon[600]: Interface wlan0.IPv4 no longer relevant for mDNS.
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: deleting route to 192.168.51.0/24
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: deleting default route via 192.168.51.1
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: Discovery: A device disappeared from network
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: Discovery: Device winonasbackroom disappeared from network
Dec 19 05:39:15 winonasbackroom ntpd[17884]: ntpd exiting on signal 15 (Terminated)
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 192.168.50.1 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom systemd[1]: Stopping Network Time Service...
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 192.168.51.1 local addr 192.168.51.64 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 208.113.130.146 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 162.244.81.139 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 204.57.30.245 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 159.203.82.102 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 66.59.198.178 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 158.51.99.19 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 144.202.66.214 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom ntpd[17884]: 69.89.207.99 local addr 192.168.50.50 ->
Dec 19 05:39:15 winonasbackroom systemd[1]: ntp.service: Succeeded.
Dec 19 05:39:15 winonasbackroom systemd[1]: Stopped Network Time Service.
Dec 19 05:39:15 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running
Dec 19 05:39:15 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
Dec 19 05:39:15 winonasbackroom systemd[1]: Starting Network Time Service...
Dec 19 05:39:15 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running
Dec 19 05:39:15 winonasbackroom ntpd[22516]: ntpd 4.2.8p12@1.3728-o (1): Starting
Dec 19 05:39:15 winonasbackroom ntpd[22516]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103
Dec 19 05:39:15 winonasbackroom systemd[1]: Started Network Time Service.
Dec 19 05:39:15 winonasbackroom ntpd[22523]: proto: precision = 0.815 usec (-20)
Dec 19 05:39:15 winonasbackroom ntpd[22523]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: rebinding lease of 192.168.51.64
Dec 19 05:39:15 winonasbackroom ntpd[22523]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37
Dec 19 05:39:15 winonasbackroom ntpd[22523]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 357 days ago
Dec 19 05:39:15 winonasbackroom ntpd[22523]: Listen and drop on 0 v6wildcard [::]:123
Dec 19 05:39:15 winonasbackroom ntpd[22523]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Dec 19 05:39:15 winonasbackroom ntpd[22523]: Listen normally on 2 lo 127.0.0.1:123
Dec 19 05:39:15 winonasbackroom ntpd[22523]: Listen normally on 3 eth0 192.168.50.50:123
Dec 19 05:39:15 winonasbackroom ntpd[22523]: Listening on routing socket on fd #20 for interface updates
Dec 19 05:39:15 winonasbackroom ntpd[22523]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
Dec 19 05:39:15 winonasbackroom ntpd[22523]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
Dec 19 05:39:15 winonasbackroom dhcpcd[887]: wlan0: probing address 192.168.51.64/24
Dec 19 05:39:15 winonasbackroom volumio-remote-updater[596]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:15 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:15 winonasbackroom volumio[1071]: {
Dec 19 05:39:15 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:15 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:15 winonasbackroom volumio[1071]: progress: 10,
Dec 19 05:39:15 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:15 winonasbackroom volumio[1071]: }
Dec 19 05:39:15 winonasbackroom volumio-remote-updater[596]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:15 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:15 winonasbackroom volumio[1071]: {
Dec 19 05:39:15 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:15 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:15 winonasbackroom volumio[1071]: progress: 10,
Dec 19 05:39:15 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:15 winonasbackroom volumio[1071]: }
Dec 19 05:39:15 winonasbackroom volumio-remote-updater[596]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:15 winonasbackroom volumio-remote-updater[596]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:15 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:15 winonasbackroom volumio[1071]: {
Dec 19 05:39:15 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:15 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:15 winonasbackroom volumio[1071]: progress: 10,
Dec 19 05:39:15 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:15 winonasbackroom volumio[1071]: }
Dec 19 05:39:15 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:15 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:15 winonasbackroom volumio[1071]: {
Dec 19 05:39:15 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:15 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:15 winonasbackroom volumio[1071]: progress: 10,
Dec 19 05:39:15 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:15 winonasbackroom volumio[1071]: }
Dec 19 05:39:16 winonasbackroom ntpd[22523]: Soliciting pool server 172.235.154.118
Dec 19 05:39:16 winonasbackroom volumio-remote-updater[596]: PROGRESS: 10, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:16 winonasbackroom volumio-remote-updater[596]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:16 winonasbackroom volumio-remote-updater[596]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:16 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:16 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:16 winonasbackroom volumio[1071]: {
Dec 19 05:39:16 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:16 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:16 winonasbackroom volumio[1071]: progress: 11,
Dec 19 05:39:16 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:16 winonasbackroom volumio[1071]: }
Dec 19 05:39:17 winonasbackroom ntpd[22523]: Soliciting pool server 173.249.203.227
Dec 19 05:39:17 winonasbackroom ntpd[22523]: Soliciting pool server 209.177.158.85
Dec 19 05:39:17 winonasbackroom volumio-remote-updater[596]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:17 winonasbackroom volumio-remote-updater[596]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:17 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:17 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:17 winonasbackroom volumio[1071]: {
Dec 19 05:39:17 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:17 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:17 winonasbackroom volumio[1071]: progress: 11,
Dec 19 05:39:17 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:17 winonasbackroom volumio[1071]: }
Dec 19 05:39:18 winonasbackroom ntpd[22523]: Soliciting pool server 162.159.200.1
Dec 19 05:39:18 winonasbackroom ntpd[22523]: Soliciting pool server 23.94.221.138
Dec 19 05:39:18 winonasbackroom ntpd[22523]: Soliciting pool server 172.235.32.243
Dec 19 05:39:19 winonasbackroom volumio-remote-updater[596]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:19 winonasbackroom volumio-remote-updater[596]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:19 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:19 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:19 winonasbackroom volumio[1071]: {
Dec 19 05:39:19 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:19 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:19 winonasbackroom volumio[1071]: progress: 12,
Dec 19 05:39:19 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:19 winonasbackroom volumio[1071]: }
Dec 19 05:39:19 winonasbackroom ntpd[22523]: Soliciting pool server 15.204.87.223
Dec 19 05:39:19 winonasbackroom ntpd[22523]: Soliciting pool server 66.244.16.123
Dec 19 05:39:19 winonasbackroom ntpd[22523]: Soliciting pool server 66.118.231.14
Dec 19 05:39:19 winonasbackroom ntpd[22523]: Soliciting pool server 204.2.134.162
Dec 19 05:39:19 winonasbackroom volumio[1071]: info: Volumio Network Manager: Network status updated: 1
Dec 19 05:39:20 winonasbackroom volumio-remote-updater[596]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:20 winonasbackroom volumio-remote-updater[596]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:20 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:20 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:20 winonasbackroom volumio[1071]: {
Dec 19 05:39:20 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:20 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:20 winonasbackroom volumio[1071]: progress: 12,
Dec 19 05:39:20 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:20 winonasbackroom volumio[1071]: }
Dec 19 05:39:20 winonasbackroom ntpd[22523]: Soliciting pool server 205.233.73.201
Dec 19 05:39:20 winonasbackroom ntpd[22523]: Soliciting pool server 69.172.133.130
Dec 19 05:39:21 winonasbackroom ntpd[22523]: Soliciting pool server 102.129.185.135
Dec 19 05:39:21 winonasbackroom volumio-remote-updater[596]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:21 winonasbackroom volumio-remote-updater[596]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:21 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:21 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:21 winonasbackroom volumio[1071]: {
Dec 19 05:39:21 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:21 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:21 winonasbackroom volumio[1071]: progress: 14,
Dec 19 05:39:21 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:21 winonasbackroom volumio[1071]: }
Dec 19 05:39:21 winonasbackroom dhcpcd[887]: wlan0: leased 192.168.51.64 for 470020 seconds
Dec 19 05:39:21 winonasbackroom avahi-daemon[600]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.51.64.
Dec 19 05:39:21 winonasbackroom avahi-daemon[600]: New relevant interface wlan0.IPv4 for mDNS.
Dec 19 05:39:21 winonasbackroom dhcpcd[887]: wlan0: adding route to 192.168.51.0/24
Dec 19 05:39:21 winonasbackroom avahi-daemon[600]: Registering new address record for 192.168.51.64 on wlan0.IPv4.
Dec 19 05:39:21 winonasbackroom dhcpcd[887]: wlan0: adding default route via 192.168.51.1
Dec 19 05:39:21 winonasbackroom ntpd[22523]: ntpd exiting on signal 15 (Terminated)
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 192.168.50.1 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom systemd[1]: Stopping Network Time Service...
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 172.235.154.118 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 173.249.203.227 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom systemd[1]: ntp.service: Succeeded.
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 209.177.158.85 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 162.159.200.1 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 23.94.221.138 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 172.235.32.243 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 66.244.16.123 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 204.2.134.162 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom systemd[1]: Stopped Network Time Service.
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 66.118.231.14 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 69.172.133.130 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 205.233.73.201 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom ntpd[22523]: 102.129.185.135 local addr 192.168.50.50 ->
Dec 19 05:39:21 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running
Dec 19 05:39:21 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
Dec 19 05:39:21 winonasbackroom systemd[1]: Starting Network Time Service...
Dec 19 05:39:21 winonasbackroom volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running
Dec 19 05:39:21 winonasbackroom ntpd[22584]: ntpd 4.2.8p12@1.3728-o (1): Starting
Dec 19 05:39:21 winonasbackroom ntpd[22584]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103
Dec 19 05:39:21 winonasbackroom systemd[1]: Started Network Time Service.
Dec 19 05:39:21 winonasbackroom ntpd[22591]: proto: precision = 0.833 usec (-20)
Dec 19 05:39:21 winonasbackroom ntpd[22591]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
Dec 19 05:39:21 winonasbackroom ntpd[22591]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37
Dec 19 05:39:21 winonasbackroom ntpd[22591]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 357 days ago
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listen and drop on 0 v6wildcard [::]:123
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listen normally on 2 lo 127.0.0.1:123
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listen normally on 3 eth0 192.168.50.50:123
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listen normally on 4 wlan0 192.168.51.64:123
Dec 19 05:39:21 winonasbackroom ntpd[22591]: Listening on routing socket on fd #21 for interface updates
Dec 19 05:39:21 winonasbackroom ntpd[22591]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
Dec 19 05:39:21 winonasbackroom ntpd[22591]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: Discovery: adding 5266fee1-e4ec-40dd-af0f-473f47a3d9c2
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: Discovery: Found device WinonasBackroom
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: CoreCommandRouter::volumioGetState
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: CorePlayQueue::getTrack 0
Dec 19 05:39:22 winonasbackroom volumio-remote-updater[596]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:22 winonasbackroom volumio-remote-updater[596]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:22 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:22 winonasbackroom volumio[1071]: {
Dec 19 05:39:22 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:22 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:22 winonasbackroom volumio[1071]: progress: 14,
Dec 19 05:39:22 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:22 winonasbackroom volumio[1071]: }
Dec 19 05:39:22 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:22 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:22 winonasbackroom volumio[1071]: {
Dec 19 05:39:22 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:22 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:22 winonasbackroom volumio[1071]: progress: 14,
Dec 19 05:39:22 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:22 winonasbackroom volumio[1071]: }
Dec 19 05:39:22 winonasbackroom ntpd[22591]: Soliciting pool server 172.235.154.118
Dec 19 05:39:23 winonasbackroom ntpd[22591]: Soliciting pool server 173.249.203.227
Dec 19 05:39:23 winonasbackroom ntpd[22591]: Soliciting pool server 209.177.158.85
Dec 19 05:39:23 winonasbackroom volumio-remote-updater[596]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:23 winonasbackroom volumio-remote-updater[596]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:23 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:23 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:23 winonasbackroom volumio[1071]: {
Dec 19 05:39:23 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:23 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:23 winonasbackroom volumio[1071]: progress: 15,
Dec 19 05:39:23 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:23 winonasbackroom volumio[1071]: }
Dec 19 05:39:23 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:23 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:23 winonasbackroom volumio[1071]: {
Dec 19 05:39:23 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:23 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:23 winonasbackroom volumio[1071]: progress: 15,
Dec 19 05:39:23 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:23 winonasbackroom volumio[1071]: }
Dec 19 05:39:24 winonasbackroom ntpd[22591]: Soliciting pool server 162.159.200.1
Dec 19 05:39:24 winonasbackroom ntpd[22591]: Soliciting pool server 66.118.231.14
Dec 19 05:39:24 winonasbackroom ntpd[22591]: Soliciting pool server 172.235.32.243
Dec 19 05:39:25 winonasbackroom ntpd[22591]: Soliciting pool server 67.217.246.204
Dec 19 05:39:25 winonasbackroom ntpd[22591]: Soliciting pool server 69.172.133.130
Dec 19 05:39:25 winonasbackroom ntpd[22591]: Soliciting pool server 23.94.221.138
Dec 19 05:39:25 winonasbackroom ntpd[22591]: Soliciting pool server 205.233.73.201
Dec 19 05:39:25 winonasbackroom volumio-remote-updater[596]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:25 winonasbackroom volumio-remote-updater[596]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:25 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:25 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:25 winonasbackroom volumio[1071]: {
Dec 19 05:39:25 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:25 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:25 winonasbackroom volumio[1071]: progress: 16,
Dec 19 05:39:25 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:25 winonasbackroom volumio[1071]: }
Dec 19 05:39:26 winonasbackroom ntpd[22591]: Soliciting pool server 23.168.24.210
Dec 19 05:39:26 winonasbackroom ntpd[22591]: Soliciting pool server 66.244.16.123
Dec 19 05:39:27 winonasbackroom volumio-remote-updater[596]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:27 winonasbackroom volumio-remote-updater[596]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:27 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:27 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:27 winonasbackroom volumio[1071]: {
Dec 19 05:39:27 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:27 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:27 winonasbackroom volumio[1071]: progress: 17,
Dec 19 05:39:27 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:27 winonasbackroom volumio[1071]: }
Dec 19 05:39:27 winonasbackroom go-librespot[1488]: time="2025-12-19T05:39:27-05:00" level=trace msg="sent dealer ping"
Dec 19 05:39:27 winonasbackroom go-librespot[1488]: time="2025-12-19T05:39:27-05:00" level=trace msg="received dealer pong"
Dec 19 05:39:27 winonasbackroom ntpd[22591]: Soliciting pool server 15.204.87.223
Dec 19 05:39:28 winonasbackroom volumio-remote-updater[596]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:28 winonasbackroom volumio-remote-updater[596]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:28 winonasbackroom volumio-remote-updater[596]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:28 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:28 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:28 winonasbackroom volumio[1071]: {
Dec 19 05:39:28 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:28 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:28 winonasbackroom volumio[1071]: progress: 18,
Dec 19 05:39:28 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:28 winonasbackroom volumio[1071]: }
Dec 19 05:39:29 winonasbackroom volumio[1071]: info: Volumio Network Manager: Network status updated: 3
Dec 19 05:39:29 winonasbackroom volumio-remote-updater[596]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:29 winonasbackroom volumio-remote-updater[596]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:29 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:29 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:29 winonasbackroom volumio[1071]: {
Dec 19 05:39:29 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:29 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:29 winonasbackroom volumio[1071]: progress: 19,
Dec 19 05:39:29 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:29 winonasbackroom volumio[1071]: }
Dec 19 05:39:31 winonasbackroom volumio-remote-updater[596]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:31 winonasbackroom volumio-remote-updater[596]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:31 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:31 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:31 winonasbackroom volumio[1071]: {
Dec 19 05:39:31 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:31 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:31 winonasbackroom volumio[1071]: progress: 20,
Dec 19 05:39:31 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:31 winonasbackroom volumio[1071]: }
Dec 19 05:39:31 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:31 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:31 winonasbackroom volumio[1071]: {
Dec 19 05:39:31 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:31 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:31 winonasbackroom volumio[1071]: progress: 20,
Dec 19 05:39:31 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:31 winonasbackroom volumio[1071]: }
Dec 19 05:39:32 winonasbackroom volumio-remote-updater[596]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:32 winonasbackroom volumio-remote-updater[596]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:32 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:32 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:32 winonasbackroom volumio[1071]: {
Dec 19 05:39:32 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:32 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:32 winonasbackroom volumio[1071]: progress: 21,
Dec 19 05:39:32 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:32 winonasbackroom volumio[1071]: }
Dec 19 05:39:32 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:32 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:32 winonasbackroom volumio[1071]: {
Dec 19 05:39:32 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:32 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:32 winonasbackroom volumio[1071]: progress: 21,
Dec 19 05:39:32 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:32 winonasbackroom volumio[1071]: }
Dec 19 05:39:33 winonasbackroom volumio-remote-updater[596]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:33 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:33 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:33 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:33 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:33 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:33 winonasbackroom volumio[1071]: {
Dec 19 05:39:33 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:33 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:33 winonasbackroom volumio[1071]: progress: 22,
Dec 19 05:39:33 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:33 winonasbackroom volumio[1071]: }
Dec 19 05:39:33 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:33 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:33 winonasbackroom volumio[1071]: {
Dec 19 05:39:33 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:33 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:33 winonasbackroom volumio[1071]: progress: 22,
Dec 19 05:39:33 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:33 winonasbackroom volumio[1071]: }
Dec 19 05:39:33 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:33 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:33 winonasbackroom volumio[1071]: {
Dec 19 05:39:33 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:33 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:33 winonasbackroom volumio[1071]: progress: 22,
Dec 19 05:39:33 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:33 winonasbackroom volumio[1071]: }
Dec 19 05:39:35 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:35 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:35 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:35 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:35 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:35 winonasbackroom volumio[1071]: {
Dec 19 05:39:35 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:35 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:35 winonasbackroom volumio[1071]: progress: 22,
Dec 19 05:39:35 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:35 winonasbackroom volumio[1071]: }
Dec 19 05:39:35 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:35 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:35 winonasbackroom volumio[1071]: {
Dec 19 05:39:35 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:35 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:35 winonasbackroom volumio[1071]: progress: 22,
Dec 19 05:39:35 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:35 winonasbackroom volumio[1071]: }
Dec 19 05:39:36 winonasbackroom volumio-remote-updater[596]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:36 winonasbackroom volumio-remote-updater[596]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:36 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:36 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:36 winonasbackroom volumio[1071]: {
Dec 19 05:39:36 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:36 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:36 winonasbackroom volumio[1071]: progress: 24,
Dec 19 05:39:36 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:36 winonasbackroom volumio[1071]: }
Dec 19 05:39:36 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:36 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:36 winonasbackroom volumio[1071]: {
Dec 19 05:39:36 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:36 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:36 winonasbackroom volumio[1071]: progress: 24,
Dec 19 05:39:36 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:36 winonasbackroom volumio[1071]: }
Dec 19 05:39:37 winonasbackroom volumio-remote-updater[596]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:37 winonasbackroom volumio-remote-updater[596]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:37 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:37 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:37 winonasbackroom volumio[1071]: {
Dec 19 05:39:37 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:37 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:37 winonasbackroom volumio[1071]: progress: 24,
Dec 19 05:39:37 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:37 winonasbackroom volumio[1071]: }
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:38 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:38 winonasbackroom volumio[1071]: {
Dec 19 05:39:38 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:38 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:38 winonasbackroom volumio[1071]: progress: 25,
Dec 19 05:39:38 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:38 winonasbackroom volumio[1071]: }
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:38 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:38 winonasbackroom volumio[1071]: {
Dec 19 05:39:38 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:38 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:38 winonasbackroom volumio[1071]: progress: 25,
Dec 19 05:39:38 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:38 winonasbackroom volumio[1071]: }
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:38 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:38 winonasbackroom volumio[1071]: {
Dec 19 05:39:38 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:38 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:38 winonasbackroom volumio[1071]: progress: 25,
Dec 19 05:39:38 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:38 winonasbackroom volumio[1071]: }
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:38 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:38 winonasbackroom volumio[1071]: {
Dec 19 05:39:38 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:38 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:38 winonasbackroom volumio[1071]: progress: 25,
Dec 19 05:39:38 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:38 winonasbackroom volumio[1071]: }
Dec 19 05:39:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:38 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:38 winonasbackroom volumio[1071]: {
Dec 19 05:39:38 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:38 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:38 winonasbackroom volumio[1071]: progress: 25,
Dec 19 05:39:38 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:38 winonasbackroom volumio[1071]: }
Dec 19 05:39:39 winonasbackroom volumio-remote-updater[596]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:39 winonasbackroom volumio-remote-updater[596]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:39 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:39 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:39 winonasbackroom volumio[1071]: {
Dec 19 05:39:39 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:39 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:39 winonasbackroom volumio[1071]: progress: 27,
Dec 19 05:39:39 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:39 winonasbackroom volumio[1071]: }
Dec 19 05:39:39 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:39 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:39 winonasbackroom volumio[1071]: {
Dec 19 05:39:39 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:39 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:39 winonasbackroom volumio[1071]: progress: 27,
Dec 19 05:39:39 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:39 winonasbackroom volumio[1071]: }
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 27, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:41 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:41 winonasbackroom volumio[1071]: {
Dec 19 05:39:41 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:41 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:41 winonasbackroom volumio[1071]: progress: 28,
Dec 19 05:39:41 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:41 winonasbackroom volumio[1071]: }
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio-remote-updater[596]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m"
Dec 19 05:39:41 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:41 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:41 winonasbackroom volumio[1071]: {
Dec 19 05:39:41 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:41 winonasbackroom volumio[1071]: eta: '5m',
Dec 19 05:39:41 winonasbackroom volumio[1071]: progress: 30,
Dec 19 05:39:41 winonasbackroom volumio[1071]: status: 'Creating backup'
Dec 19 05:39:41 winonasbackroom volumio[1071]: }
Dec 19 05:39:43 winonasbackroom volumio-remote-updater[596]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Dec 19 05:39:43 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:39:43 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:39:43 winonasbackroom volumio[1071]: {
Dec 19 05:39:43 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:39:43 winonasbackroom volumio[1071]: eta: '4m',
Dec 19 05:39:43 winonasbackroom volumio[1071]: progress: 30,
Dec 19 05:39:43 winonasbackroom volumio[1071]: status: 'Downloading new update'
Dec 19 05:39:43 winonasbackroom volumio[1071]: }
Dec 19 05:39:57 winonasbackroom go-librespot[1488]: time="2025-12-19T05:39:57-05:00" level=trace msg="sent dealer ping"
Dec 19 05:39:57 winonasbackroom go-librespot[1488]: time="2025-12-19T05:39:57-05:00" level=trace msg="received dealer pong"
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: Received Get System Info
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: Discovery: Getting this device information
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CoreCommandRouter::volumioGetState
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CorePlayQueue::getTrack 0
Dec 19 05:40:14 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 19 05:40:22 winonasbackroom volumio-remote-updater[596]: zsync done
Dec 19 05:40:22 winonasbackroom volumio-remote-updater[596]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Dec 19 05:40:22 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:22 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:40:22 winonasbackroom volumio[1071]: {
Dec 19 05:40:22 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:40:22 winonasbackroom volumio[1071]: eta: '2m',
Dec 19 05:40:22 winonasbackroom volumio[1071]: progress: 80,
Dec 19 05:40:22 winonasbackroom volumio[1071]: status: 'Downloading new update'
Dec 19 05:40:22 winonasbackroom volumio[1071]: }
Dec 19 05:40:27 winonasbackroom go-librespot[1488]: time="2025-12-19T05:40:27-05:00" level=trace msg="sent dealer ping"
Dec 19 05:40:27 winonasbackroom go-librespot[1488]: time="2025-12-19T05:40:27-05:00" level=trace msg="received dealer pong"
Dec 19 05:40:29 winonasbackroom volumio-remote-updater[596]: zsync done
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: PROGRESS: 90, STATUS: "Cleaning old files", ETA: "1m"
Dec 19 05:40:30 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:30 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:40:30 winonasbackroom volumio[1071]: {
Dec 19 05:40:30 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:40:30 winonasbackroom volumio[1071]: eta: '1m',
Dec 19 05:40:30 winonasbackroom volumio[1071]: progress: 90,
Dec 19 05:40:30 winonasbackroom volumio[1071]: status: 'Cleaning old files'
Dec 19 05:40:30 winonasbackroom volumio[1071]: }
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: /bin/cp: cannot stat '/data/volumio_factory.sqsh': No such file or directory
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: /bin/rm: cannot remove '/data/volumio_factory.sqsh': No such file or directory
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s"
Dec 19 05:40:30 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:30 winonasbackroom volumio[1071]: updateProgress
Dec 19 05:40:30 winonasbackroom volumio[1071]: {
Dec 19 05:40:30 winonasbackroom volumio[1071]: downloadSpeed: '',
Dec 19 05:40:30 winonasbackroom volumio[1071]: eta: '30s',
Dec 19 05:40:30 winonasbackroom volumio[1071]: progress: 95,
Dec 19 05:40:30 winonasbackroom volumio[1071]: status: 'Finalizing update'
Dec 19 05:40:30 winonasbackroom volumio[1071]: }
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: PROGRESS: 100, STATUS: "success", MESSAGE: "Successfully updated to \"3.886\" version. System restart required."
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: No test mode
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: No alpha test mode
Dec 19 05:40:30 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: [2025-12-19 05:40:30] [disconnect] Disconnect close local:[1000] remote:[1000]
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: [2025-12-19 05:40:30] [info] asio async_write error: system:32 (Broken pipe)
Dec 19 05:40:30 winonasbackroom volumio-remote-updater[596]: [2025-12-19 05:40:30] [fatal] handle_write_frame error: websocketpp.transport:2 (Underlying Transport Error)
Dec 19 05:40:30 winonasbackroom volumio[1071]: updateReady
Dec 19 05:40:30 winonasbackroom volumio[1071]: {
Dec 19 05:40:30 winonasbackroom volumio[1071]: changeLogLink: 'http://volumio.org',
Dec 19 05:40:30 winonasbackroom volumio[1071]: description: 'FIXES
- Fix TIDAL low quality (AAC) playback
- Fix for DLNA Server discovery
- Fix for Plugins installation
NEW ADDITIONS
- BLE-based onboarding setup
- Update TIDAL SDK
',
Dec 19 05:40:30 winonasbackroom volumio[1071]: title: 'Update v3.886',
Dec 19 05:40:30 winonasbackroom volumio[1071]: updateavailable: true
Dec 19 05:40:30 winonasbackroom volumio[1071]: }
Dec 19 05:40:31 winonasbackroom systemd[1]: volumio-remote-updater.service: Succeeded.
Dec 19 05:40:31 winonasbackroom systemd[1]: volumio-remote-updater.service: Service RestartSec=100ms expired, scheduling restart.
Dec 19 05:40:31 winonasbackroom systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1.
Dec 19 05:40:31 winonasbackroom systemd[1]: Stopped volumio-remote-updater.service.
Dec 19 05:40:31 winonasbackroom systemd[1]: Started volumio-remote-updater.service.
Dec 19 05:40:31 winonasbackroom volumio-remote-updater[22801]: Error: No active session
Dec 19 05:40:31 winonasbackroom volumio-remote-updater[22801]: [2025-12-19 05:40:31] [connect] Successful connection
Dec 19 05:40:31 winonasbackroom volumio-remote-updater[22801]: [2025-12-19 05:40:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1766140831 101
Dec 19 05:40:31 winonasbackroom volumio[1071]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 8
Dec 19 05:40:31 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:32 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:33 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:34 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:35 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:36 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:37 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:38 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:39 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:40 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:41 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:42 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:43 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:44 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:45 winonasbackroom volumio[1071]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Dec 19 05:40:46 winonasbackroom volumio[1071]: info: CoreCommandRouter::Close All Modals sent
Dec 19 05:40:46 winonasbackroom volumio[1071]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________
Dec 19 05:40:46 winonasbackroom volumio[1071]: info: PLUGIN onReboot : networkfs
Dec 19 05:40:46 winonasbackroom volumio[1071]: info: PLUGIN onReboot : audiophonicsonoff
Dec 19 05:40:46 winonasbackroom volumio[1071]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 19 05:40:46 winonasbackroom volumio[1071]: TypeError: Cannot read property 'writeSync' of undefined
Dec 19 05:40:46 winonasbackroom volumio[1071]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at HashMap. (/volumio/app/pluginmanager.js:668:31)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/updater_comm/index.js:156:35)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at listOnTimeout (internal/timers.js:554:17)
Dec 19 05:40:46 winonasbackroom volumio[1071]: at processTimers (internal/timers.js:497:7)
Dec 19 05:40:46 winonasbackroom volumio[1071]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 19 05:40:47 winonasbackroom sudo[22873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-19 05:39
Dec 19 05:40:47 winonasbackroom sudo[22873]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="cc50ad4a2058d01de272214eb33827883bd2b7d8"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET"
VOLUMIO_VERSION="3.874"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"