/bugs

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ignition times out waiting on EBS volumes with AWS "Nitro"-based EC2 instance types (NVMe) #2531

Closed
seh opened this Issue Dec 4, 2018 · 9 comments

Comments

Assignees
No one assigned
Labels
Projects
None yet
Milestone
No milestone
3 participants
@seh @bgilbert @ajeddeloh
@seh

seh commented Dec 4, 2018 •
edited

Issue Report

Bug

Container Linux Version

AWS EC2 AMI built atop the latest Container Linux AMI selected by the following filter:

{
  "virtualization-type": "hvm",
  "name": "CoreOS-alpha-*-hvm",
  "root-device-type": "ebs",
}

This yields the following /etc/os-release file content:

NAME="Container Linux by CoreOS"
ID=coreos
VERSION=1967.0.0
VERSION_ID=1967.0.0
BUILD_ID=2018-11-19-2041
PRETTY_NAME="Container Linux by CoreOS 1967.0.0 (Rhyolite)"
ANSI_COLOR="38;5;75"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://issues.coreos.com"
COREOS_BOARD="amd64-usr"

Environment

AWS EC2 in the "us-east-1" availability zone.

Expected Behavior

Container Linux should boot on a "Nitro"-based EC2 instance type such as the "m5" and "m5a" families, with Ignition creating a filesystem on an attached EBS volume, per a configuration stanza like this:

{
  "ignition": {
    "config": {},
    "timeouts": {},
    "version": "2.1.0"
  },
  "storage": {
    "filesystems": [
      {
        "mount": {
          "device": "/dev/sdf",
          "format": "ext4",
          "label": "etcd"
        },
        "name": "etcd-data"
      }
    ]
  }
}

Actual Behavior

When the EC2 instance mounts the EBS volume via NVMe, Ignition times out waiting for the systemd device unit "dev-sdf.device" to start. The call to conn.StartUnit in internal/systemd.WaitOnDevices fails with result string of "timeout."

Note, however, that if I replace "/dev/sdf" with, say, "/dev/nvme1n1" in the above Ignition configuration's "storage.filesystems.mount.device" field, the EC2 instance boots as expected and Ignition creates the filesystem on the attached EBS volume.

After the instance has booted and that filesystem is created, we can see that the symbolic link from the /dev/sdf device path I specified to AWS to /dev/nvme1n1 does in fact get created (as I had reported in #2481):

% ls -l /dev/sdf
lrwxrwxrwx. 1 root root 7 Dec  3 18:46 /dev/sdf -> nvme1n1

The NVMe-related udev rules are in place:

% grep -C3 'Elastic Block' /usr/lib/udev/rules.d/90-cloud-storage.rules 
## AWS EBS NVMe names
## https://github.com/coreos/bugs/issues/2399
# NVMe devices
KERNEL=="nvme[0-9]*n[0-9]*", ENV{DEVTYPE}=="disk", ATTRS{model}=="Amazon Elastic Block Store", ATTRS{serial}=="?*", SYMLINK+="disk/by-id/nvme-$attr{model}_$attr{serial}-ns-%n", OPTIONS+="string_escape=replace"
KERNEL=="nvme[0-9]*n[0-9]*", ENV{DEVTYPE}=="disk", ATTRS{model}=="Amazon Elastic Block Store", ATTRS{serial}=="?*", PROGRAM="cloud_aws_ebs_nvme_id -d /dev/%k", SYMLINK+="%c"
# NVMe partitions
KERNEL=="nvme[0-9]*n[0-9]*p[0-9]*", ENV{DEVTYPE}=="partition", ATTRS{model}=="Amazon Elastic Block Store", ATTRS{serial}=="?*", IMPORT{program}="cloud_aws_ebs_nvme_id -n /dev/%k"
KERNEL=="nvme[0-9]*n[0-9]*p[0-9]*", ENV{DEVTYPE}=="partition", ATTRS{model}=="Amazon Elastic Block Store", ATTRS{serial}=="?*", ENV{_NS_ID}=="?*", SYMLINK+="disk/by-id/nvme-$attr{model}_$attr{serial}-ns-$env{_NS_ID}-part%n", OPTIONS+="string_escape=replace"
KERNEL=="nvme[0-9]*n[0-9]*p[0-9]*", ENV{DEVTYPE}=="partition", ATTRS{model}=="Amazon Elastic Block Store", ATTRS{serial}=="?*", ENV{_NS_ID}=="?*", PROGRAM="cloud_aws_ebs_nvme_id -d /dev/%k", SYMLINK+="%c%n"

# TODO: Anyone else support friendly names?

However, #2481 noted that these rules may not be present in initramfs, though coreos/bootengine#149 and coreos/coreos-overlay#3456 were supposed to solve that problem. I don't know how to determine whether these rules are in fact present in initramfs. It does seem that when Ignition has systemd go looking for these symbolic link device paths, though, that they're not there yet.

I also tried updating my grub.cfg file to increase the values for nvme_core.io_timeout nvme_core.max_retries, but that didn't change the behavior. When I specify a device path of /dev/nvme1n1 for Ignition's "storage.filesystems.mount.device" field, it completes successfully and quickly, so I don't think we're timing out waiting for the EBS volume to attach. Rather, I think we're timing out because we're looking for a symbolic link that hasn't been created yet when Ignition runs.

Reproduction Steps

Failing Case

  1. Create an EBS volume.
  2. Create an AWS EC2 instance of type "m5.large," or any other "Nitro"-based type.
    In the "user data" for the instance, include an Ignition configuration with a "filesystem.mount" stanza, specifying a device path like "/dev/sdf."
  3. Quickly afterward attach the EBS volume to the instance.
    Again, specify a device path matching the Ignition configuration like "/dev/sdf."
  4. Attempt to connect to the instance via SSH after attaching the volume.
    If the instance isn't responsive after the first minute or so, it isn't ever going to be.
  5. Wait about seven minutes, then inspect the system log in one of two ways:
  • In the AWS Web console, repeatedly try the context menu in the "Instances" view, selecting the instance and using the "Instance Settings → Get System Log" option, until the content finally appears.
  • Use the aws command-line tool to retrieve the log.
    Run the following command repeatedly until it prints an integer value in the hundreds rather than seven, the inspect the destination file /tmp/ec2-console.txt.
i=<YOUR INSTANCE ID>; aws ec2 get-console-output --instance-id "${i}" > /tmp/ec2-console.txt && wc -l /tmp/ec2-console.txt

Successful Case

  1. Create an EBS volume.
  2. Create an AWS EC2 instance of type "m5.large," or any other "Nitro"-based type.
    In the "user data" for the instance, include an Ignition configuration with a "filesystem.mount" stanza, specifying a device path like "/dev/sdf."
  3. Quickly afterward attach the EBS volume to the instance.
    Again, specify a device path matching the Ignition configuration of "/dev/nvme1n1." (Here we're assuming that the number of devices attached via NVMe is small, and that the EBS volume will be the second such device, landing at index 1.)
  4. Connect to the instance via SSH after attaching the volume.
  5. Confirm that the EBS volume is attached.
  6. Confirm that a symbolic link exists from /dev/sdf to /dev/nvme1n1.
  7. Confirm that the filesystem got created on /dev/nvme1n1.

Other Information

I've seen this same failure occur on EC2 instances in the "m5a" family, but I expect that the behavior will be the same on all those types using NVMe.

Again, by my reading of #2481, we thought we had this fixed—at least for Azure—but I'm not finding it to work for me in AWS.

Here's the EC2 instance console log from a failing case, asking Ignition to create a filesystem on the device path "/dev/sdf."

i-0f68a76c8f1e44c52	                                                �[m�[11;78H�[m�[m�[12;3H                                                                            �[m�[12;78H�[m�[m�[13;3H                                                                            �[m�[13;78H�[m�[m�[14;3H          
                                                                  �[m�[14;78H�[m�[m�[15;3H                                                                            �[m�[15;78H�[m�[m�[16;3H                                                                            �[m�[16;78H�[m�[16;80H �[5;78H�[22;1H   The highlighted entry will be executed automatically in 1s.                 �[5;78H�[22;1H   The highlighted entry will be executed automatically in 0s.                 �[5;78H�[?25h�[H�[J�[1;1H�[H�[J�[1;1H  Booting `CoreOS default'

[    0.000000] Linux version 4.19.2-coreos (jenkins@ip-10-7-32-103) (gcc version 7.3.0 (Gentoo Hardened 7.3.0-r3 p1.4)) #1 SMP Mon Nov 19 20:04:21 -00 2018
[    0.000000] Command line: BOOT_IMAGE=/coreos/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200n8 coreos.first_boot=detected coreos.oem.id=ec2 modprobe.blacklist=xen_fbfront net.ifnames=0 verity.usrhash=736254de31d7f6d28dbd80e6086b5d211ec5a9685e5d0369e3b5b68e3988c7fa
[    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x008: 'MPX bounds registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x010: 'MPX CSR'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: xstate_offset[3]:  832, xstate_sizes[3]:   64
[    0.000000] x86/fpu: xstate_offset[4]:  896, xstate_sizes[4]:   64
[    0.000000] x86/fpu: xstate_offset[5]:  960, xstate_sizes[5]:   64
[    0.000000] x86/fpu: xstate_offset[6]: 1024, xstate_sizes[6]:  512
[    0.000000] x86/fpu: xstate_offset[7]: 1536, xstate_sizes[7]: 1024
[    0.000000] x86/fpu: xstate_offset[9]: 2560, xstate_sizes[9]:    8
[    0.000000] x86/fpu: Enabled xstate features 0x2ff, context size is 2568 bytes, using 'compacted' format.
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bfff9fff] usable
[    0.000000] BIOS-e820: [mem 0x00000000bfffa000-0x00000000bfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000e0000000-0x00000000e03fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x00000004229fffff] usable
[    0.000000] BIOS-e820: [mem 0x0000000422a00000-0x000000043fffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.7 present.
[    0.000000] DMI: Amazon EC2 m5.xlarge/, BIOS 1.0 10/16/2017
[    0.000000] Hypervisor detected: KVM
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 254c7d001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 8558166579 cycles
[    0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000004] tsc: Detected 2500.000 MHz processor
[    0.001050] last_pfn = 0x422a00 max_arch_pfn = 0x400000000
[    0.001086] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.001092] last_pfn = 0xbfffa max_arch_pfn = 0x400000000
[    0.001198] Using GB pages for direct mapping
[    0.001360] ACPI: Early table checksum verification disabled
[    0.001409] ACPI: RSDP 0x00000000000F8F90 000014 (v00 AMAZON)
[    0.001412] ACPI: RSDT 0x00000000BFFFE270 00003C (v01 AMAZON AMZNRSDT 00000001 AMZN 00000001)
[    0.001416] ACPI: FACP 0x00000000BFFFFF80 000074 (v01 AMAZON AMZNFACP 00000001 AMZN 00000001)
[    0.001420] ACPI: DSDT 0x00000000BFFFE2B0 0010E9 (v01 AMAZON AMZNDSDT 00000001 AMZN 00000001)
[    0.001422] ACPI: FACS 0x00000000BFFFFF40 000040
[    0.001425] ACPI: SSDT 0x00000000BFFFF600 00093C (v01 AMAZON AMZNSSDT 00000001 AMZN 00000001)
[    0.001427] ACPI: APIC 0x00000000BFFFF500 000086 (v01 AMAZON AMZNAPIC 00000001 AMZN 00000001)
[    0.001430] ACPI: SRAT 0x00000000BFFFF440 0000C0 (v01 AMAZON AMZNSRAT 00000001 AMZN 00000001)
[    0.001432] ACPI: SLIT 0x00000000BFFFF3D0 00006C (v01 AMAZON AMZNSLIT 00000001 AMZN 00000001)
[    0.001434] ACPI: WAET 0x00000000BFFFF3A0 000028 (v01 AMAZON AMZNWAET 00000001 AMZN 00000001)
[    0.001517] SRAT: PXM 0 -> APIC 0x00 -> Node 0
[    0.001518] SRAT: PXM 0 -> APIC 0x01 -> Node 0
[    0.001520] SRAT: PXM 0 -> APIC 0x02 -> Node 0
[    0.001521] SRAT: PXM 0 -> APIC 0x03 -> Node 0
[    0.001524] ACPI: SRAT: Node 0 PXM 0 [mem 0x00000000-0xbfffffff]
[    0.001526] ACPI: SRAT: Node 0 PXM 0 [mem 0x100000000-0x43fffffff]
[    0.001535] NUMA: Node 0 [mem 0x00000000-0xbfffffff] + [mem 0x100000000-0x4229fffff] -> [mem 0x00000000-0x4229fffff]
[    0.001538] NODE_DATA(0) allocated [mem 0x4229f9000-0x4229fefff]
[    0.001568] Zone ranges:
[    0.001569]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.001571]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.001572]   Normal   [mem 0x0000000100000000-0x00000004229fffff]
[    0.001573] Movable zone start for each node
[    0.001574] Early memory node ranges
[    0.001574]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.001575]   node   0: [mem 0x0000000000100000-0x00000000bfff9fff]
[    0.001576]   node   0: [mem 0x0000000100000000-0x00000004229fffff]
[    0.001866] Reserved but unavailable: 22120 pages
[    0.001867] Initmem setup node 0 [mem 0x0000000000001000-0x00000004229fffff]
[    0.071926] ACPI: PM-Timer IO Port: 0xb008
[    0.071937] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.071973] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.071975] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.071976] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.071978] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.071979] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.071983] Using ACPI (MADT) for SMP configuration information
[    0.071985] smpboot: Allowing 4 CPUs, 0 hotplug CPUs
[    0.072008] [mem 0xc0000000-0xdfffffff] available for PCI devices
[    0.072010] Booting paravirtualized kernel on KVM
[    0.072013] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.139147] random: get_random_bytes called from start_kernel+0x94/0x524 with crng_init=0
[    0.139156] setup_percpu: NR_CPUS:512 nr_cpumask_bits:512 nr_cpu_ids:4 nr_node_ids:1
[    0.139492] percpu: Embedded 44 pages/cpu @(____ptrval____) s142104 r8192 d29928 u524288
[    0.139516] KVM setup async PF for cpu 0
[    0.139520] kvm-stealtime: cpu 0, msr 412a161c0
[    0.139525] Built 1 zonelists, mobility grouping on.  Total pages: 4010203
[    0.139526] Policy zone: Normal
[    0.139528] Kernel command line: rootflags=rw mount.usrflags=ro BOOT_IMAGE=/coreos/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200n8 coreos.first_boot=detected coreos.oem.id=ec2 modprobe.blacklist=xen_fbfront net.ifnames=0 verity.usrhash=736254de31d7f6d28dbd80e6086b5d211ec5a9685e5d0369e3b5b68e3988c7fa
[    0.181907] Memory: 15909116K/16295520K available (10252K kernel code, 1213K rwdata, 4584K rodata, 39380K init, 1664K bss, 386404K reserved, 0K cma-reserved)
[    0.181994] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.181996] Kernel/User page tables isolation: enabled
[    0.205272] ftrace: allocating 29061 entries in 114 pages
[    0.215167] rcu: Hierarchical RCU implementation.
[    0.215169] rcu: 	RCU event tracing is enabled.
[    0.215170] rcu: 	RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4.
[    0.215171] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    0.216989] NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16
[    0.257089] Console: colour VGA+ 80x25
[    0.356880] console [ttyS0] enabled
[    0.357405] ACPI: Core revision 20180810
[    0.358028] APIC: Switch to symmetric I/O mode setup
[    0.358979] x2apic enabled
[    0.359820] Switched APIC routing to physical x2apic.
[    0.361756] ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
[    0.362656] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x240939f1bb2, max_idle_ns: 440795263295 ns
[    0.364156] Calibrating delay loop (skipped) preset value.. 5000.00 BogoMIPS (lpj=2500000)
[    0.365148] pid_max: default: 32768 minimum: 301
[    0.366170] Security Framework initialized
[    0.366769] SELinux:  Initializing.
[    0.369505] Dentry cache hash table entries: 2097152 (order: 12, 16777216 bytes)
[    0.371676] Inode-cache hash table entries: 1048576 (order: 11, 8388608 bytes)
[    0.372193] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.373182] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.374392] mce: CPU supports 32 MCE banks
[    0.375875] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.376147] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.377148] Spectre V2 : Mitigation: Full generic retpoline
[    0.378147] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.379147] Speculative Store Bypass: Vulnerable
[    0.385066] Freeing SMP alternatives memory: 24K
[    0.387308] smpboot: CPU0: Intel(R) Xeon(R) Platinum 8175M CPU @ 2.50GHz (family: 0x6, model: 0x55, stepping: 0x4)
[    0.388232] Performance Events: unsupported p6 CPU model 85 no PMU driver, software events only.
[    0.389196] rcu: Hierarchical SRCU implementation.
[    0.390492] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.391206] smp: Bringing up secondary CPUs ...
[    0.391995] x86: Booting SMP configuration:
[    0.392150] .... node  #0, CPUs:      #1
[    0.143021] kvm-clock: cpu 1, msr 254c7d041, secondary cpu clock
[    0.393062] KVM setup async PF for cpu 1
[    0.393146] kvm-stealtime: cpu 1, msr 412a961c0
[    0.395219]  #2
[    0.143021] kvm-clock: cpu 2, msr 254c7d081, secondary cpu clock
[    0.395865] KVM setup async PF for cpu 2
[    0.396146] kvm-stealtime: cpu 2, msr 412b161c0
[    0.398234]  #3
[    0.143021] kvm-clock: cpu 3, msr 254c7d0c1, secondary cpu clock
[    0.398791] KVM setup async PF for cpu 3
[    0.399146] kvm-stealtime: cpu 3, msr 412b961c0
[    0.400154] smp: Brought up 1 node, 4 CPUs
[    0.401149] smpboot: Max logical packages: 1
[    0.401768] smpboot: Total of 4 processors activated (20000.00 BogoMIPS)
[    0.402673] devtmpfs: initialized
[    0.403190] x86/mm: Memory block size: 128MB
[    0.404688] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.406158] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.407134] pinctrl core: initialized pinctrl subsystem
[    0.407252] NET: Registered protocol family 16
[    0.407991] audit: initializing netlink subsys (disabled)
[    0.409162] audit: type=2000 audit(1543940206.003:1): state=initialized audit_enabled=0 res=1
[    0.410153] cpuidle: using governor menu
[    0.410901] ACPI: bus type PCI registered
[    0.412150] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.413121] dca service started, version 1.12.1
[    0.413208] PCI: Using configuration type 1 for base access
[    0.415183] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.416150] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.417196] ACPI: Added _OSI(Module Device)
[    0.417805] ACPI: Added _OSI(Processor Device)
[    0.418153] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.418881] ACPI: Added _OSI(Processor Aggregator Device)
[    0.420150] ACPI: Added _OSI(Linux-Dell-Video)
[    0.420796] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.421872] ACPI: 2 ACPI AML tables successfully acquired and loaded
[    0.424025] ACPI: Interpreter enabled
[    0.424156] ACPI: (supports S0 S5)
[    0.424662] ACPI: Using IOAPIC for interrupt routing
[    0.425157] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.426386] ACPI: Enabled 16 GPEs in block 00 to 0F
[    0.428894] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.430152] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[    0.431151] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    0.432109] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    0.434429] acpiphp: Slot [3] registered
[    0.435052] acpiphp: Slot [4] registered
[    0.435174] acpiphp: Slot [5] registered
[    0.435772] acpiphp: Slot [6] registered
[    0.436174] acpiphp: Slot [7] registered
[    0.436770] acpiphp: Slot [8] registered
[    0.438174] acpiphp: Slot [9] registered
[    0.438768] acpiphp: Slot [10] registered
[    0.439174] acpiphp: Slot [11] registered
[    0.439779] acpiphp: Slot [12] registered
[    0.440174] acpiphp: Slot [13] registered
[    0.440795] acpiphp: Slot [14] registered
[    0.441175] acpiphp: Slot [15] registered
[    0.441783] acpiphp: Slot [16] registered
[    0.442175] acpiphp: Slot [17] registered
[    0.442783] acpiphp: Slot [18] registered
[    0.444174] acpiphp: Slot [19] registered
[    0.444792] acpiphp: Slot [20] registered
[    0.445174] acpiphp: Slot [21] registered
[    0.445785] acpiphp: Slot [22] registered
[    0.446174] acpiphp: Slot [23] registered
[    0.446782] acpiphp: Slot [24] registered
[    0.447174] acpiphp: Slot [25] registered
[    0.447780] acpiphp: Slot [26] registered
[    0.448176] acpiphp: Slot [27] registered
[    0.448781] acpiphp: Slot [28] registered
[    0.450174] acpiphp: Slot [29] registered
[    0.450810] acpiphp: Slot [30] registered
[    0.451174] acpiphp: Slot [31] registered
[    0.451766] PCI host bridge to bus 0000:00
[    0.452149] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.453113] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.454149] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.455149] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window]
[    0.456149] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.458969] pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
[    0.460163] pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
[    0.461199] pci 0000:00:01.3: PIIX4 devres E PIO at fff0-ffff
[    0.462023] pci 0000:00:01.3: PIIX4 devres F MMIO at ffc00000-ffffffff
[    0.463162] pci 0000:00:01.3: PIIX4 devres G PIO at fff0-ffff
[    0.463987] pci 0000:00:01.3: PIIX4 devres H MMIO at ffc00000-ffffffff
[    0.465163] pci 0000:00:01.3: PIIX4 devres I PIO at fff0-ffff
[    0.466012] pci 0000:00:01.3: PIIX4 devres J PIO at fff0-ffff
[    0.475729] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    0.476230] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    0.477134] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    0.478226] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    0.479071] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    0.480173] pci 0000:00:03.0: vgaarb: setting as boot VGA device
[    0.481049] pci 0000:00:03.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[    0.482151] pci 0000:00:03.0: vgaarb: bridge control possible
[    0.482977] vgaarb: loaded
[    0.483158] pps_core: LinuxPPS API ver. 1 registered
[    0.483884] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.485151] PTP clock support registered
[    0.485770] PCI: Using ACPI for IRQ routing
[    0.487231] clocksource: Switched to clocksource kvm-clock
[    0.496257] VFS: Disk quotas dquot_6.6.0
[    0.496916] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.497973] pnp: PnP ACPI init
[    0.498760] pnp: PnP ACPI: found 5 devices
[    0.505499] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.506852] NET: Registered protocol family 2
[    0.507600] tcp_listen_portaddr_hash hash table entries: 8192 (order: 5, 131072 bytes)
[    0.508761] TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.509961] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[    0.511042] TCP: Hash tables configured (established 131072 bind 65536)
[    0.512039] UDP hash table entries: 8192 (order: 6, 262144 bytes)
[    0.512973] UDP-Lite hash table entries: 8192 (order: 6, 262144 bytes)
[    0.513978] NET: Registered protocol family 1
[    0.514634] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.515488] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.516458] pci 0000:00:03.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    0.983844] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.984910] software IO TLB: mapped [mem 0xbbffa000-0xbfffa000] (64MB)
[    0.986328] RAPL PMU: API unit is 2^-32 Joules, 3 fixed counters, 10737418240 ms ovfl timer
[    0.987544] RAPL PMU: hw unit of domain pp0-core 2^-0 Joules
[    0.988402] RAPL PMU: hw unit of domain package 2^-0 Joules
[    0.989225] RAPL PMU: hw unit of domain dram 2^-16 Joules
[    0.990049] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x240939f1bb2, max_idle_ns: 440795263295 ns
[    0.991923] Initialise system trusted keyrings
[    0.992667] workingset: timestamp_bits=39 max_order=22 bucket_order=0
[    0.994816] pstore: using deflate compression
[    1.206865] Key type asymmetric registered
[    1.207507] Asymmetric key parser 'x509' registered
[    1.208224] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.209303] io scheduler noop registered
[    1.209880] io scheduler deadline registered
[    1.210531] io scheduler cfq registered (default)
[    1.211216] io scheduler mq-deadline registered
[    1.211869] io scheduler kyber registered
[    1.212475] io scheduler bfq registered
[    1.213365] ioatdma: Intel(R) QuickData Technology Driver 4.00
[    1.214273] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.237617] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    1.239277] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    1.240658] i8042: Warning: Keylock active
[    2.370392] serio: i8042 KBD port at 0x60,0x64 irq 1
[    2.371330] rtc_cmos 00:00: RTC can wake from S4
[    2.372677] rtc_cmos 00:00: registered as rtc0
[    2.373344] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
[    2.374433] NET: Registered protocol family 10
[    2.375279] Segment Routing with IPv6
[    2.375828] NET: Registered protocol family 17
[    2.376491] Key type dns_resolver registered
[    2.377406] sched_clock: Marking stable (2235293936, 142021154)->(2381235678, -3920588)
[    2.378768] registered taskstats version 1
[    2.379368] Loading compiled-in X.509 certificates
[    2.408325] Loaded X.509 cert 'CoreOS, Inc: Module signing key for 4.19.2-coreos: 512c5e2348b40b061941a47d5adc701142784fed'
[    2.409910] ima: No TPM chip found, activating TPM-bypass!
[    2.410704] ima: Allocated hash algorithm: sha1
[    2.411718] rtc_cmos 00:00: setting system clock to 2018-12-04 16:16:47 UTC (1543940207)
[    2.521969] Freeing unused kernel image memory: 39380K
[    2.528155] Write protecting the kernel read-only data: 18432k
[    2.530363] Freeing unused kernel image memory: 2016K
[    2.531459] Freeing unused kernel image memory: 1560K
[    2.532235] Run /init as init process
[    2.537736] 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)
[    2.540693] systemd[1]: Detected virtualization kvm.
[    2.541411] systemd[1]: Detected architecture x86-64.
[    2.542135] systemd[1]: Running in initial RAM disk.

Welcome to �[0;34mdracut-045 (Initramfs)�[0m!

[    2.546680] systemd[1]: No hostname configured.
[    2.547354] systemd[1]: Set hostname to <localhost>.
[    2.548096] systemd[1]: Initializing machine ID from KVM UUID.
[    2.585744] 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.
[    2.588191] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[    2.594624] random: systemd: uninitialized urandom read (16 bytes read)
[    2.595593] systemd[1]: Reached target Timers.
[�[0;32m  OK  �[0m] Reached target Timers.
[    2.597369] random: systemd: uninitialized urandom read (16 bytes read)
[�[0;32m  OK  �[0m] Listening on Journal Audit Socket.
[    2.599466] random: systemd: uninitialized urandom read (16 bytes read)
[�[0;32m  OK  �[0m] Listening on udev Kernel Socket.
[�[0;32m  OK  �[0m] Listening on udev Control Socket.
[�[0;32m  OK  �[0m] Started Dispatch Password Requests to Console Directory Watch.
[�[0;32m  OK  �[0m] Listening on Journal Socket (/dev/log).
[�[0;32m  OK  �[0m] Reached target Swap.
[�[0;32m  OK  �[0m] Reached target Local Encrypted Volumes.
[�[0;32m  OK  �[0m] Reached target Slices.
[�[0;32m  OK  �[0m] Created slice system-systemd\x2dfsck.slice.
[�[0;32m  OK  �[0m] Listening on Journal Socket.
         Starting Journal Service...
         Starting Create list of required st…ce nodes for the current kernel...
[�[0;32m  OK  �[0m] Reached target Sockets.
         Starting dracut cmdline hook...
         Starting Apply Kernel Variables...
[�[0;32m  OK  �[0m] Reached target Paths.
[�[0;32m  OK  �[0m] Started Create list of required sta…vice nodes for the current kernel.
[�[0;32m  OK  �[0m] Started Apply Kernel Variables.
         Starting Create Static Device Nodes in /dev...
[�[0;32m  OK  �[0m] Started Create Static Device Nodes in /dev.
[    2.634675] audit: type=1130 audit(1543940207.722:2): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-tmpfiles-setup-dev comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[�[0;32m  OK  �[0m] [    2.506804] Started Journal Service.systemd-sysctl
[167]: Couldn't write 'fq_codel' to 'net/core/default_qdisc', ignoring: No such file or directory
[    2.652023] audit: type=1130 audit(1543940207.738:3): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-journald comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    2.510694] dracut-cmdline[166]: dracut-dracut-045
[    2.514204] dracut-cmdline[166]: Using kernel command line parameters: rootflags=rw mount.usrflags=ro BOOT_IMAGE=/coreos/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200n8 coreos.first_boot=detected coreos.oem.id=ec2 modprobe.blacklist=xen_fbfront net.ifnames=0 verity.usrhash=736254de31d7f6d28dbd80e6086b5d211ec5a9685e5d0369e3b5b68e3988c7fa
[�[0;32m  OK  �[0m[    2.536876] ] systemdStarted dracut cmdline hook.
[1]: Started dracut cmdline hook.
         [    2.539780] Starting dracut pre-udev hook...systemd
[1]: Starting dracut pre-udev hook...
[    2.683897] audit: type=1130 audit(1543940207.768:4): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-cmdline comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    2.697308] device-mapper: uevent: version 1.0.3
[    2.698040] device-mapper: ioctl: 4.39.0-ioctl (2018-04-03) initialised: dm-devel@redhat.com
[�[0;32m  OK  �[0m[    2.571778] ] systemd[1]: Started dracut pre-udev hook.
Started dracut pre-udev hook.
[    2.716989] audit: type=1130 audit(1543940207.804:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-udev comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         [    2.575744] Starting udev Kernel Device Manager...systemd[1]: Starting udev Kernel Device Manager...

[    2.584012] systemd-udevd[252]: Network interface NamePolicy= disabled on kernel command line, ignoring.
[    2.586145] systemd-udevd[252]: Specified group 'render' unknown
[�[0;32m  OK  �[0m[    2.587704] systemd[1]: Started udev Kernel Device Manager.
] Started udev Kernel Device Manager.
[    2.732860] audit: type=1130 audit(1543940207.820:6): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udevd comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         [    2.592112] Starting dracut pre-trigger hook...systemd
[1]: Starting dracut pre-trigger hook...
[    2.596096] systemd[1]: Starting Network Service...
         Starting Network Service...
[�[0;32m  OK  �[0m] [    2.607514] Started Network Service.systemd-networkd
[261]: Enumeration completed
[    2.751841] audit: type=1130 audit(1543940207.838:7): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-networkd comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         [    2.609930] Starting Network Name Resolution...systemd
[1]: Started Network Service.
[    2.616097] dracut-pre-trigger[260]: rd.md=0: removing MD RAID activation
[    2.617658] systemd[1]: Starting Network[    2.760341] random: fast init done
 Name Resolution...
[�[0;32m  OK  �[0m] Started dracut pre-trigger hook.
[    2.639434] systemd[    2.783697] audit: type=1130 audit(1543940207.871:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-trigger comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         Starting udev Coldplug all Devices...
[1]: Started dracut pre-trigger hook.
[    2.647090] systemd[1]: Starting udev Coldplug all Devices...
[    2.651754] systemd-udevd[252]: Network interface NamePolicy= disabled on kernel command line, ignoring.
[    2.654189] systemd-resolved[[271]: �[0;32m  OK  �[0mPositive Trust Anchors:] 
Started Network Name Resolution.[    2.656053] 
systemd-resolved[271]: . IN DS 19036 8 2 49aac11d7b6f6446702e54a1607371[    2.800095] audit: type=1130 audit(1543940207.886:9): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-resolved comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
607a1a41855200fd2ce1cdde32f24e8fb5[�[0;32m  OK  �[0m
] Reached target Network.
[�[0;32m  OK  �[0m[    2.662736] ] systemd-resolved[271]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
Reached target Host and Network Name Lookups.
[    2.664878] systemd-resolved[271]: Negative trust anchors: 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa corp home internal intranet lan local private test
[    2.674607] systemd-resolved[271]: Defaulting to hostname 'linux'.
[    2.684419] systemd[1]: Started Network Name Resolution.
[    2.685893] systemd[1]: Reached target Network.
[�[0;32m  OK  �[0m[    2.687253] systemd[1]: Reached target Host and Network Name Lookups.
] [    2.688975] systemd-udevd[252]: Specified group 'render' unknown
Started udev Coldplug all Devices.[    2.690804] systemd[1]: Started udev Coldplug all Devices.

[    2.835106] audit: type=1130 audit(1543940207.922:10): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         [    2.694483] Starting dracut initqueue hook...systemd
[1]: Starting dracut initqueue hook...
[    2.853406] ena: Elastic Network Adapter (ENA) v1.5.0K
[    2.854454] ena 0000:00:05.0: Elastic Network Adapter (ENA) v1.5.0K
[    2.858471] cryptd: max_cpu_qlen set to 1000
[    2.859277] nvme nvme0: pci function 0000:00:04.0
[    2.860221] nvme nvme1: pci function 0000:00:1f.0
[    2.862174] ena: ena device version: 0.10
[    2.862500] PCI Interrupt Link [LNKD] enabled at IRQ 11
[    2.862901] ena: ena controller version: 0.0.1 implementation version 1
[    2.867397] PCI Interrupt Link [LNKC] enabled at IRQ 10
[    2.869385] AVX2 version of gcm_enc/dec engaged.
[    2.870170] AES CTR mode by8 optimization enabled
[    2.878700] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    2.739019] systemd-udevd[328]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
[    2.741655] systemd-networkd[261]: lo: Configured
[    2.913169] ena 0000:00:05.0: creating 4 io queues. queue size: 1024
[    2.914801] ena 0000:00:05.0: Elastic Network Adapter (ENA) found at mem febf4000, mac addr 12:9b:b0:6c:93:2a Queues 4
[    2.923203] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    2.923329] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    2.774334] systemd-udevd[311]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
[    2.869611] systemd-networkd[261]: eth0: IPv6 successfully enabled
[    2.871548] systemd-networkd[261]: eth0: Gained carrier
[    2.873230] systemd-networkd[261]: eth0: DHCPv4 address 10.105.48.37/23 via 10.105.48.1
[    2.875071] systemd-networkd[261]: Not connected to system bus, not setting hostname.
[    3.074436]  nvme0n1: p1 p2 p3 p4 p6 p7 p9
[[    2.971149] systemd[1]: Found device Amazon Elastic Block Store OEM.
�[0;32m  OK  �[0m] Found device Amazon Elastic Block Store OEM.
[[    2.976817] systemd[1]: Found device Amazon Elastic Block Store EFI-SYSTEM.
�[0;32m  OK  �[0m] Found device Amazon Elastic Block Store EFI-SYSTEM.
[[    2.982008] systemd[1]: Found device Amazon Elastic Block Store USR-A.
�[0;32m  OK  �[0m] Found device Amazon Elastic Block Store USR-A.
[[    2.985571] systemd[1]: Started dracut initqueue hook.
�[0;32m  OK  �[0m] Started dracut initqueue hook.
[[    2.990091] systemd[1]: Found device Amazon Elastic Block Store ROOT.
�[0;32m  OK  �[0m] Found device Amazon Elastic Block Store ROOT.
[[    2.996466] systemd[1]: Reached target Initrd Root Device.
�[0;32m  OK  �[0m] Reached target Initrd Root Device.
         Starting dracut pre-mount hook...
[    2.999834] systemd[1]: Starting dracut pre-mount hook...
[�[0;32m  OK  �[0m] Reached target Remote File Systems (Pre).
[�[0;32m  OK  �[0m] Reached target Remote File Systems.
[    3.004638] systemd[1]: Reached target Remote File Systems (Pre).
[    3.008209] systemd[1]: Reached target Remote File Systems.
         [    3.010764] systemd[1]: Starting Ignition (setup)...
Starting Ignition (setup)...
[[    3.013527] systemd[1]: Started dracut pre-mount hook.
�[0;32m  OK  �[0m] Started dracut pre-mount hook.
[    3.193262] EXT4-fs (nvme0n1p6): mounted filesystem with ordered data mode. Opts: (null)
[[    3.072278] systemd[1]: Started Ignition (setup).
�[0;32m  OK  �[0m] Started Ignition (setup).
         [    3.075619] systemd[1]: Starting Ignition (disks)...
Starting Ignition (disks)...
[    3.081700] ignition[413]: Ignition v0.28.0
[    3.083162] ignition[413]: reading system config file "/usr/lib/ignition/base.ign"
[    3.085256] ignition[413]: no config URL provided
[    3.086752] ignition[413]: reading system config file "/usr/lib/ignition/user.ign"
[    3.088574] ignition[413]: no config at "/usr/lib/ignition/user.ign"
[    3.090240] ignition[413]: GET http://169.254.169.254/2009-04-04/user-data: attempt #1
[    3.092032] ignition[413]: GET result: OK
[    3.098782] ignition[413]: disks: createFilesystems: op(1): [started]  waiting for devices [/dev/sdf]
[    4.792579] systemd-networkd[261]: eth0: Gained IPv6LL
[�[0m�[0;31m*     �[0m] (1 of 3) A start job is running for Ignition (disks) (5s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for Ignition (disks) (6s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is running for Ignition (disks) (7s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (6s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for dev-sdf.device (7s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (8s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…-mapper-usr.device (9s / no limit)�[K[     �[0;31m*�[0m] (3 of 3) A start job is running for…-mapper-usr.device (9s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (10s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of
 3) A start job is running for Ignition (disks) (11s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for Ignition (disks) (11s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for Ignition (disks) (12s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (12s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for dev-sdf.device (12s / 1min 30s)�[K[�[0m�[0;31m*     �[0m] (2 of 3) A start job is running for dev-sdf.device (13s / 1min 30s)[   16.802584] systemd-networkd[261]: eth0: Configured
�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…mapper-usr.device (14s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…mapper-usr.device (15s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…mapper-usr.device (15s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for Ignition (disks) (16s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (16s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (17s / no limit)�[K[     �[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (17s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (18s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (18s / 1min 30s)�[K[  �[0;31m*�[0;1;31
m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…mapper-usr.device (19s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…mapper-usr.device (20s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…mapper-usr.device (21s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for Ignition (disks) (21s / no limit)�[K[�[0m�[0;31m*     �[0m] (1 of 3) A start job is running for Ignition (disks) (22s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for Ignition (disks) (22s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (22s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (23s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for dev-sdf.device (23s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�
[0m�[0;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (25s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (25s / no limit)�[K[     �[0;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (26s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (26s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (27s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for Ignition (disks) (28s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (28s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (28s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for dev-sdf.device (29s / 1min 30s)�[K[�[0m�[0;31m*     �[0m] (3 of 3) A start job i
s running for…mapper-usr.device (30s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…mapper-usr.device (31s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…mapper-usr.device (31s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for Ignition (disks) (32s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for Ignition (disks) (32s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (33s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (33s / 1min 30s)�[K[     �[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (33s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (34s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (3 of 3) A start job is running for…mapper-
usr.device (35s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…mapper-usr.device (36s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…mapper-usr.device (36s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is running for Ignition (disks) (37s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for Ignition (disks) (38s / no limit)�[K[�[0m�[0;31m*     �[0m] (1 of 3) A start job is running for Ignition (disks) (38s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for dev-sdf.device (38s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (39s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (39s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…mapper-usr.
device (40s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (41s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (42s / no limit)�[K[     �[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (42s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (43s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (43s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for dev-sdf.device (43s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (44s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (45s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…mapper-usr.device (46s / no limit)
�[K[�[0m�[0;31m*     �[0m] (3 of 3) A start job is running for…mapper-usr.device (46s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…mapper-usr.device (47s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is running for Ignition (disks) (48s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for Ignition (disks) (48s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for Ignition (disks) (49s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (49s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (49s / 1min 30s)�[K[     �[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (50s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (51s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�
[0m] (3 of 3) A start job is running for…mapper-usr.device (51s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…mapper-usr.device (52s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for Ignition (disks) (52s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is running for Ignition (disks) (53s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m[   56.502757] random: crng init done
[   56.503341] random: 7 urandom warning(s) missed due to ratelimiting
] (1 of 3) A start job is running for Ignition (disks) (53s / no limit)�[K[�[0m�[0;31m*     �[0m] (2 of 3) A start job is running for dev-sdf.device (53s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for dev-sdf.device (54s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for dev-sdf.device (54s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…mapper-usr.device (55s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…mapper-usr.device (56s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (3 of 3) A start job is running for…mapper-usr.device (56s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (57s / no limit)�[K[     �[0;31m*�[0m] (1 of 3) A start job is running for Ignition (disks) (57s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for I
gnition (disks) (58s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for dev-sdf.device (58s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for dev-sdf.device (58s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for dev-sdf.device (59s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…apper-usr.device (1min / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…apper-usr.device (1min / no limit)�[K[�[0m�[0;31m*     �[0m] (3 of 3) A start job is running for…er-usr.device (1min 1s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for…ition (disks) (1min 1s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is running for…ition (disks) (1min 2s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for
…ition (disks) (1min 2s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 2s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 3s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 3s / 1min 30s)�[K[     �[0;31m*�[0m] (3 of 3) A start job is running for…er-usr.device (1min 4s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…er-usr.device (1min 5s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (3 of 3) A start job is running for…er-usr.device (1min 5s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for…ition (disks) (1min 6s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job is running for…ition (disks) (1min 6s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is run
ning for…ition (disks) (1min 7s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 7s / 1min 30s)�[K[�[0m�[0;31m*     �[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 7s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for…ev-sdf.device (1min 8s / 1min 30s)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…er-usr.device (1min 9s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…er-usr.device (1min 9s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…r-usr.device (1min 10s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for…tion (disks) (1min 10s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A start job is running for…tion (disks) (1min 11s / no limit)�[K[     �[0;31m*�[0m] (1 of 3) A start job is running for…
tion (disks) (1min 11s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 11s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 12s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 12s / 1min 30s)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…r-usr.device (1min 13s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…r-usr.device (1min 14s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…r-usr.device (1min 14s / no limit)�[K[�[0m�[0;31m*     �[0m] (1 of 3) A start job is running for…tion (disks) (1min 15s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for…tion (disks) (1min 15s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (1 of 3) A start job is runni
ng for…tion (disks) (1min 16s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 16s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 16s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 17s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…r-usr.device (1min 18s / no limit)�[K[     �[0;31m*�[0m] (3 of 3) A start job is running for…r-usr.device (1min 18s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (3 of 3) A start job is running for…r-usr.device (1min 19s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for…tion (disks) (1min 19s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for…tion (disks) (1min 20s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (1 of 3) A start job 
is running for…tion (disks) (1min 20s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 20s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 21s / 1min 30s)�[K[�[0m�[0;31m*     �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 21s / 1min 30s)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (3 of 3) A start job is running for…r-usr.device (1min 22s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…r-usr.device (1min 23s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…r-usr.device (1min 23s / no limit)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (1 of 3) A start job is running for…tion (disks) (1min 24s / no limit)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (1 of 3) A start job is running for…tion (disks) (1min 24s / no limit)�[K[    �[0;31m*�[0;1;31m*�[0m] (1 of 3) A s
tart job is running for…tion (disks) (1min 25s / no limit)�[K[     �[0;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 25s / 1min 30s)�[K[    �[0;31m*�[0;1;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 25s / 1min 30s)�[K[   �[0;31m*�[0;1;31m*�[0m�[0;31m*�[0m] (2 of 3) A start job is running for…v-sdf.device (1min 26s / 1min 30s)�[K[  �[0;31m*�[0;1;31m*�[0m�[0;31m* �[0m] (3 of 3) A start job is running for…r-usr.device (1min 27s / no limit)�[K[ �[0;31m*�[0;1;31m*�[0m�[0;31m*  �[0m] (3 of 3) A start job is running for…r-usr.device (1min 27s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (3 of 3) A start job is running for…r-usr.device (1min 28s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is running for…tion (disks) (1min 28s / no limit)�[K[�[0m�[0;31m*     �[0m] (1 of 3) A start job is running for…tion (disks) (1min 29s / no limit)�[K[�[0;1;31m*�[0m�[0;31m*    �[0m] (1 of 3) A start job is
 running for…tion (disks) (1min 29s / no limit)�[K[�[0;31m*�[0;1;31m*�[0m�[0;31m*   �[0m] (2 of 3) A start job is running for…v-sdf.device (1min 29s / 1min 30s)�[K[�[0;1;31m TIME �[0m[   93.110103] systemd[1]: dev-sdf.device: Job dev-sdf.device/start timed out.
] [   93.111898] systemd[1]: Timed out waiting for device dev-sdf.device.
Timed out waiting for device dev-sdf.device.
[   93.114875] systemd[1]: dev-sdf.device: Job dev-sdf.device/start failed with result 'timeout'.
[   93.116933] ignition[413]: disks: createFilesystems: op(1): [failed]   waiting for devices [/dev/sdf]: device unit dev-sdf.device timeout
[   93.119534] ignition[413]: Ignition failed: failed to create filesystems: failed to wait on filesystems devs: device unit dev-sdf.device timeout
[[   93.122409] �[0;1;31mFAILED�[0mignition] [413]: Failed to start Ignition (disks).disks failed

[   93.125182] See 'systemctl status ignition-disks.service' for details.
systemd[1]: [ignition-disks.service: Main process exited, code=exited, status=1/FAILURE
�[0;1;33mDEPEND�[0m] Dependency failed for Ignition (record completion).
[[   93.127872] systemd�[0;1;33mDEPEND�[0m] Dependency failed for Initrd Default Target.
[1]: ignition-disks.service: Failed with result 'exit-code'.
[[   93.144807] �[0;1;33mDEPEND�[0msystemd] [1]: Failed to start Ignition (disks).
Dependency failed for Ignition (files).[   93.146753] 
systemd[1]: Dependency failed for Ignition (record completion).
[[   93.149013] systemd�[0;1;33mDEPEND�[0m[1]: ] Dependency failed for Initrd Default Target.
Dependency failed for Populate torcx store to satisfy profile.[   93.151384] systemd[1]: initrd.target: Job initrd.target/start [   93.295652] kauditd_printk_skb: 4 callbacks suppressed
failed with resu[   93.295654] audit: type=1130 audit(1543940298.383:15): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=ignition-disks comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=failed'
lt 'dependency'.

[   93.152335] systemd[1]: initrd.target: Triggering OnFailure= dependencies.
         [   93.159412] systemd[1]: ignition-quench.service: Job ignition-quench.service/start failed with result 'dependency'.
Starting Verity Setup for /dev/mapper/usr...[   93.160752] systemd[1]: Dependency failed for Ignition (files).

[   93.163735] systemd[1]: Dependency failed for Populate torcx store to satisfy profile.
[[   93.165282] systemd[1]: torcx-profile-populate.service: Job torcx-profile-populate.service/start failed with result 'dependency'.
�[0;32m  OK  �[0m[   93.167055] systemd] [1]: Reached target Local File Systems (Pre).ignition-files.service: Job ignition-files.service/start failed with result 'dependency'.

         Stopping Network Service...
[[   93.185766] �[0;32m  OK  �[0msystemd] [1]: Reached target Local File Systems.Starting Verity Setup for /dev/mapper/usr...

[   93.188485] systemd[1]: Reached target Local File Systems (Pre).
[   93.190159] systemd[1]: Stopping Network Service...
[   93.191728] systemd[1]: Reached target Local File Systems.
         Starting Setup Virtual Console...
[   93.293643] systemd[1]: Starting Setup Virtual Console...
[[   93.295501] systemd[1]: Stopped dracut pre-mount hook.
�[0;32m  OK  �[0m] Stopped dracut pre-mount hook.
[   93.440548] audit: type=1131 audit(1543940298.528:16): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-mount comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
         Starting File System Check on /dev/disk/by-label/ROOT...
[�[0;32m  OK  �[0m] Stopped dracut initqueue hook.
[   93.299177] systemd[1]: Starting File System Check on /dev/disk/by-label/ROOT...
[�[0;32m  OK  �[0m] Stopped dracut pre-trigger hook.
[   93.305936] systemd[1]: Stopped dracut initqueue hook.
[   93.306453] systemd[1]: Stopped dracut pre-trigger hook.
[�[0;32m  OK  �[0m] Stopped dracut pre-udev hook.
[   93.307079] systemd[1]: Stopped dracut pre-udev hook.
[   93.307498] systemd[1]: Stopped dracut cmdline hook.
[�[0;32m  OK  �[0m[   93.454538] audit: type=1131 audit(1543940298.534:17): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-initqueue comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
] [   93.457349] audit: type=1131 audit(1543940298.535:18): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-trigger comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   93.460343] audit: type=1131 audit(1543940298.537:19): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-udev comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
Stopped dracut cmdline hook.[   93.318773] systemd-fsck[444]: ROOT: clean, 2713/1498496 files, 102800/1489915 blocks

[   93.466338] audit: type=1131 audit(1543940298.554:20): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-cmdline comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[[   93.325824] �[0;32m  OK  �[0msystemd] [1]: Started Setup Virtual Console.Started Setup Virtual Console.

[   93.472049] audit: type=1130 audit(1543940298.559:21): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   93.330831] [   93.475144] audit: type=1131 audit(1543940298.559:22): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[�[0;32m  OK  �[0msystemd] Started File System Check on /dev/disk/by-label/ROOT.
[1]: [   93.480211] audit: type=1130 audit(1543940298.567:23): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-fsck-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
Started File System Check on /dev/disk/by-label/ROOT.
[�[0;32m  OK  �[0m] Started Verity Setup for /dev/mapper/usr.
[   93.486041] audit: type=1130 audit(1543940298.573:24): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=verity-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   93.343882] [systemd[1]: Started Verity Setup for /dev/mapper/usr.
�[0;32m  OK  �[0m] Found device /dev/mapper/usr.
         Mounting /sysroot...
[   93.350189] systemd-networkd         Starting Emergency Shell...[261]: 
lo: Lost carrier
[   93.352405] systemd[1]: Found device /dev/mapper/usr.
[   93.354006] systemd[1]: Mounting /sysroot...
[   93.355329] systemd[1]: Starting Emergency Shell...
[   93.358201] systemd-networkd[261]: eth0: Lost carrier
[   93.506236] EXT4-fs (nvme0n1p9): mounted filesystem with ordered data mode. Opts: (null)
[�[0;32m  OK  �[0m] Stopped Network Service.
[   93.365604] systemd[1]: Stopped Network Service.
[�[0;32m  OK  �[0m] Mounted /sysroot.
[   93.368468] systemd[1]: Mounted /sysroot.
[�[0;32m  OK  �[0m] Reached target Initrd Root File System.
[   93.372557] systemd[1]: Reached target Initrd Root File System.
         Mounting /sysroot/usr...
[   93.376203] systemd[1]: Mounting /sysroot/usr...
[[   93.394786] �[0;32m  OK  �[0msystemd] [1]: Mounted /sysroot/usr.Mounted /sysroot/usr.

         [   93.397601] Starting Root filesystem setup...systemd
[1]: Starting Root filesystem setup...
[�[0;32m  OK  �[0m] Started Root filesystem setup.
[   93.457865] systemd[1]:          Starting Reload Configuration from the Real Root...
Started Root filesystem setup.
[   93.461200] systemd[1]: Starting Reload Configuration from the Real Root...
[   93.464190] systemd[1]: Reloading.
[�[0;32m  OK  �[0m] [   93.527691] Started Reload Configuration from the Real Root.
systemd[[1]: Started Reload Configuration from the Real Root.�[0;32m  OK  �[0m
] Reached target Initrd File Systems.
[   93.531527] systemd         Starting Cleaning Up and Shutting Down Daemons...
[1]: Reached target Initrd File Systems.
[   93.535401] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
[�[0;1;31mFAILED�[0m] Failed to start Cleaning Up and Shutting Down Daemons.
See 'systemctl status initrd-cleanup.service' for details.
         Starting Setup Virtual Console...
[   93.539774] systemctl[581]: Failed to start initrd-switch-root.target: Transaction is destructive.
[   93.543597] systemctl[581]: See system logs and 'systemctl status initrd-switch-root.target' for details.
[   93.546398] systemd[1]: Requested transaction contradicts existing jobs: Transaction is destructive.
[   93.549079] systemd[1]: initrd-cleanup.service: Main process exited, code=exited, status=4/NOPERMISSION
[   93.551784] systemd[1]: initrd-cleanup.service: Failed with result 'exit-code'.
[   93.554574] systemd[1]: [�[0;32m  OK  �[0mFailed to start Cleaning Up and Shutting Down Daemons.
] [   93.656457] Started Setup Virtual Console.
systemd[1]: initrd-cleanup.service: Triggering OnFailure= dependencies.
[   93.659523] systemd[1]: Starting Setup Virtual Console...
[   93.661724] systemd[1]: Started Setup Virtual Console.
cat: unrecognized option '-------------------------------------------------------------------------------'
Try 'cat --help' for more information.
�[0;1;31m�[0mIgnition v0.28.0
�[0;1;31m�[0mreading system config file "/usr/lib/ignition/base.ign"
�[0;1;31m�[0mparsing config: {
  "ignition": {
    "version": "2.1.0"
  },
  "systemd": {
    "units": [
      {
        "name": "coreos-metadata-sshkeys@.service",
        "enabled": true
      }
    ]
  }
}
�[0;1;31m�[0mparsed url from cmdline: ""
�[0;1;31m�[0mno config URL provided
�[0;1;31m�[0mreading system config file "/usr/lib/ignition/user.ign"
�[0;1;31m�[0mno config at "/usr/lib/ignition/user.ign"
�[0;1;31m�[0mGET http://169.254.169.254/2009-04-04/user-data: attempt #1
�[0;1;31m�[0mGET result: OK
�[0;1;31m�[0mparsing config: {"ignition":{"config":{},"timeouts":{},"version":"2.1.0"},"networkd":{},"passwd":{},"storage":{"directories":[{"filesystem":"root","group":{},"path":"/etc/ssl/etcd","user":{},"mode":493}],"files":[{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/ca.crt","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/shared/ca.crt","verification":{"hash":"sha512-db44cf94ad3fad72888ef15bbcc2b3a5b18a7ead6f96b70e2eda648c112cea51530ae10425022f85fe066127639d6e1a39541910d8a1d408f98658d7bddf876a"}},"mode":420},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/client.key","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/client.key","verification":{"hash":"sha512-7a7a6c7184d06f191ca2c5325773e0e73e7e5fcdfced5b2f041e5f99313322a4ad53054634fc3ca60c0e877eb8c9e8fb461f08a2c7dd1fe655347ecf5a48851f"}},"mode":384},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/client.crt","user
":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/client.crt","verification":{"hash":"sha512-4162647ddd8d9460c35ef4c0f88e0cc568fb1a19753e73f6d0d78bfb31d0ca9bea7c5a64dcf6ac9395d96c2df779dc8aa173d70f8f5fb28f02e421208621e016"}},"mode":420},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/server.key","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/server.key","verification":{"hash":"sha512-69230ab8269ee9e656693ef61d3c272bdcc1613884a2c2ca6e1ef2b18e042847be9697fc5599646a5c6513b2149f47bac00a2da562b7ab18e524f43a39d46c2f"}},"mode":384},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/server.crt","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/server.crt","verification":{"hash":"sha512-97012c36d6b7cbe06ec1a73a835d7b84fa390f9eb8fe85e0359ad923e29e116b53900f9547fb66b02d1912217a32e277c616c5153a943c5e1011da9a00ec463f"
}},"mode":420},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/peer.key","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/peer.key","verification":{"hash":"sha512-85a677a36602dc30606639e93acc6df4262e5f127c5db2a4d7a6585e36b368d410676f8d05cf1b7f093a090355b100a8be7c858f4ee7761f763f8a6602baa2f9"}},"mode":384},{"filesystem":"root","group":{},"path":"/etc/ssl/etcd/peer.crt","user":{"id":232},"contents":{"source":"s3://kubernetes.dev.example.com/000-003/etcd/servers/etcd0.000-003/peer.crt","verification":{"hash":"sha512-a0411b0e5f519054b0871ea27ec7df86adb5b77927be1d71e9602ba2a1f4ec2f9ba14f5dd18e71986e4b7b08d36161adbeda3db86700a672170e0d0b73084934"}},"mode":420}],"filesystems":[{"mount":{"device":"/dev/sdf","format":"ext4","label":"etcd"},"name":"etcd-data"}]},"systemd":{"units":[{"contents":"[Unit]\nDescription=Mount volume for storing etcd data\nBefore=etcd-member.service\n\n[Mount]\nWhat=/dev/sdf\nWhere=/media/etcd\nType=
ext4\n\n[Install]\nWantedBy=etcd-member.service\n","enabled":true,"name":"media-etcd.mount"},{"dropins":[{"contents":"[Service]\nEnvironment=ETCD_ADVERTISE_CLIENT_URLS=\"https://etcd0.000-003.k
ubernetes.local:2379\"\nEnvironment=ETCD_CERT_FILE=\"/etc/ssl/certs/server.crt\"\nEnvironment=ETCD_CLIENT_CERT_AUTH=true\nEnvironment=ETCD_DATA_DIR=\"/media/etcd/data\"\nEnvironment=ETCD_DISCOVERY_SRV=\"000-003.kubernetes.local\"\nEnvironment=ETCD_INITIAL_ADVERTISE_PEER_URLS=\"https://etcd0.000-003.kubernetes.local:2380\"\nEnvironment=ETCD_INITIAL_CLUSTER_TOKEN=\"000-003\"\nEnvironment=ETCD_KEY_FILE=\"/etc/ssl/certs/server.key\"\nEnvironment=ETCD_LISTEN_CLIENT_URLS=\"https://10.105.48.37:2379,https://127.0.0.1:2379\"\nEnvironment=ETCD_LISTEN_METRICS_URLS=\"http://0.0.0.0:9379\"\nEnvironment=ETCD_LISTEN_PEER_URLS=\"https://10.105.48.37:2380\"\nEnvironment=ETCD_PEER_CERT_FILE=\"/etc/ssl/certs/peer.crt\"\nEnvironment=ETCD_PEER_CLIENT_CERT_AUTH=true\nEnvironment=ETCD_PEER_KEY_FILE=\"/etc/ssl/ce
rts/peer.key\"\nEnvironment=ETCD_PEER_TRUSTED_CA_FILE=\"/etc/ssl/certs/ca.crt\"\nEnvironment=ETCD_SSL_DIR=\"/etc/ssl/etcd\"\nEnvironment=ETCD_TRUSTED_CA_FILE=\"/etc/ssl/certs/ca.crt\"\n","name":"20-clct-etcd-member.conf"},{"contents":"[Service]\nExecStartPre=/bin/sh -c \\\n  \"if [ -d /media/etcd/data/member ]; then \\\n     echo 'ETCD_INITIAL_CLUSTER_STATE=existing' \u003e /tmp/initial-cluster-state; fi\"\nEnvironmentFile=-/tmp/initial-cluster-state\n","name":"25-initial-cluster-state.conf"}],"enabled":true,"name":"etcd-member.service"}]}}
�[0;1;31m�[0mdisks: createFilesystems: op(1): [started]  waiting for devices [/dev/sdf]
�[0;1;31m�[0mdisks: createFilesystems: op(1): [failed]   waiting for devices [/dev/sdf]: device unit dev-sdf.device timeout
�[0;1;31m�[0mIgnition failed: failed to create filesystems: failed to wait on filesystems devs: device unit dev-sdf.device timeout
�[0;1;31m�[0mdisks failed
	2018-12-04T16:18:55.000Z

@seh seh referenced this issue Dec 4, 2018

Closed

bootengine: some udev rules are in rootfs but missing in initramfs #2481

@bgilbert

This comment has been minimized.

Sign in to view
Member

bgilbert commented Dec 5, 2018

The udev rules aren't actually being installed in the initramfs. The docs for the dracut inst_rules command say:

Non-existant udev rules are reported, but do not let dracut fail.
@seh

This comment has been minimized.

Sign in to view

seh commented Dec 5, 2018

Does that mean that the rules aren't supposed to be installed there, or that they are supposed to but by a mistake or historical omission they are not yet installed there?
@seh

This comment has been minimized.

Sign in to view

seh commented Dec 5, 2018 •
edited

I see the file 90-cloud-storage.rules is mentioned in file dracut/30ignition/module-setup.h, but I don't know where any of the rules files mentioned there come from. It sounds like you're saying that we mentioned them, but didn't put them in place. There's a comment in coreos/bootengine#148 that says as much, and it doesn't look like the follow-on coreos/bootengine#149 adds those rules files either.

Reading it again tonight, #2481 sounds like it was intended to address this problem, as I mentioned above. That one takes us to coreos/bootengine#149.
@seh

This comment has been minimized.

Sign in to view

seh commented Dec 5, 2018

coreos/init#268 introduced file udev/rules.d/90-cloud-storage.rules.

@bgilbert bgilbert referenced this issue Dec 5, 2018

Merged

sys-kernel/coreos-kernel: depend on coreos-init #3499

@bgilbert bgilbert added kind/bug area/usability team/os component/initrd labels Dec 5, 2018

@bgilbert

This comment has been minimized.

Sign in to view
Member

bgilbert commented Dec 5, 2018

Sorry, #2531 (comment) was meant as a note for the record while I tracked this down; I didn't intend to send you on a wild goose chase. This is a bug in coreos/coreos-overlay#3396 and coreos/coreos-overlay#3456: bootengine expects to copy the udev rules from coreos-init into the initramfs, but there was nothing ensuring that coreos-init is installed before bootengine runs. Because Dracut's inst_rules doesn't fail on error, this wasn't noticed. This should be fixed by coreos/coreos-overlay#3499.

Thanks for the careful and detailed report!
@seh

This comment has been minimized.

Sign in to view

seh commented Dec 5, 2018

That's fantastic news. Thank you for the fast response. I'll keep an eye on coreos/coreos-overlay#3499.

@bgilbert bgilbert referenced this issue Dec 6, 2018

Closed

Update grub-ec2.cfg to be inline with the aws docs #3366

@bgilbert bgilbert closed this in coreos/coreos-overlay#3499 Dec 6, 2018

@bgilbert

This comment has been minimized.

Sign in to view
Member

bgilbert commented Dec 6, 2018

This will be in alpha 1995.0.0. Thanks again for reporting!
@seh

This comment has been minimized.

Sign in to view

seh commented Dec 6, 2018

Thank you!

How long do you estimate the delay will be before there's an EC2 AMI available for that version? I see we're at version 1981.0.0 today.
@ajeddeloh

This comment has been minimized.

Sign in to view

ajeddeloh commented Dec 6, 2018

1995.0.0 should land in about two weeks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment