Hello Ladies and Gentlemen,
I am looking for some help with the remote updater in Volumio. We have a RPi Zero with an Allo Boss DAC running Volumio 2.777. It has allowed us to bring my wifes 25 year old Sony HiFi into the internet age. It is one of the easiest to use, most useful pieces of “IOT” i have ever come across. Every single person involved in the project deserves a beer in my local bar.
However i have this annoying issue when i go to update via the browser it would show an update was available and then update and reboot. however after the reboot the version remains the same.
I connected two sessions via SSH. One running “sudo journalctl -f” and the other running the update “/volumio/app/plugins/system_controller/volumio_command_line_client$ ./volumio.sh updater forceupdate”
The juicy pieces of the logs follow below. From my limited understanding they seem to indicate is an http error 416 “volumio-remote-updater[512]: bad status code 416”. I believe a 416 is that “i have tried to resume downloading a file but can’t or i need to download a portion of a file and cant”
I have checked my firewall and the traffic is allowed and seems good. If it use those two same links below from other computers on the network the files download successfully. There is also enough free space on the SD card to take these files. I believe they go to /imgpart. Note i had to mangle the links as the topic post won’t allow more than two links in it.
Any help would be appreciated in trying to figure this out.
volumio@volumio:~$ df
Filesystem Size Used Avail Use% Mounted on
/dev/mmcblk0p2 2.4G 1.5G 695M 69% /imgpart
/dev/loop0 350M 350M 0 100% /static
overlay 5.4G 743M 4.3G 15% /
devtmpfs 229M 0 229M 0% /dev
tmpfs 244M 13k 244M 1% /dev/shm
tmpfs 244M 4.9M 239M 2% /run
tmpfs 5.3M 4.1k 5.3M 1% /run/lock
tmpfs 244M 0 244M 0% /sys/fs/cgroup
tmpfs 244M 29k 244M 1% /tmp
tmpfs 244M 0 244M 0% /var/spool/cups
tmpfs 21M 17k 21M 1% /var/log
tmpfs 244M 0 244M 0% /var/spool/cups/tmp
/dev/mmcblk0p1 63M 62M 2.0M 97% /boot
tmpfs 49M 0 49M 0% /run/user/1000
http://updates.volumio.org/pi/volumio/2.799/kernel_current.tar
or
http://updates.volumio.org/pi/volumio/2.799/volumio_current.sqsh
Jul 23 08:24:23 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:25:52 volumio volumio-remote-updater[512]: [439B blob data]
Jul 23 08:27:08 volumio volumio-remote-updater[512]: [465B blob data]
Jul 23 08:27:08 volumio volumio-remote-updater[512]: downloading from
h t t p ://updates.volumio.org/pi/volumio/2.799/volumio_current.sqsh:
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: bad status code 416
Jul 23 08:27:08 volumio volumio-remote-updater[512]: failed to retrieve from
h t t p ://updates.volumio.org/pi/volumio/2.799/volumio_current.sqsh
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:08 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:09 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:09 volumio volumio[951]: updateProgress
Jul 23 08:27:09 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:09 volumio volumio[951]: eta: '4m',
Jul 23 08:27:09 volumio volumio[951]: progress: 30,
Jul 23 08:27:09 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:09 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:09 volumio volumio[951]: updateProgress
Jul 23 08:27:09 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:09 volumio volumio[951]: eta: '4m',
Jul 23 08:27:09 volumio volumio[951]: progress: 30,
Jul 23 08:27:09 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:09 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:09 volumio volumio[951]: updateProgress
Jul 23 08:27:09 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:09 volumio volumio[951]: eta: '4m',
Jul 23 08:27:09 volumio volumio[951]: progress: 30,
Jul 23 08:27:09 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:25 volumio volumio-remote-updater[512]: Aborting, download available in volumio_current.sqsh.part
Jul 23 08:27:25 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:25 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:25 volumio volumio-remote-updater[512]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m"
Jul 23 08:27:25 volumio volumio[951]: updateProgress
Jul 23 08:27:25 volumio volumio-remote-updater[512]: zsync done
Jul 23 08:27:25 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:26 volumio volumio[951]: progress: 80,
Jul 23 08:27:26 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:39 volumio volumio-remote-updater[512]: [146B blob data]
Jul 23 08:27:47 volumio volumio-remote-updater[512]: [154B blob data]
Jul 23 08:27:49 volumio volumio-remote-updater[512]: downloading from
h t t p ://updates.volumio.org/pi/volumio/2.799/kernel_current.tar:
Jul 23 08:27:49 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:49 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:49 volumio volumio[951]: updateProgress
Jul 23 08:27:49 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:49 volumio volumio[951]: eta: '2m',
Jul 23 08:27:49 volumio volumio[951]: progress: 80,
Jul 23 08:27:49 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:49 volumio volumio-remote-updater[512]: bad status code 416
Jul 23 08:27:49 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:49 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:49 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:50 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:50 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:50 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:50 volumio volumio-remote-updater[512]: failed to retrieve from
h t t p ://updates.volumio.org/pi/volumio/2.799/kernel_current.tar
Jul 23 08:27:50 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:50 volumio volumio[951]: updateProgress
Jul 23 08:27:50 volumio volumio[951]: { downloadSpeed: '0.0',
Jul 23 08:27:50 volumio volumio[951]: eta: '2m',
Jul 23 08:27:50 volumio volumio[951]: progress: 80,
Jul 23 08:27:50 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:52 volumio volumio-remote-updater[512]: Aborting, download available in kernel_current.tar.part
Jul 23 08:27:52 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:52 volumio volumio-remote-updater[512]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m"
Jul 23 08:27:52 volumio volumio-remote-updater[512]: zsync done
Jul 23 08:27:52 volumio volumio[951]: status: 'Downloading new update' }
Jul 23 08:27:52 volumio volumio-remote-updater[512]: PROGRESS: 90, STATUS: "Cleaning old files", ETA: "1m"
Jul 23 08:27:52 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:52 volumio volumio[951]: updateProgress
Jul 23 08:27:52 volumio volumio[951]: { downloadSpeed: '',
Jul 23 08:27:52 volumio volumio[951]: eta: '1m',
Jul 23 08:27:52 volumio volumio[951]: progress: 90,
Jul 23 08:27:52 volumio volumio[951]: status: 'Cleaning old files' }
Jul 23 08:27:52 volumio volumio-remote-updater[512]: /bin/rm: cannot remove '/imgpart/volumio_current.sqsh.zs-old': No such file or directory
Jul 23 08:27:52 volumio volumio-remote-updater[512]: /bin/rm: cannot remove '/imgpart/kernel_current.tar.zs-old': No such file or directory
Jul 23 08:27:52 volumio volumio-remote-updater[512]: /bin/cp: cannot stat '/data/volumio_factory.sqsh': No such file or directory
Jul 23 08:27:52 volumio volumio-remote-updater[512]: /bin/rm: cannot remove '/data/volumio_factory.sqsh': No such file or directory
Jul 23 08:27:52 volumio volumio-remote-updater[512]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s"
Jul 23 08:27:52 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:52 volumio volumio[951]: updateProgress
Jul 23 08:27:52 volumio volumio[951]: { downloadSpeed: '',
Jul 23 08:27:52 volumio volumio[951]: eta: '30s',
Jul 23 08:27:52 volumio volumio[951]: progress: 95,
Jul 23 08:27:52 volumio volumio[951]: status: 'Finalizing update' }
Jul 23 08:27:53 volumio volumio-remote-updater[512]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s"
Jul 23 08:27:53 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:53 volumio volumio[951]: updateProgress
Jul 23 08:27:53 volumio volumio[951]: { downloadSpeed: '',
Jul 23 08:27:53 volumio volumio[951]: eta: '30s',
Jul 23 08:27:53 volumio volumio[951]: progress: 95,
Jul 23 08:27:53 volumio volumio[951]: status: 'Finalizing update' }
Jul 23 08:27:53 volumio volumio-remote-updater[512]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s"
Jul 23 08:27:53 volumio volumio[951]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage
Jul 23 08:27:53 volumio volumio[951]: updateProgress
Jul 23 08:27:53 volumio volumio[951]: { downloadSpeed: '',
Jul 23 08:27:53 volumio volumio[951]: eta: '30s',
Jul 23 08:27:53 volumio volumio[951]: progress: 95,
Jul 23 08:27:53 volumio volumio[951]: status: 'Finalizing update' }
Jul 23 08:27:53 volumio volumio-remote-updater[512]: PROGRESS: 100, STATUS: "success", MESSAGE: "Successfully updated to \"2.799\" version. System restart required."
Jul 23 08:27:53 volumio volumio-remote-updater[512]: [2020-07-23 08:27:53] [disconnect] Disconnect close local:[1000] remote:[1000]
Jul 23 08:27:54 volumio systemd[1]: volumio-remote-updater.service holdoff time over, scheduling restart.
Regards,
Jonathan