cc_grub_dpkg: race condition on dpkg-set-selections lock

This bug was originally filed in Launchpad as LP: #1986947

Launchpad user Chad Smith(chad.smith) wrote on 2022-08-18T13:35:39.133907+00:00

Intermittent failure found during jenkins test runs:

We probably want a couple quick retries if lock is held. https://github.com/canonical/cloud-init/blob/main/cloudinit/config/cc_grub_dpkg.py#L155

'2022-08-18 06:54:21,464 - handlers.py[DEBUG]: start: ' 'modules-config/config-grub-dpkg: running config-grub-dpkg with frequency ' 'once-per-instance\n' '2022-08-18 06:54:21,464 - util.py[DEBUG]: Writing to ' '/var/lib/cloud/instances/32493477-976f-924a-b363-1ddcabc724d9/sem/config_grub_dpkg ' '- wb: [644] 25 bytes\n' '2022-08-18 06:54:21,464 - helpers.py[DEBUG]: Running config-grub-dpkg using ' 'lock (<FileLock using file ' "'/var/lib/cloud/instances/32493477-976f-924a-b363-1ddcabc724d9/sem/config_grub_dpkg'>)\n" "2022-08-18 06:54:21,464 - subp.py[DEBUG]: Running command ['grub-probe', " "'-t', 'disk', '/boot'] with allowed return codes [0] (shell=False, " 'capture=True)\n' "2022-08-18 06:54:21,710 - subp.py[DEBUG]: Running command ['udevadm', " "'info', '--root', '--query=symlink', '/dev/sda'] with allowed return codes " '[0] (shell=False, capture=True)\n' '2022-08-18 06:54:21,713 - cc_grub_dpkg.py[DEBUG]: considering these device ' 'symlinks: ' '/dev/disk/azure/root,/dev/disk/by-id/scsi-36002248026fe88a16909c01e11d36751,/dev/disk/by-id/wwn-0x6002248026fe88a16909c01e11d36751,/dev/disk/by-path/acpi-VMBUS:01-scsi-0:0:0:0,/dev/disk/cloud/azure_root\n' '2022-08-18 06:54:21,714 - cc_grub_dpkg.py[DEBUG]: filtered to these ' 'disk/by-id symlinks: ' '/dev/disk/by-id/scsi-36002248026fe88a16909c01e11d36751,/dev/disk/by-id/wwn-0x6002248026fe88a16909c01e11d36751\n' '2022-08-18 06:54:21,714 - cc_grub_dpkg.py[DEBUG]: selected ' '/dev/disk/by-id/scsi-36002248026fe88a16909c01e11d36751\n' '2022-08-18 06:54:21,714 - cc_grub_dpkg.py[DEBUG]: Setting grub ' 'debconf-set-selections with ' "'/dev/disk/by-id/scsi-36002248026fe88a16909c01e11d36751','false'\n" '2022-08-18 06:54:21,714 - subp.py[DEBUG]: Running command ' "['debconf-set-selections'] with allowed return codes [0] (shell=False, " 'capture=True)\n' '2022-08-18 06:54:21,817 - util.py[WARNING]: Failed to run ' 'debconf-set-selections for grub-dpkg\n' '2022-08-18 06:54:21,823 - util.py[DEBUG]: Failed to run ' 'debconf-set-selections for grub-dpkg\n' 'Traceback (most recent call last):\n' ' File "/usr/lib/python3/dist-packages/cloudinit/config/cc_grub_dpkg.py", ' 'line 155, in handle\n' ' subp.subp(["debconf-set-selections"], dconf_sel)\n' ' File "/usr/lib/python3/dist-packages/cloudinit/subp.py", line 336, in ' 'subp\n' ' stdout=out, stderr=err, exit_code=rc, cmd=args\n' 'cloudinit.subp.ProcessExecutionError: Unexpected error while running ' 'command.\n' "Command: ['debconf-set-selections']\n" 'Exit code: 1\n' 'Reason: -\n' 'Stdout: \n' 'Stderr: debconf: DbDriver "config": /var/cache/debconf/config.dat is locked ' 'by another process: Resource temporarily unavailable\n'