[Bug 1910815] Re: race on boot between multiple invocations of grub-editenv

Tue Feb 16 18:35:11 UTC 2021

booted hirsute instance and observed the race:

$ journalctl -u grub-initrd-fallback -u grub-common
-- Journal begins at Tue 2021-02-16 18:28:59 UTC, ends at Tue 2021-02-16 18:29:30 UTC. --
Feb 16 18:29:06 ip-172-31-7-49 systemd[1]: Starting Record successful boot for GRUB...
Feb 16 18:29:06 ip-172-31-7-49 systemd[1]: Starting GRUB failed boot detection...
Feb 16 18:29:06 ip-172-31-7-49 sh[528]: grub-editenv: error: invalid environment block.
Feb 16 18:29:06 ip-172-31-7-49 systemd[1]: Started Record successful boot for GRUB.
Feb 16 18:29:06 ip-172-31-7-49 systemd[1]: grub-initrd-fallback.service: Succeeded.
Feb 16 18:29:06 ip-172-31-7-49 systemd[1]: Finished GRUB failed boot detection.

Upgraded to

$ dpkg-query -W grub-efi-arm64 grub-efi-arm64-signed grub-efi-arm64-bin
grub-efi-arm64	2.04-1ubuntu40
grub-efi-arm64-bin	2.04-1ubuntu40
grub-efi-arm64-signed	1.161+2.04-1ubuntu40

Rebooted twice

Observed

$ journalctl -b -u grub-initrd-fallback -u grub-common

Feb 16 18:33:22 ip-172-31-7-49 systemd[1]: Starting Record successful boot for GRUB...
Feb 16 18:33:22 ip-172-31-7-49 systemd[1]: Started Record successful boot for GRUB.
Feb 16 18:33:22 ip-172-31-7-49 systemd[1]: Starting GRUB failed boot detection...
Feb 16 18:33:22 ip-172-31-7-49 systemd[1]: grub-initrd-fallback.service: Succeeded.
Feb 16 18:33:22 ip-172-31-7-49 systemd[1]: Finished GRUB failed boot detection.

Notice how one job starting & started; before the next one does starting & finished. Thus they are are now run in sequence.

Rather than having two Starting messages back to back

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to grub2 in Ubuntu.
https://bugs.launchpad.net/bugs/1910815

Title:
  race on boot between multiple invocations of grub-editenv

Status in grub2 package in Ubuntu:
  Fix Committed
Status in grub2 source package in Focal:
  Fix Committed
Status in grub2 source package in Groovy:
  Fix Committed
Status in grub2 source package in Hirsute:
  Fix Committed

Bug description:
  [Impact]

   * two grub systemd units run in parallel.

   * ensure they are serialzed.

  [Test Case]

   * boot on initrdless systems (such as modern/recent public cloud
  instances)

   * observe that grub-initrd-fallback.service is always after grub-
  common.service

   * observe that both are successful

  this is easy to view using

  $ sudo journalctl -u grub-initrd-fallback.service grub-common.service

  the output should be in order, not interleaved, with grub-common first
  and then grub-initrd-fallback.

  [Where problems could occur]

   * The boot is slightly slower as the two jobs are serialized, but
  they are not computationally intensive and shouldn't affect bootspeed
  at all, especially on multicore systems where other things are
  happening in parallel to these.

  [Other Info]

   * Original bug report

  On focal, it appears systemd can run /etc/init.d/grub-common in parallel with /lib/systemd/system/grub-initrd-fallback.service. Both of these invoke grub-editenv for different reasons, apparently resulting in race conditions that generate messages like this:

  Jan 08 18:07:15 asr-host systemd[1]: Starting LSB: Record successful boot for GRUB...
  Jan 08 18:07:15 asr-host systemd[1]: Starting GRUB failed boot detection...
  [..]
  Jan 08 18:07:15 asr-host grub-common[1822]:  * Recording successful boot for GRUB
  [..]
  Jan 08 18:07:16 asr-host grub-editenv[1886]: /usr/bin/grub-editenv: error: cannot rename the file /boot/grub/grubenv.new to /boot/grub/grubenv.
  Jan 08 18:07:16 asr-host systemd[1]: grub-initrd-fallback.service: Main process exited, code=exited, status=1/FAILURE
  Jan 08 18:07:16 asr-host systemd[1]: grub-initrd-fallback.service: Failed with result 'exit-code'.
  Jan 08 18:07:16 asr-host systemd[1]: Failed to start GRUB failed boot detection.
  Jan 08 18:07:16 asr-host grub-common[1822]:    ...done.
  Jan 08 18:07:16 asr-host systemd[1]: Started LSB: Record successful boot for GRUB.

  Google search for "Failed to start GRUB failed boot detection" throws
  up a few hits, which suggests this isn't necessarily something to
  weird about the machine I'm running on:

  https://www.google.co.uk/search?q=%22Failed+to+start+GRUB+failed+boot+detection.%22

  ProblemType: Bug
  DistroRelease: Ubuntu 20.04
  Package: grub-common 2.04-1ubuntu26.7
  ProcVersionSignature: Ubuntu 5.4.0-59.65-generic 5.4.78
  Uname: Linux 5.4.0-59-generic x86_64
  ApportVersion: 2.20.11-0ubuntu27.14
  Architecture: amd64
  CasperMD5CheckResult: skip
  Date: Fri Jan  8 20:19:42 2021
  ProcEnviron:
   TERM=screen.xterm-256color
   PATH=(custom, no user)
   LANG=en_GB.UTF-8
   SHELL=/bin/bash
  SourcePackage: grub2
  UpgradeStatus: Upgraded to focal on 2020-12-23 (15 days ago)

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/grub2/+bug/1910815/+subscriptions