pacman-init.service needs to be ordered before cloud-final.service
There is a race condition between cloud-init
based user data and the inline pacman-init.service
.
If cloud-init user-data defines packages to be installed, these will be installed with cloud-final.service
.
Unfortunately we don't have a service ordering between pacman-init.service
and cloud-final.service
, which leads to a race condition in which cloud-final might run pacman without the key being initialized, failing on this and leaving a half-initialized pacman keyring behind. The pacman-init.service
will then fail on that in turn.
cloud-final.service:
-- Logs begin at Mon 2020-11-30 17:35:57 UTC, end at Mon 2020-11-30 17:58:06 UTC. --
Nov 30 17:36:13 archlinux systemd[1]: Starting Execute cloud user/final scripts...
Nov 30 17:36:14 archlinux cloud-init[435]: :: Synchronizing package databases...
Nov 30 17:36:14 archlinux cloud-init[435]: downloading core.db...
Nov 30 17:36:14 archlinux cloud-init[435]: downloading extra.db...
Nov 30 17:36:14 archlinux cloud-init[435]: downloading community.db...
Nov 30 17:36:14 archlinux cloud-init[435]: :: Synchronizing package databases...
Nov 30 17:36:15 archlinux cloud-init[435]: core is up to date
Nov 30 17:36:15 archlinux cloud-init[435]: extra is up to date
Nov 30 17:36:15 archlinux cloud-init[435]: community is up to date
Nov 30 17:36:15 archlinux cloud-init[435]: :: There are 2 providers available for man:
Nov 30 17:36:15 archlinux cloud-init[435]: :: Repository core
Nov 30 17:36:15 archlinux cloud-init[435]: 1) man-db
Nov 30 17:36:15 archlinux cloud-init[435]: :: Repository community
Nov 30 17:36:15 archlinux cloud-init[435]: 2) mandoc
Nov 30 17:36:15 archlinux cloud-init[435]: Enter a number (default=1):
Nov 30 17:36:15 archlinux cloud-init[435]: resolving dependencies...
Nov 30 17:36:15 archlinux cloud-init[435]: looking for conflicting packages...
Nov 30 17:36:15 archlinux cloud-init[435]: Packages (16) geoip-1.6.12-2 geoip-database-20201110-1 gpm-1.20.7.r38.ge82d1a6-3 groff-1.22.4-3 libevent-2.1.12-1 libpipeline-1.5.3-1 libutempter-1.2.1-1 mailcap-2.1.49-1 vim-runtime-8.2.1989-2 man-db-2.9.3-1 man-pages-5.09-2 nginx-1.18.0-2 qemu-guest-agent-5.1.0-3 tmux-3.1_c-1 tree-1.8.0-2 vim-8.2.1989-2
Nov 30 17:36:15 archlinux cloud-init[435]: Total Download Size: 19.96 MiB
Nov 30 17:36:15 archlinux cloud-init[435]: Total Installed Size: 59.61 MiB
Nov 30 17:36:15 archlinux cloud-init[435]: :: Proceed with installation? [Y/n]
Nov 30 17:36:15 archlinux cloud-init[435]: :: Retrieving packages...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading libevent-2.1.12-1-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading gpm-1.20.7.r38.ge82d1a6-3-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading groff-1.22.4-3-x86_64.pkg.tar.xz...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading libpipeline-1.5.3-1-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading man-db-2.9.3-1-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading man-pages-5.09-2-any.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading geoip-database-20201110-1-any.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading geoip-1.6.12-2-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading mailcap-2.1.49-1-any.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading nginx-1.18.0-2-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading qemu-guest-agent-5.1.0-3-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading libutempter-1.2.1-1-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading tree-1.8.0-2-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading vim-runtime-8.2.1989-2-x86_64.pkg.tar.zst...
Nov 30 17:36:15 archlinux cloud-init[435]: downloading vim-8.2.1989-2-x86_64.pkg.tar.zst...
Nov 30 17:36:16 archlinux cloud-init[435]: downloading tmux-3.1_c-1-x86_64.pkg.tar.zst...
Nov 30 17:36:16 archlinux cloud-init[435]: checking keyring...
Nov 30 17:36:16 archlinux cloud-init[435]: downloading required keys...
Nov 30 17:36:16 archlinux cloud-init[435]: error: keyring is not writable
Nov 30 17:36:16 archlinux cloud-init[435]: error: keyring is not writable
Nov 30 17:36:16 archlinux cloud-init[435]: error: keyring is not writable
Nov 30 17:36:16 archlinux cloud-init[435]: error: keyring is not writable
Nov 30 17:36:16 archlinux cloud-init[435]: error: required key missing from keyring
Nov 30 17:36:16 archlinux cloud-init[435]: error: failed to commit transaction (unexpected error)
Nov 30 17:36:16 archlinux cloud-init[435]: Errors occurred, no packages were upgraded.
Nov 30 17:36:16 archlinux cloud-init[435]: Cloud-init v. 20.2 running 'modules:final' at Mon, 30 Nov 2020 17:36:13 +0000. Up 21.42 seconds.
Nov 30 17:36:16 archlinux cloud-init[435]: 2020-11-30 17:36:16,972 - util.py[WARNING]: Failed to install packages: ['nginx', 'qemu-guest-agent', 'tmux', 'tree', 'vim', 'man', 'man-pages']
Nov 30 17:36:16 archlinux cloud-init[435]: 2020-11-30 17:36:16,993 - cc_package_update_upgrade_install.py[WARNING]: 1 failed with exceptions, re-raising the last one
Nov 30 17:36:17 archlinux cloud-init[435]: 2020-11-30 17:36:17,006 - util.py[WARNING]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/lib/python3.8/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) failed
Nov 30 17:36:17 archlinux cloud-init[435]: Failed to enable unit: Unit file qemu-guest-agent.service does not exist.
Nov 30 17:36:17 archlinux cloud-init[435]: 2020-11-30 17:36:17,082 - util.py[WARNING]: Failed running /var/lib/cloud/instance/scripts/runcmd [1]
Nov 30 17:36:17 archlinux cloud-init[435]: 2020-11-30 17:36:17,082 - cc_scripts_user.py[WARNING]: Failed to run module scripts-user (scripts in /var/lib/cloud/instance/scripts)
Nov 30 17:36:17 archlinux cloud-init[435]: 2020-11-30 17:36:17,083 - util.py[WARNING]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3.8/site-packages/cloudinit/config/cc_scripts_user.py'>) failed
Nov 30 17:36:17 archlinux ec2[604]:
Nov 30 17:36:17 archlinux ec2[604]: #############################################################
Nov 30 17:36:17 archlinux ec2[604]: -----BEGIN SSH HOST KEY FINGERPRINTS-----
Nov 30 17:36:17 archlinux ec2[604]: 1024 SHA256:KpQbbTDo4bVHuln9KT14BLh/fLDMVkPfx0p6JblpzcE root@archlinux (DSA)
Nov 30 17:36:17 archlinux ec2[604]: 256 SHA256:q9zA0ZO8VR4ILnKhT5PURFTlp2ZMiIjj4XojcPva/iU root@archlinux (ECDSA)
Nov 30 17:36:17 archlinux ec2[604]: 256 SHA256:iRmTAdpiaw3P6pXMTPqZdCYHBlJS2XV89+an8/xW4Lk root@archlinux (ED25519)
Nov 30 17:36:17 archlinux ec2[604]: 3072 SHA256:iXUxbIjTn8dKHoeNHCgRqMV57NcPaO4Pzd0EM8xD3qU root@archlinux (RSA)
Nov 30 17:36:17 archlinux ec2[604]: -----END SSH HOST KEY FINGERPRINTS-----
Nov 30 17:36:17 archlinux ec2[604]: #############################################################
Nov 30 17:36:17 archlinux cloud-init[435]: Cloud-init v. 20.2 finished at Mon, 30 Nov 2020 17:36:17 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net]. Up 24.85 seconds
Nov 30 17:36:17 archlinux systemd[1]: cloud-final.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Nov 30 17:36:17 archlinux systemd[1]: cloud-final.service: Failed with result 'exit-code'.
Nov 30 17:36:17 archlinux systemd[1]: Failed to start Execute cloud user/final scripts.
pacman-init.service:
-- Logs begin at Mon 2020-11-30 17:35:57 UTC, end at Mon 2020-11-30 17:43:47 UTC. --
Nov 30 17:35:58 archlinux systemd[1]: Starting Initializes Pacman keyring...
Nov 30 17:35:58 archlinux pacman-key[257]: gpg: /etc/pacman.d/gnupg/trustdb.gpg: trustdb created
Nov 30 17:35:58 archlinux pacman-key[257]: gpg: no ultimately trusted keys found
Nov 30 17:35:59 archlinux pacman-key[278]: gpg: starting migration from earlier GnuPG versions
Nov 30 17:35:59 archlinux pacman-key[278]: gpg: porting secret keys from '/etc/pacman.d/gnupg/secring.gpg' to gpg-agent
Nov 30 17:35:59 archlinux pacman-key[278]: gpg: migration succeeded
Nov 30 17:35:59 archlinux pacman-key[284]: gpg: Generating pacman keyring master key...
Nov 30 17:36:06 archlinux pacman-key[284]: gpg: key 89774D90627C84A6 marked as ultimately trusted
Nov 30 17:36:06 archlinux pacman-key[284]: gpg: directory '/etc/pacman.d/gnupg/openpgp-revocs.d' created
Nov 30 17:36:06 archlinux pacman-key[284]: gpg: revocation certificate stored as '/etc/pacman.d/gnupg/openpgp-revocs.d/97D020CED2F3A86C57BAA1A689774D90627C84A6.rev'
Nov 30 17:36:06 archlinux pacman-key[284]: gpg: Done
Nov 30 17:36:06 archlinux pacman-key[249]: ==> Updating trust database...
Nov 30 17:36:06 archlinux pacman-key[403]: gpg: marginals needed: 3 completes needed: 1 trust model: pgp
Nov 30 17:36:06 archlinux pacman-key[403]: gpg: depth: 0 valid: 1 signed: 0 trust: 0-, 0q, 0n, 0m, 0f, 1u
Nov 30 17:36:06 archlinux pacman-key[404]: ==> Appending keys from archlinux.gpg...
Nov 30 17:36:14 archlinux pacman-key[404]: ==> Locally signing trusted keys in keyring...
Nov 30 17:36:14 archlinux pacman-key[404]: -> Locally signing key D8AFDDA07A5B6EDFA7D8CCDAD6D055F927843F1C...
Nov 30 17:36:14 archlinux pacman-key[404]: -> Locally signing key DDB867B92AA789C165EEFA799B729B06A680C281...
Nov 30 17:36:14 archlinux pacman-key[404]: -> Locally signing key 91FFE0700E80619CEB73235CA88E23E377514E00...
Nov 30 17:36:15 archlinux pacman-key[404]: -> Locally signing key 0E8B644079F599DFC1DDC3973348882F6AC6A4C2...
Nov 30 17:36:15 archlinux pacman-key[404]: -> Locally signing key AB19265E5D7D20687D303246BA1DFB64FFF979E7...
Nov 30 17:36:15 archlinux pacman-key[404]: ==> Importing owner trust values...
Nov 30 17:36:15 archlinux pacman-key[463]: gpg: inserting ownertrust of 4
Nov 30 17:36:15 archlinux pacman-key[463]: gpg: setting ownertrust to 4
Nov 30 17:36:15 archlinux pacman-key[463]: gpg: setting ownertrust to 4
Nov 30 17:36:15 archlinux pacman-key[463]: gpg: setting ownertrust to 4
Nov 30 17:36:15 archlinux pacman-key[463]: gpg: setting ownertrust to 4
Nov 30 17:36:15 archlinux pacman-key[404]: ==> Disabling revoked keys in keyring...
Nov 30 17:36:15 archlinux pacman-key[404]: -> Disabling key 8F76BEEA0289F9E1D3E229C05F946DED983D4366...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 63F395DE2D6398BBE458F281F2DBB4931985A992...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 50F33E2E5B0C3D900424ABE89BDCF497A4BBCC7F...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 27FFC4769E19F096D41D9265A04F9397CDFD6BB0...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 39F880E50E49A4D11341E8F939E4F17F295AFBF4...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 8840BD07FC24CB7CE394A07CCF7037A4F27FB7DA...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 5559BC1A32B8F76B3FCCD9555FA5E5544F010D48...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 0B20CA1931F5DA3A70D0F8D2EA6836E1AB441196...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 07DFD3A0BC213FA12EDC217559B3122E2FA915EC...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 4FCF887689C41B09506BE8D5F3E1D5C5D30DB0AD...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 5A2257D19FF7E1E0E415968CE62F853100F0D0F0...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key D921CABED130A5690EF1896E81AF739EC0711BF1...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 7FA647CD89891DEDC060287BB9113D1ED21E1A55...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key BC1FBE4D2826A0B51E47ED62E2539214C6C11350...
Nov 30 17:36:16 archlinux pacman-key[404]: -> Disabling key 4A8B17E20B88ACA61860009B5CED81B7C2E5C0D2...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 5696C003B0854206450C8E5BE613C09CB4440678...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 684148BB25B49E986A4944C55184252D824B18E8...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 8CF934E339CAD8ABF342E822E711306E3C4F88BC...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key F5A361A3A13554B85E57DDDAAF7EF7873CFD4BB6...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 5E7585ADFF106BFFBBA319DC654B877A0864983E...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 65EEFE022108E2B708CBFCF7F9E712E59AF5F22A...
Nov 30 17:36:17 archlinux pacman-key[587]: /usr/bin/pacman-key: line 338: printf: write error: Broken pipe
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 40440DC037C05620984379A6761FAD69BA06C6A9...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 34C5D94FE7E7913E86DC427E7FB1A3800C84C0A5...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 1A60DC44245D06FEF90623D6EEEEE2EEEE2EEEEE...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 81D7F8241DB38BC759C80FCE3A726C6170E80477...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key E7210A59715F6940CF9A4E36A001876699AD6E84...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 5357F3B111688D88C1D88119FCF2CB179205AC90...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 4D913AECD81726D9A6C74F0ADA6426DD215B37AD...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key FB871F0131FEA4FB5A9192B4C8880A6406361833...
Nov 30 17:36:17 archlinux pacman-key[616]: /usr/bin/pacman-key: line 338: printf: write error: Broken pipe
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 66BD74A036D522F51DD70A3C7F2A16726521E06D...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 487EACC08557AD082088DABA1EB2638FF56C0C53...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key B1F2C889CB2CCB2ADA36D963097D629E437520BD...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 9515D8A8EAB88E49BB65EDBCE6B456CAF15447D5...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 76B4192E902C0A52642C63C273B8ED52F1D357C1...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 40776A5221EF5AD468A4906D42A1DB15EC133BAD...
Nov 30 17:36:17 archlinux pacman-key[639]: /usr/bin/pacman-key: line 338: printf: write error: Broken pipe
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key D4DE5ABDE2A7287644EAC7E36D1A9E70E19DAA50...
Nov 30 17:36:17 archlinux pacman-key[404]: -> Disabling key 44D4A033AC140143927397D47EFD567D4C7EA887...
Nov 30 17:36:17 archlinux pacman-key[404]: ==> Updating trust database...
Nov 30 17:36:17 archlinux pacman-key[648]: gpg: public key of ultimately trusted key 89774D90627C84A6 not found
Nov 30 17:36:17 archlinux pacman-key[648]: gpg: marginals needed: 3 completes needed: 1 trust model: pgp
Nov 30 17:36:17 archlinux pacman-key[648]: gpg: depth: 0 valid: 1 signed: 0 trust: 0-, 0q, 0n, 0m, 0f, 1u
Nov 30 17:36:17 archlinux pacman-key[404]: ==> ERROR: Trust database could not be updated.
Nov 30 17:36:17 archlinux systemd[1]: pacman-init.service: Main process exited, code=exited, status=1/FAILURE
Nov 30 17:36:17 archlinux systemd[1]: pacman-init.service: Failed with result 'exit-code'.
Nov 30 17:36:17 archlinux systemd[1]: Failed to start Initializes Pacman keyring.