Page MenuHomeVyOS Platform

grub: vyos-grub-update failed to start on "slow" systems
Closed, ResolvedPublicBUG

Description

The PCEngines APU2 systems with mSATA disks tend to be very slow. This results in a service startup error:

$ systemctl status vyos-grub-update
× vyos-grub-update.service - Update GRUB loader configuration structure
     Loaded: loaded (/lib/systemd/system/vyos-grub-update.service; enabled; preset: enabled)
     Active: failed (Result: timeout) since Sun 2024-03-24 08:48:10 UTC; 14min ago
   Main PID: 779 (code=killed, signal=TERM)
        CPU: 869ms

Mar 24 08:48:05 LR4.wue3 systemd[1]: Starting vyos-grub-update.service - Update GRUB loader configuration structure...
Mar 24 08:48:10 LR4.wue3 systemd[1]: vyos-grub-update.service: start operation timed out. Terminating.
Mar 24 08:48:10 LR4.wue3 systemd[1]: vyos-grub-update.service: Main process exited, code=killed, status=15/TERM
Mar 24 08:48:10 LR4.wue3 systemd[1]: vyos-grub-update.service: Failed with result 'timeout'.
Mar 24 08:48:10 LR4.wue3 systemd[1]: Failed to start vyos-grub-update.service - Update GRUB loader configuration structure.

Measunring on an APU2 system after boot and memory is "hot", it still needs almost 17 seconds to complete the job

[email protected]:~$ time sudo /usr/libexec/vyos/system/grub_update.py
real    0m16.803s
user    0m0.018s
sys     0m0.028s

Fix

Increasing the timeout to 60 seconds get's rid of the problem as there's plenty time to startup the service

[email protected]:~$ systemctl status vyos-grub-update
○ vyos-grub-update.service - Update GRUB loader configuration structure
     Loaded: loaded (/lib/systemd/system/vyos-grub-update.service; enabled; preset: enabled)
     Active: inactive (dead) since Sun 2024-03-24 09:12:49 UTC; 1min 52s ago
   Main PID: 780 (code=exited, status=0/SUCCESS)
        CPU: 24.961s

Mar 24 09:12:09 LR4.wue3 systemd[1]: Starting vyos-grub-update.service - Update GRUB loader configuration structure...
Mar 24 09:12:49 LR4.wue3 systemd[1]: vyos-grub-update.service: Deactivated successfully.
Mar 24 09:12:49 LR4.wue3 systemd[1]: Finished vyos-grub-update.service - Update GRUB loader configuration structure.
Mar 24 09:12:49 LR4.wue3 systemd[1]: vyos-grub-update.service: Consumed 24.961s CPU time.

Details

Difficulty level
Easy (less than an hour)
Version
1.4.0-epa2
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Perfectly compatible
Issue type
Performance optimization

Event Timeline

c-po changed the task status from Open to In progress.Mar 24 2024, 9:17 AM
c-po claimed this task.
c-po triaged this task as High priority.
c-po created this task.
c-po changed Difficulty level from Unknown (require assessment) to Easy (less than an hour).
c-po changed Is it a breaking change? from Unspecified (possibly destroys the router) to Perfectly compatible.
c-po changed Issue type from Unspecified (please specify) to Performance optimization.
c-po moved this task from In Progress to Finished on the VyOS 1.4 Sagitta (1.4.0-epa3) board.