Open brianmcgillion opened 1 month ago
@SuperSandro2000 Any ideas?
Maybe supervisord is not stopping after all processes it supervisors where told to stop. Maybe we can convince it with another signal?
Doing some more investigations and logging, I can see the following failures are occurring in the shutdown phase between supervisord
and the virtiofsd
processes
Aug 09 11:10:45 ghaf-host supervisord[1226]: virtiofsd-log-store [2024-08-09T07:10:45Z INFO virtiofsd] Client disconnected, shutting down
Aug 09 11:10:45 ghaf-host supervisord[1226]: virtiofsd-ro-store [2024-08-09T07:10:45Z INFO virtiofsd] Client disconnected, shutting down
Aug 09 11:10:45 ghaf-host microvm-virtiofsd@admin-vm[1226]: 2024-08-09 11:10:45,931 INFO exited: virtiofsd-log-store (exit status 0; expected)
Aug 09 11:10:45 ghaf-host systemd[1]: microvm@admin-vm.service: Deactivated successfully.
Aug 09 11:10:45 ghaf-host systemd[1]: Stopped MicroVM 'admin-vm'.
Aug 09 11:10:45 ghaf-host systemd[1]: microvm@admin-vm.service: Consumed 24.634s CPU time, 478.8M memory peak.
Aug 09 11:10:46 ghaf-host systemd[1]: Stopping VirtioFS daemons for MicroVM 'admin-vm'...
Aug 09 11:10:46 ghaf-host microvm-virtiofsd@admin-vm[1783]: ERROR: http://localhost:9001 refused connection (already shut down?)
Aug 09 11:10:46 ghaf-host systemd[1]: microvm-virtiofsd@admin-vm.service: Control process exited, code=exited, status=1/FAILURE
Aug 09 11:10:46 ghaf-host microvm-virtiofsd@admin-vm[1226]: 2024-08-09 11:10:46,166 WARN exited: notify (terminated by SIGTERM; not expected)
Aug 09 11:10:46 ghaf-host microvm-virtiofsd@admin-vm[1226]: 2024-08-09 11:10:46,166 WARN exited: virtiofsd-ro-store (exit status 1; not expected)
Aug 09 11:10:46 ghaf-host microvm-virtiofsd@admin-vm[1226]: 2024-08-09 11:10:46,166 WARN received SIGTERM indicating exit request
Aug 09 11:10:46 ghaf-host systemd[1]: microvm-virtiofsd@admin-vm.service: Failed with result 'exit-code'.
Aug 09 11:10:46 ghaf-host systemd[1]: Stopped VirtioFS daemons for MicroVM 'admin-vm'.
These commits introduce a substantial delay in rebooting or shutting down a VM. I am not sure commit exactly which, as the first one fails to start the virtiofs with a permission denied error. so tested together.
https://github.com/astro/microvm.nix/commit/36e261aa2c15a4020663cef87905f436b15305f7 https://github.com/astro/microvm.nix/commit/a50d1bf0d4a2f23ce2ffc503d65c9423a8a268e1
latest working commit is here: https://github.com/astro/microvm.nix/commit/bb0c6d867bae270288197e01449bba74ac0d381e
As can be seen in the below log for a reboot of the vm
sudo systemctl restart microvm@admin-vm.service
the shutdown takes 1.5 minutes before the graceful shutdown eventually times out.after which it starts to boot again as normal.