Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Save rfairley/34f00d99e3c330a84ddbec87db5df175 to your computer and use it in GitHub Desktop.
Save rfairley/34f00d99e3c330a84ddbec87db5df175 to your computer and use it in GitHub Desktop.
Failing coreos-cloudinit config of locksmithd

Failing coreos-cloudinit config of locksmithd

This shows a failing and a successful case of coreos-cloudint configuring locksmith with the config used in coreos/bugs#2463. 20-cloudinit.conf is written before locksmithd is active, it seems, so this is not the race condition causing the failure. The logs have not revealed the cause of the failure.

The journalctl commands use -t to specify a syslog ID rather than -u for a unit, due to systemd/systemd#2913.

Steps to get logs

  • Use the userdata in the bug linked above.
  • First boot CL, passing in the userdata as cloud-config.
  • SSH into the machine.
  • Enter the "Command to show logs" (see below).

Failing config

Command to show logs

journalctl -b [=ID] -t "coreos-cloudinit" -t "locksmithd" -t "systemd"

Logs

-- Logs begin at Mon 2018-07-23 14:47:42 UTC, end at Wed 2018-07-25 14:41:40 UTC. --
Jul 23 14:47:42 localhost systemd[1]: systemd 238 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS -ACL +XZ +LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN +PCRE2 default-hierarchy=legacy)
Jul 23 14:47:42 localhost systemd[1]: Detected virtualization kvm.
Jul 23 14:47:42 localhost systemd[1]: Detected architecture x86-64.
Jul 23 14:47:42 localhost systemd[1]: Running in initial RAM disk.
Jul 23 14:47:42 localhost systemd[1]: No hostname configured.
Jul 23 14:47:42 localhost systemd[1]: Set hostname to <localhost>.
Jul 23 14:47:42 localhost systemd[1]: Initializing machine ID from random generator.
Jul 23 14:47:42 localhost systemd[1]: File /usr/lib/systemd/system/systemd-journald.service:35 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
Jul 23 14:47:42 localhost systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
Jul 23 14:47:42 localhost systemd[1]: Listening on udev Control Socket.
Jul 23 14:47:42 localhost systemd[1]: Started dracut cmdline hook.
Jul 23 14:47:42 localhost systemd[1]: Starting dracut pre-udev hook...
Jul 23 14:47:42 localhost systemd[1]: Started dracut pre-udev hook.
Jul 23 14:47:42 localhost systemd[1]: Starting udev Kernel Device Manager...
Jul 23 14:47:42 localhost systemd[1]: Started udev Kernel Device Manager.
Jul 23 14:47:42 localhost systemd[1]: Starting Network Service...
Jul 23 14:47:42 localhost systemd[1]: Starting dracut pre-trigger hook...
Jul 23 14:47:42 localhost systemd[1]: Started Network Service.
Jul 23 14:47:42 localhost systemd[1]: Starting Network Name Resolution...
Jul 23 14:47:42 localhost systemd[1]: Started Network Name Resolution.
Jul 23 14:47:42 localhost systemd[1]: Started dracut pre-trigger hook.
Jul 23 14:47:42 localhost systemd[1]: Starting udev Coldplug all Devices...
Jul 23 14:47:42 localhost systemd[1]: Reached target Host and Network Name Lookups.
Jul 23 14:47:42 localhost systemd[1]: Reached target Network.
Jul 23 14:47:42 localhost systemd[1]: Started udev Coldplug all Devices.
Jul 23 14:47:42 localhost systemd[1]: Starting dracut initqueue hook...
Jul 23 14:47:42 localhost systemd[1]: Found device /dev/disk/by-diskuuid/00000000-0000-0000-0000-000000000001.
Jul 23 14:47:42 localhost systemd[1]: Found device /dev/disk/by-label/OEM.
Jul 23 14:47:42 localhost systemd[1]: Found device /dev/disk/by-label/EFI-SYSTEM.
Jul 23 14:47:42 localhost systemd[1]: Found device /dev/disk/by-label/ROOT.
Jul 23 14:47:42 localhost systemd[1]: Found device /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132.
Jul 23 14:47:42 localhost systemd[1]: Reached target Initrd Root Device.
Jul 23 14:47:42 localhost systemd[1]: Starting Generate new UUID for disk GPT dev/disk/by-diskuuid/00000000-0000-0000-0000-000000000001...
Jul 23 14:47:43 localhost systemd[1]: Started dracut initqueue hook.
Jul 23 14:47:43 localhost systemd[1]: Reached target Remote File Systems (Pre).
Jul 23 14:47:43 localhost systemd[1]: Reached target Remote File Systems.
Jul 23 14:47:43 localhost systemd[1]: Starting dracut pre-mount hook...
Jul 23 14:47:43 localhost systemd[1]: Started dracut pre-mount hook.
Jul 23 14:47:44 localhost systemd[1]: Started Generate new UUID for disk GPT dev/disk/by-diskuuid/00000000-0000-0000-0000-000000000001.
Jul 23 14:47:44 localhost systemd[1]: Starting Ignition (setup)...
Jul 23 14:47:44 localhost systemd[1]: Started Ignition (setup).
Jul 23 14:47:44 localhost systemd[1]: Starting Ignition (disks)...
Jul 23 14:47:44 localhost systemd[1]: Started Ignition (disks).
Jul 23 14:47:44 localhost systemd[1]: Reached target Local File Systems (Pre).
Jul 23 14:47:44 localhost systemd[1]: Reached target Local File Systems.
Jul 23 14:47:44 localhost systemd[1]: Reached target System Initialization.
Jul 23 14:47:44 localhost systemd[1]: Reached target Basic System.
Jul 23 14:47:44 localhost systemd[1]: Starting File System Check on /dev/disk/by-label/ROOT...
Jul 23 14:47:44 localhost systemd[1]: Starting Verity Setup for /dev/mapper/usr...
Jul 23 14:47:44 localhost systemd[1]: Started File System Check on /dev/disk/by-label/ROOT.
Jul 23 14:47:44 localhost systemd[1]: Mounting /sysroot...
Jul 23 14:47:44 localhost systemd[1]: Mounted /sysroot.
Jul 23 14:47:44 localhost systemd[1]: Reached target Initrd Root File System.
Jul 23 14:47:44 localhost systemd[1]: Found device /dev/mapper/usr.
Jul 23 14:47:44 localhost systemd[1]: Mounting /sysroot/usr...
Jul 23 14:47:44 localhost systemd[1]: Started Verity Setup for /dev/mapper/usr.
Jul 23 14:47:44 localhost systemd[1]: Mounted /sysroot/usr.
Jul 23 14:47:44 localhost systemd[1]: Starting Root filesystem setup...
Jul 23 14:47:44 localhost systemd[1]: Started Root filesystem setup.
Jul 23 14:47:44 localhost systemd[1]: Starting Ignition (files)...
Jul 23 14:47:44 localhost systemd[1]: Starting /sysroot/boot...
Jul 23 14:47:44 localhost systemd[1]: Started Ignition (files).
Jul 23 14:47:44 localhost systemd[1]: Starting Reload Configuration from the Real Root...
Jul 23 14:47:44 localhost systemd[1]: Started /sysroot/boot.
Jul 23 14:47:44 localhost systemd[1]: Starting Ignition (record completion)...
Jul 23 14:47:44 localhost systemd[1]: Started Ignition (record completion).
Jul 23 14:47:44 localhost systemd[1]: Reloading.
Jul 23 14:47:44 localhost systemd[1]: Started Reload Configuration from the Real Root.
Jul 23 14:47:44 localhost systemd[1]: Reached target Initrd File Systems.
Jul 23 14:47:44 localhost systemd[1]: Reached target Initrd Default Target.
Jul 23 14:47:44 localhost systemd[1]: Starting dracut pre-pivot and cleanup hook...
Jul 23 14:47:44 localhost systemd[1]: Started dracut pre-pivot and cleanup hook.
Jul 23 14:47:44 localhost systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
Jul 23 14:47:44 localhost systemd[1]: Stopped target Host and Network Name Lookups.
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut pre-pivot and cleanup hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Network.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Remote File Systems.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Timers.
Jul 23 14:47:44 localhost systemd[1]: Stopping Network Name Resolution...
Jul 23 14:47:44 localhost systemd[1]: Stopped target Initrd Default Target.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Initrd Root Device.
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut pre-mount hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Basic System.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Sockets.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Slices.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Paths.
Jul 23 14:47:44 localhost systemd[1]: Stopped target System Initialization.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Local Encrypted Volumes.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Local File Systems.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Local File Systems (Pre).
Jul 23 14:47:44 localhost systemd[1]: Stopped target Swap.
Jul 23 14:47:44 localhost systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
Jul 23 14:47:44 localhost systemd[1]: Stopped target Remote File Systems (Pre).
Jul 23 14:47:44 localhost systemd[1]: Stopping /sysroot/boot...
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut initqueue hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped udev Coldplug all Devices.
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut pre-trigger hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped Network Name Resolution.
Jul 23 14:47:44 localhost systemd[1]: Stopping Network Service...
Jul 23 14:47:44 localhost systemd[1]: Started Cleaning Up and Shutting Down Daemons.
Jul 23 14:47:44 localhost systemd[1]: Stopped /sysroot/boot.
Jul 23 14:47:44 localhost systemd[1]: Stopped Network Service.
Jul 23 14:47:44 localhost systemd[1]: Stopped Apply Kernel Variables.
Jul 23 14:47:44 localhost systemd[1]: Stopping udev Kernel Device Manager...
Jul 23 14:47:44 localhost systemd[1]: Stopped udev Kernel Device Manager.
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut pre-udev hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped dracut cmdline hook.
Jul 23 14:47:44 localhost systemd[1]: Stopped Create Static Device Nodes in /dev.
Jul 23 14:47:44 localhost systemd[1]: Stopped Create list of required static device nodes for the current kernel.
Jul 23 14:47:44 localhost systemd[1]: Closed udev Control Socket.
Jul 23 14:47:44 localhost systemd[1]: Closed udev Kernel Socket.
Jul 23 14:47:44 localhost systemd[1]: Starting Cleanup udevd DB...
Jul 23 14:47:44 localhost systemd[1]: Started Cleanup udevd DB.
Jul 23 14:47:44 localhost systemd[1]: Reached target Switch Root.
Jul 23 14:47:44 localhost systemd[1]: Starting Switch Root...
Jul 23 14:47:44 localhost systemd[1]: Switching root.
Jul 23 14:47:47 localhost systemd[1]: Successfully loaded SELinux policy in 145.188ms.
Jul 23 14:47:47 localhost systemd[1]: Relabelled /dev, /run and /sys/fs/cgroup in 6.294ms.
Jul 23 14:47:47 localhost systemd[1]: systemd 238 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS -ACL +XZ +LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN +PCRE2 default-hierarchy=legacy)
Jul 23 14:47:47 localhost systemd[1]: Detected virtualization kvm.
Jul 23 14:47:47 localhost systemd[1]: Detected architecture x86-64.
Jul 23 14:47:47 localhost systemd[1]: Running with unpopulated /etc.
Jul 23 14:47:47 localhost systemd[1]: Initializing machine ID from random generator.
Jul 23 14:47:47 localhost systemd[1]: Populated /etc with preset unit settings.
Jul 23 14:47:47 localhost systemd[1]: File /usr/lib/systemd/system/systemd-journald.service:35 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
Jul 23 14:47:47 localhost systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
Jul 23 14:47:47 localhost systemd[1]: Stopped Switch Root.
Jul 23 14:47:47 localhost systemd[1]: systemd-journald.service: Service has no hold-off time, scheduling restart.
Jul 23 14:47:47 localhost systemd[1]: Mounted POSIX Message Queue File System.
Jul 23 14:47:47 localhost systemd[1]: Started Create list of required static device nodes for the current kernel.
Jul 23 14:47:47 localhost systemd[1]: Mounted External Media Directory.
Jul 23 14:47:47 localhost systemd[1]: Mounted Kernel Debug File System.
Jul 23 14:47:47 localhost systemd[1]: Started Create missing system files.
Jul 23 14:47:47 localhost systemd[1]: Mounted Huge Pages File System.
Jul 23 14:47:47 localhost systemd[1]: Mounted Temporary Directory (/tmp).
Jul 23 14:47:47 localhost systemd[1]: Started Load/Save Random Seed.
Jul 23 14:47:47 localhost systemd[1]: Started Apply Kernel Variables.
Jul 23 14:47:47 localhost systemd[1]: Starting Create System Users...
Jul 23 14:47:47 localhost systemd[1]: Starting Flush Journal to Persistent Storage...
Jul 23 14:47:47 localhost systemd[1]: Started udev Coldplug all Devices.
Jul 23 14:47:47 localhost systemd[1]: Starting udev Wait for Complete Device Initialization...
Jul 23 14:47:47 localhost systemd[1]: Started Create System Users.
Jul 23 14:47:47 localhost systemd[1]: Starting Create Static Device Nodes in /dev...
Jul 23 14:47:47 localhost systemd[1]: Started Flush Journal to Persistent Storage.
Jul 23 14:47:47 localhost systemd[1]: Started Create Static Device Nodes in /dev.
Jul 23 14:47:47 localhost systemd[1]: Started Rebuild Hardware Database.
Jul 23 14:47:47 localhost systemd[1]: Starting udev Kernel Device Manager...
Jul 23 14:47:47 localhost systemd[1]: Started udev Kernel Device Manager.
Jul 23 14:47:47 localhost systemd[1]: Starting Network Service...
Jul 23 14:47:47 localhost systemd[1]: Started Network Service.
Jul 23 14:47:47 localhost systemd[1]: Found device /dev/disk/by-label/OEM.
Jul 23 14:47:47 localhost systemd[1]: Found device /dev/ttyS0.
Jul 23 14:47:47 localhost systemd[1]: Starting Create missing system files...
Jul 23 14:47:47 localhost systemd[1]: Started Create missing system files.
Jul 23 14:47:47 localhost systemd[1]: Started udev Wait for Complete Device Initialization.
Jul 23 14:47:47 localhost systemd[1]: Starting Activation of LVM2 logical volumes...
Jul 23 14:47:47 localhost systemd[1]: Started Activation of LVM2 logical volumes.
Jul 23 14:47:47 localhost systemd[1]: Reached target Local Encrypted Volumes.
Jul 23 14:47:47 localhost systemd[1]: Starting Activation of LVM2 logical volumes...
Jul 23 14:47:47 localhost systemd[1]: Started Activation of LVM2 logical volumes.
Jul 23 14:47:47 localhost systemd[1]: Reached target Local File Systems (Pre).
Jul 23 14:47:47 localhost systemd[1]: Mounting /media/configvirtfs...
Jul 23 14:47:47 localhost systemd[1]: Reached target Containers.
Jul 23 14:47:47 localhost systemd[1]: Starting File System Check on /dev/disk/by-label/EFI-SYSTEM...
Jul 23 14:47:47 localhost systemd[1]: Starting File System Check on /dev/disk/by-label/OEM...
Jul 23 14:47:47 localhost systemd[1]: Mounted /media/configvirtfs.
Jul 23 14:47:47 localhost systemd[1]: Started File System Check on /dev/disk/by-label/EFI-SYSTEM.
Jul 23 14:47:47 localhost systemd[1]: Mounting Boot partition...
Jul 23 14:47:47 localhost systemd[1]: Mounted Boot partition.
Jul 23 14:47:47 localhost systemd[1]: Started File System Check on /dev/disk/by-label/OEM.
Jul 23 14:47:47 localhost systemd[1]: Mounting /usr/share/oem...
Jul 23 14:47:47 localhost systemd[1]: Mounted /usr/share/oem.
Jul 23 14:47:47 localhost systemd[1]: Reached target Local File Systems.
Jul 23 14:47:47 localhost systemd[1]: Starting Create Volatile Files and Directories...
Jul 23 14:47:47 localhost systemd[1]: Starting Rebuild Journal Catalog...
Jul 23 14:47:47 localhost systemd[1]: Starting Rebuild Dynamic Linker Cache...
Jul 23 14:47:47 localhost systemd[1]: Started Rebuild Journal Catalog.
Jul 23 14:47:47 localhost systemd[1]: Started Create Volatile Files and Directories.
Jul 23 14:47:47 localhost systemd[1]: Starting Load Security Auditing Rules...
Jul 23 14:47:47 localhost systemd[1]: Starting Network Time Synchronization...
Jul 23 14:47:47 localhost systemd[1]: Starting Network Name Resolution...
Jul 23 14:47:47 localhost systemd[1]: Starting Clean up broken links in /etc/ssl/certs...
Jul 23 14:47:47 localhost systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Jul 23 14:47:47 localhost systemd[1]: Started Clean up broken links in /etc/ssl/certs.
Jul 23 14:47:47 localhost systemd[1]: Started Update UTMP about System Boot/Shutdown.
Jul 23 14:47:47 localhost systemd[1]: Started Load Security Auditing Rules.
Jul 23 14:47:47 localhost systemd[1]: Started Network Time Synchronization.
Jul 23 14:47:47 localhost systemd[1]: Reached target System Time Synchronized.
Jul 23 14:47:47 localhost systemd[1]: Started Network Name Resolution.
Jul 23 14:47:47 localhost systemd[1]: Reached target Network.
Jul 23 14:47:47 localhost systemd[1]: Reached target Host and Network Name Lookups.
Jul 23 14:47:48 localhost systemd[1]: Started Rebuild Dynamic Linker Cache.
Jul 23 14:47:48 localhost systemd[1]: Starting Update is Completed...
Jul 23 14:47:48 localhost systemd[1]: Started Update is Completed.
Jul 23 14:47:48 localhost systemd[1]: Reached target System Initialization.
Jul 23 14:47:48 localhost systemd[1]: Started Watch for a cloud-config at /var/lib/coreos-install/user_data.
Jul 23 14:47:48 localhost systemd[1]: Starting Docker Socket for the API.
Jul 23 14:47:48 localhost systemd[1]: Starting rkt metadata service socket.
Jul 23 14:47:48 localhost systemd[1]: Started Periodic Garbage Collection for rkt.
Jul 23 14:47:48 localhost systemd[1]: Started Daily Cleanup of Temporary Directories.
Jul 23 14:47:48 localhost systemd[1]: Started Daily Log Rotation.
Jul 23 14:47:48 localhost systemd[1]: Listening on OpenSSH Server Socket.
Jul 23 14:47:48 localhost systemd[1]: Reached target Timers.
Jul 23 14:47:48 localhost systemd[1]: Started Watch for update engine configuration changes.
Jul 23 14:47:48 localhost systemd[1]: Reached target Paths.
Jul 23 14:47:48 localhost systemd[1]: Listening on D-Bus System Message Bus Socket.
Jul 23 14:47:48 localhost systemd[1]: Listening on Docker Socket for the API.
Jul 23 14:47:48 localhost systemd[1]: Listening on rkt metadata service socket.
Jul 23 14:47:48 localhost systemd[1]: Reached target Sockets.
Jul 23 14:47:48 localhost systemd[1]: Reached target Basic System.
Jul 23 14:47:48 localhost systemd[1]: Starting Extend Filesystems...
Jul 23 14:47:48 localhost systemd[1]: Starting Garbage Collection for rkt...
Jul 23 14:47:48 localhost systemd[1]: Starting Install an ssh key from /proc/cmdline...
Jul 23 14:47:48 localhost systemd[1]: Starting Generate /run/coreos/motd...
Jul 23 14:47:48 localhost systemd[1]: Starting Generate sshd host keys...
Jul 23 14:47:48 localhost systemd[1]: Starting Load cloud-config from /media/configvirtfs...
Jul 23 14:47:48 localhost systemd[1]: Starting Login Service...
Jul 23 14:47:48 localhost systemd[1]: Started D-Bus System Message Bus.
Jul 23 14:47:48 localhost systemd[1]: Starting Load cloud-config from /usr/share/coreos/developer_data...
Jul 23 14:47:48 localhost systemd[1]: Starting Update Engine...
Jul 23 14:47:48 localhost systemd[1]: Started Install an ssh key from /proc/cmdline.
Jul 23 14:47:48 localhost systemd[1]: Started Generate /run/coreos/motd.
Jul 23 14:47:49 localhost systemd[1]: Started Extend Filesystems.
Jul 23 14:47:49 localhost systemd[1]: Started Login Service.
Jul 23 14:47:49 localhost systemd[1]: Starting Hostname Service...
Jul 23 14:47:49 localhost systemd[1]: Started Update Engine.
Jul 23 14:47:49 localhost systemd[1]: Started Cluster reboot manager.
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Checking availability of "local-file"
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Fetching user-data from datasource of type "local-file"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Checking availability of "cloud-drive"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Fetching user-data from datasource of type "cloud-drive"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Attempting to read from "/media/configvirtfs/openstack/latest/user_data"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Fetching meta-data from datasource of type "cloud-drive"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Attempting to read from "/media/configvirtfs/openstack/latest/meta_data.json"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Parsing user-data as cloud-config
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Merging cloud-config from meta-data and user-data
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Ensuring runtime unit file "etcd.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Ensuring runtime unit file "etcd2.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Ensuring runtime unit file "fleet.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Writing drop-in unit "20-cloudinit.conf" to filesystem
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Writing file to "/run/systemd/system/locksmithd.service.d/20-cloudinit.conf"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Wrote file to "/run/systemd/system/locksmithd.service.d/20-cloudinit.conf"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Wrote drop-in unit "20-cloudinit.conf"
Jul 23 14:47:49 localhost coreos-cloudinit[790]: 2018/07/23 14:47:49 Ensuring runtime unit file "locksmithd.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Fetching meta-data from datasource of type "local-file"
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Parsing user-data as cloud-config
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Merging cloud-config from meta-data and user-data
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 User 'core' exists, ignoring creation-time fields
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Setting 'core' user's password
Jul 23 14:47:49 localhost systemd[1]: Reloading.
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Ensuring runtime unit file "etcd.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Ensuring runtime unit file "etcd2.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Ensuring runtime unit file "fleet.service" is unmasked
Jul 23 14:47:49 localhost coreos-cloudinit[795]: 2018/07/23 14:47:49 Ensuring runtime unit file "locksmithd.service" is unmasked
Jul 23 14:47:49 localhost locksmithd[826]: No configured reboot window
Jul 23 14:47:49 localhost locksmithd[826]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot"
Jul 23 14:47:49 localhost systemd[1]: Started Garbage Collection for rkt.
Jul 23 14:47:49 localhost systemd[1]: Started Generate sshd host keys.
Jul 23 14:47:49 localhost systemd[1]: Started Load cloud-config from /media/configvirtfs.
Jul 23 14:47:49 localhost systemd[1]: Started Load cloud-config from /usr/share/coreos/developer_data.
Jul 23 14:47:49 localhost systemd[1]: Started Hostname Service.
Jul 23 14:47:49 localhost systemd[1]: Starting Authorization Manager...
Jul 23 14:47:49 localhost systemd[1]: Starting Generate /run/issue...
Jul 23 14:47:49 localhost systemd[1]: Reached target Load system-provided cloud configs.
Jul 23 14:47:49 localhost systemd[1]: Reached target Load user-provided cloud configs.
Jul 23 14:47:49 localhost systemd[1]: Started Generate /run/issue.
Jul 23 14:47:49 localhost systemd[1]: Starting Permit User Sessions...
Jul 23 14:47:49 localhost systemd[1]: Started Permit User Sessions.
Jul 23 14:47:49 localhost systemd[1]: Started Serial Getty on ttyS0.
Jul 23 14:47:49 localhost systemd[1]: Started Getty on tty1.
Jul 23 14:47:49 localhost systemd[1]: Reached target Login Prompts.
Jul 23 14:47:49 localhost systemd[1]: Reached target Multi-User System.
Jul 23 14:47:49 localhost systemd[1]: Started Authorization Manager.
Jul 23 14:47:49 localhost systemd[1]: Startup finished in 1.192s (kernel) + 2.100s (initrd) + 3.827s (userspace) = 7.120s.
Jul 23 14:47:57 coreos_production_qemu-1814-0-0- systemd[1]: Created slice system-sshd.slice.
Jul 23 14:47:57 coreos_production_qemu-1814-0-0- systemd[1]: Started OpenSSH per-connection server daemon (10.0.2.2:39296).
Jul 23 14:48:13 coreos_production_qemu-1814-0-0- systemd[1]: Started OpenSSH per-connection server daemon (10.0.2.2:39300).
Jul 23 14:49:34 coreos_production_qemu-1814-0-0- systemd[1]: Started OpenSSH per-connection server daemon (10.0.2.2:39304).
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[1]: Created slice User Slice of core.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[1]: Starting User Manager for UID 500...
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[1]: Started Session 1 of user core.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: pam_unix(systemd-user:session): session opened for user core by (uid=0)
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Reached target Sockets.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Reached target Paths.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Reached target Timers.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Reached target Basic System.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Reached target Default.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[912]: Startup finished in 17ms.
Jul 23 14:50:27 coreos_production_qemu-1814-0-0- systemd[1]: Started User Manager for UID 500.
Jul 23 14:50:39 coreos_production_qemu-1814-0-0- locksmithd[826]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_CHECKING_FOR_UPDATE" NewVersion=0.0.0 NewSize=0
Jul 23 14:50:40 coreos_production_qemu-1814-0-0- locksmithd[826]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_REPORTING_ERROR_EVENT" NewVersion=0.0.0 NewSize=0
Jul 23 14:50:41 coreos_production_qemu-1814-0-0- locksmithd[826]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_IDLE" NewVersion=0.0.0 NewSize=0
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- systemd[1]: Stopping Cluster reboot manager...
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- locksmithd[826]: Received interrupt/termination signal - locksmithd is exiting.
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- systemd[1]: Stopped Cluster reboot manager.
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- systemd[1]: Started Cluster reboot manager.
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- locksmithd[959]: Reboot window start is "23:00" and length is "2h"
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- locksmithd[959]: Next window begins at 2018-07-23 23:00:00 +0000 UTC and ends at 2018-07-24 01:00:00 +0000 UTC
Jul 23 14:55:33 coreos_production_qemu-1814-0-0- locksmithd[959]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot"
Jul 23 14:55:54 coreos_production_qemu-1814-0-0- systemd[1]: Reloading.
Jul 23 14:55:54 coreos_production_qemu-1814-0-0- systemd[1]: Starting Garbage Collection for rkt...
Jul 23 14:55:54 coreos_production_qemu-1814-0-0- systemd[1]: Started Garbage Collection for rkt.

Successful config

Command to show logs (note the systemd SYSLOG_IDENTIFIER was excluded)

journalctl -b [=ID] -t "coreos-cloudinit" -t "locksmithd"

Logs

-- Logs begin at Wed 2018-07-25 14:11:36 UTC, end at Wed 2018-07-25 15:17:04 UTC. --
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Checking availability of "local-file"
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Fetching user-data from datasource of type "local-file"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Checking availability of "cloud-drive"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Fetching user-data from datasource of type "cloud-drive"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Attempting to read from "/media/configvirtfs/openstack/latest/user_data"
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Fetching meta-data from datasource of type "local-file"
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Parsing user-data as cloud-config
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Merging cloud-config from meta-data and user-data
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Fetching meta-data from datasource of type "cloud-drive"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Attempting to read from "/media/configvirtfs/openstack/latest/meta_data.json"
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 User 'core' exists, ignoring creation-time fields
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Setting 'core' user's password
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Parsing user-data as cloud-config
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Merging cloud-config from meta-data and user-data
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Ensuring runtime unit file "etcd.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Ensuring runtime unit file "etcd2.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Ensuring runtime unit file "fleet.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Writing drop-in unit "20-cloudinit.conf" to filesystem
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Writing file to "/run/systemd/system/locksmithd.service.d/20-cloudinit.conf"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Wrote file to "/run/systemd/system/locksmithd.service.d/20-cloudinit.conf"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Wrote drop-in unit "20-cloudinit.conf"
Jul 25 14:11:41 localhost coreos-cloudinit[814]: 2018/07/25 14:11:41 Ensuring runtime unit file "locksmithd.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Ensuring runtime unit file "etcd.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Ensuring runtime unit file "etcd2.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Ensuring runtime unit file "fleet.service" is unmasked
Jul 25 14:11:41 localhost coreos-cloudinit[811]: 2018/07/25 14:11:41 Ensuring runtime unit file "locksmithd.service" is unmasked
Jul 25 14:11:42 coreos_production_qemu-1828-0-0- locksmithd[892]: Reboot window start is "23:00" and length is "2h"
Jul 25 14:11:42 coreos_production_qemu-1828-0-0- locksmithd[892]: Next window begins at 2018-07-25 23:00:00 +0000 UTC and ends at 2018-07-26 01:00:00 +0000 UTC
Jul 25 14:11:42 coreos_production_qemu-1828-0-0- locksmithd[892]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot"
Jul 25 14:17:44 coreos_production_qemu-1828-0-0- locksmithd[892]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_CHECKING_FOR_UPDATE" NewVersion=0.0.0 N>
Jul 25 14:17:45 coreos_production_qemu-1828-0-0- locksmithd[892]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_REPORTING_ERROR_EVENT" NewVersion=0.0.0>
Jul 25 14:17:46 coreos_production_qemu-1828-0-0- locksmithd[892]: LastCheckedTime=0 Progress=0 CurrentOperation="UPDATE_STATUS_IDLE" NewVersion=0.0.0 NewSize=0
@rfairley
Copy link
Author

Used journalctl -b 81963876b4d24df3ac860d6caac1e12c -t "coreos-cloudinit" -t "locksmithd" -t "systemd", with -t rather than -u due to race systemd/systemd#3277.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment