search

firecracker-microvm / firecracker

Secure and fast microVMs for serverless computing.
http://firecracker-microvm.io
Apache License 2.0
26.38k stars 1.83k forks source link

Virtual block device containing UEFI partitions not mounted #2021

Closed mazzy89 closed 4 years ago

mazzy89 commented 4 years ago

I'm running the following command:

sudo ./firectl --firecracker-binary=$HOME/firecracker --kernel=$HOME/vmlinux --root-drive=$HOME/flatcar_production_image.bin --root-partition="cf6a426f-c175-42b9-a165-fd3bab6a652c" --kernel-opts="rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 reboot=k panic=1 pci=off" --cpu-template=T2 --memory=1024

Despite I get this:

INFO[0000] Attaching drive /home/salvo/flatcar_production_image.bin, slot 1, root true.
INFO[0000] Attached drive /home/salvo/flatcar_production_image.bin: [PUT /drives/{drive_id}][204] putGuestDriveByIdNoContent

I do not see any device mounted in my host machine in fact it does not boot up correctly returning 

Warning: /dev/disk/by-partuuid/cf6a426f-c175-42b9-a165-fd3bab6a652c does not exist

I would not mind improving the mounting of the device wiring a PR in case there is an issue. However, at the moment, I'm stuck to debug further the following issue.

gbionescu commented 4 years ago

Hi @mazzy89,

I think that this issue may be related to the firectl project.

If you want to try the kernel and root filesystem that you're using with Firecracker, you can follow the Getting Started document.

Thanks!

mazzy89 commented 4 years ago

Hi @gc-plp

thank you for the reaction.

I think the issue belongs here 😉

I've tested also without using firectl and I get the same result. It is not a problem of firectl for sure.

You can replicate this simply:

{
  "boot-source": {
    "kernel_image_path": "vmlinux",
    "boot_args": "rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 noapic reboot=k panic=1 pci=off"
  },
  "drives": [
    {
      "drive_id": "1",
      "path_on_host": "flatcar_production_image.bin",
      "is_root_device": true,
      "is_read_only": false,
      "partuuid": "cf6a426f-c175-42b9-a165-fd3bab6a652c"
    }
  ],
  "machine-config": {
    "vcpu_count": 1,
    "mem_size_mib": 1024,
    "ht_enabled": false
  }
}
sudo firecracker --api-sock /tmp/firecracker --config-file config.json
gbionescu commented 4 years ago

In order to debug what Firecracker is doing under the hood, you can enable the logging module as described here.

it does not boot up correctly

Could you give us more details on what you are referring to by not booting up correctly? Does the kernel boot? If yes, does it work with a different rootfs?

mazzy89 commented 4 years ago

Thank you @gc-plp

I'll try to turn on the logging module.

Meanwhile trying to reply to your question

Yes the kernel boot.

I have tried with different rootfs and it does not work.

My gut feeling is that the kernel I'm using with this config https://stable.release.flatcar-linux.net/amd64-usr/current/flatcar_production_image_kernel_config.txt has not loaded the virtio modules.

I'm trying to load them at the startup.

mazzy89 commented 4 years ago

built the latest unreleased firecracker version so to have logging flags available. here what I get using the flags

--log-path ./firecracker-vmm.log --level Error --show-level --show-log-origin
Running Firecracker v0.21.0

not much

mazzy89 commented 4 years ago

bootstrap output

[    0.000000] Linux version 4.19.128-flatcar (jenkins@jenkins-worker-3) (gcc version 8.3.0 (Gentoo Hardened 8.3.0-r1 p1.1)) #1 SMP Tue Jun 16 10:17:17 -00 2020
[    0.000000] Command line: rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 reboot=k panic=1 pci=off root=PARTUUID=cf6a426f-c175-42b9-a165-fd3bab6a652c ro virtio_mmio.device=4K@0xd0000000:5
[    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: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] Hypervisor detected: KVM
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 5266001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 14829022 cycles
[    0.000041] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000072] tsc: Detected 2194.848 MHz processor
[    0.000692] last_pfn = 0x80000 max_arch_pfn = 0x400000000
[    0.000957] Disabled
[    0.000989] x86/PAT: MTRRs disabled, skipping PAT initialization too.
[    0.001024] CPU MTRRs all blank - virtualized system.
[    0.001062] x86/PAT: Configuration [0-7]: WB  WT  UC- UC  WB  WT  UC- UC
[    0.001898] ACPI: Early table checksum verification disabled
[    0.002059] ACPI BIOS Error (bug): A valid RSDP was not found (20180810/tbxfroot-210)
[    0.002431] No NUMA configuration found
[    0.002433] Faking a node at [mem 0x0000000000000000-0x000000007fffffff]
[    0.002448] NODE_DATA(0) allocated [mem 0x7fffa000-0x7fffffff]
[    0.002964] Zone ranges:
[    0.003002]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.003004]   DMA32    [mem 0x0000000001000000-0x000000007fffffff]
[    0.003005]   Normal   empty
[    0.003007] Movable zone start for each node
[    0.003008] Early memory node ranges
[    0.003009]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.003010]   node   0: [mem 0x0000000000100000-0x000000007fffffff]
[    0.003048] Zeroed struct page in unavailable ranges: 98 pages
[    0.003049] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffffff]
[    0.094834] smpboot: Boot CPU (id 0) not listed by BIOS
[    0.094859] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.095026] [mem 0x80000000-0xffffffff] available for PCI devices
[    0.095037] Booting paravirtualized kernel on KVM
[    0.095051] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.187793] random: get_random_bytes called from start_kernel+0x93/0x525 with crng_init=0
[    0.187831] setup_percpu: NR_CPUS:512 nr_cpumask_bits:512 nr_cpu_ids:1 nr_node_ids:1
[    0.193428] percpu: Embedded 44 pages/cpu s143192 r8192 d28840 u2097152
[    0.193533] KVM setup async PF for cpu 0
[    0.193549] kvm-stealtime: cpu 0, msr 7da161c0
[    0.193584] Built 1 zonelists, mobility grouping on.  Total pages: 515977
[    0.193586] Policy zone: DMA32
[    0.193599] Kernel command line: rootflags=rw mount.usrflags=ro rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 reboot=k panic=1 pci=off root=PARTUUID=cf6a426f-c175-42b9-a165-fd3bab6a652c ro virtio_mmio.device=4K@0xd0000000:5
[    0.199039] Memory: 1993932K/2096760K available (10252K kernel code, 1217K rwdata, 6032K rodata, 45380K init, 1768K bss, 102828K reserved, 0K cma-reserved)
[    0.199748] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.199782] ftrace: allocating 29240 entries in 115 pages
[    0.226923] rcu: Hierarchical RCU implementation.
[    0.226925] rcu:     RCU event tracing is enabled.
[    0.226937] rcu:     RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=1.
[    0.226950] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.231669] NR_IRQS: 33024, nr_irqs: 32, preallocated irqs: 16
[    0.232204] Console: colour dummy device 80x25
[    0.366262] console [ttyS0] enabled
[    0.367308] APIC: ACPI MADT or MP tables are not detected
[    0.368910] APIC: Switch to virtual wire mode setup with no configuration
[    0.370850] Not enabling interrupt remapping due to skipped IO-APIC setup
[    0.372810] KVM setup pv IPIs
[    0.373920] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1fa33006d59, max_idle_ns: 440795304862 ns
[    0.376959] Calibrating delay loop (skipped) preset value.. 4389.69 BogoMIPS (lpj=2194848)
[    0.378951] pid_max: default: 32768 minimum: 301
[    0.379991] Security Framework initialized
[    0.380969] SELinux:  Initializing.
[    0.388284] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.393687] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.395974] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.397962] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.401034] x86/cpu: Activated the Intel User Mode Instruction Prevention (UMIP) CPU feature
[    0.404101] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.404950] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.406959] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.408968] Spectre V2 : Mitigation: Enhanced IBRS
[    0.409951] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.411960] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.413952] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.429024] Freeing SMP alternatives memory: 28K
[    0.433318] smpboot: SMP disabled
[    0.434979] Performance Events: unsupported p6 CPU model 85 no PMU driver, software events only.
[    0.438130] rcu: Hierarchical SRCU implementation.
[    0.441239] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.443143] smp: Bringing up secondary CPUs ...
[    0.443951] smp: Brought up 1 node, 1 CPU
[    0.445951] smpboot: Max logical packages: 1
[    0.446951] smpboot: Total of 1 processors activated (4389.69 BogoMIPS)
[    0.450159] devtmpfs: initialized
[    0.451047] x86/mm: Memory block size: 128MB
[    0.453613] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.454954] futex hash table entries: 256 (order: 2, 16384 bytes)
[    0.457063] pinctrl core: initialized pinctrl subsystem
[    0.459345] NET: Registered protocol family 16
[    0.461105] audit: initializing netlink subsys (disabled)
[    0.463229] cpuidle: using governor menu
[    0.464087] KVM setup pv remote TLB flush
[    0.466151] dca service started, version 1.12.1
[    0.467958] PCI: Fatal: No config space access function found
[    0.471154] audit: type=2000 audit(1594654956.227:1): state=initialized audit_enabled=0 res=1
[    0.474422] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.477239] ACPI: Interpreter disabled.
[    0.478060] vgaarb: loaded
[    0.478977] pps_core: LinuxPPS API ver. 1 registered
[    0.480950] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.482953] PTP clock support registered
[    0.483959] PCI: System does not support PCI
[    0.486443] clocksource: Switched to clocksource kvm-clock
[    0.517862] VFS: Disk quotas dquot_6.6.0
[    0.519165] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.521431] pnp: PnP ACPI: disabled
[    0.524735] NET: Registered protocol family 2
[    0.526662] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes)
[    0.529139] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
[    0.531737] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[    0.534589] TCP: Hash tables configured (established 16384 bind 16384)
[    0.537117] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[    0.539146] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[    0.541273] NET: Registered protocol family 1
[    0.542666] NET: Registered protocol family 44
[    0.636014] random: fast init done
[    1.752946] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1fa33006d59, max_idle_ns: 440795304862 ns
[    1.758031] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    1.761806] Initialise system trusted keyrings
[    1.763400] workingset: timestamp_bits=39 max_order=19 bucket_order=0
[    2.017765] Key type asymmetric registered
[    2.019900] Asymmetric key parser 'x509' registered
[    2.022296] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    2.026017] io scheduler noop registered
[    2.027997] io scheduler deadline registered
[    2.030176] io scheduler cfq registered (default)
[    2.032124] io scheduler mq-deadline registered
[    2.033667] io scheduler kyber registered
[    2.035014] io scheduler bfq registered
[    2.036616] ioatdma: Intel(R) QuickData Technology Driver 4.00
[    2.038596] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    2.065623] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a U6_16550A
[    2.093409] serial8250: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a U6_16550A
[    2.121051] serial8250: ttyS2 at I/O 0x3e8 (irq = 4, base_baud = 115200) is a U6_16550A
[    2.124232] i8042: PNP: No PS/2 controller found.
[    2.125818] i8042: Probing ports directly.
[    2.138055] i8042: Failed to disable AUX port, but continuing anyway... Is this a SiS?
[    2.140585] i8042: If AUX port is really absent please use the 'i8042.noaux' option
[    2.394269] serio: i8042 KBD port at 0x60,0x64 irq 1
[    2.396277] rtc_cmos rtc_cmos: only 24-hr supported
[    2.398270] NET: Registered protocol family 10
[    2.400246] Segment Routing with IPv6
[    2.401464] NET: Registered protocol family 17
[    2.402942] Key type dns_resolver registered
[    2.404596] mce: Using 32 MCE banks
[    2.405765] sched_clock: Marking stable (2267872409, 137859657)->(2411612930, -5880864)
[    2.408474] registered taskstats version 1
[    2.409843] Loading compiled-in X.509 certificates
[    2.444867] Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 4.19.128-flatcar: 9cffd6cc9ffc8fb271bb8740d6aa5663d6b12864'
[    2.448530] ima: No TPM chip found, activating TPM-bypass!
[    2.450282] ima: Allocated hash algorithm: sha1
[    2.452028] hctosys: unable to open rtc device (rtc0)
[    2.461410] Freeing unused kernel image memory: 45380K
[    2.465042] Write protecting the kernel read-only data: 18432k
[    2.474456] Freeing unused kernel image memory: 2016K
[    2.476445] Freeing unused kernel image memory: 112K
[    2.478007] Run /init as init process
[    2.485597] systemd[1]: systemd 241-53-gbe3cc54+ 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.492636] systemd[1]: Detected virtualization kvm.
[    2.494259] systemd[1]: Detected architecture x86-64.
[    2.495854] systemd[1]: Running in initial RAM disk.

Welcome to dracut-049 (Initramfs)!

[    2.501525] systemd[1]: No hostname configured.
[    2.502999] systemd[1]: Set hostname to <localhost>.
[    2.504619] systemd[1]: Initializing machine ID from random generator.
[    2.506896] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid argument
[    2.620630] systemd[1]: File /usr/lib/systemd/system/systemd-journald.service:12 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
[    2.626100] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[  OK  ] Listening on udev Kernel Socket.
[  OK  ] Created slice system-systemd\x2dfsck.slice.
[  OK  ] Created slice system-disk\x2duuid.slice.
[  OK  ] Listening on udev Control Socket.
[  OK  ] Listening on Journal Audit Socket.
[  OK  ] Listening on Journal Socket.
         Starting Create list of re…odes for the current kernel...
         Starting Apply Kernel Variables...
[  OK  ] Reached target Swap.
         Starting Setup Virtual Console...
[  OK  ] Started Dispatch Password …ts to Console Directory Watch.
[  OK  ] Reached target Local Encrypted Volumes.
[  OK  ] Reached target Timers.
[  OK  ] Reached target Slices.
[  OK  ] Listening on Journal Socket (/dev/log).
         Starting Journal Service...
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Paths.
[  OK  ] Started Create list of req… nodes for the current kernel.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Setup Virtual Console.
         Starting dracut cmdline hook...
         Starting Create Static Device Nodes in /dev...
[  OK  ] Started Create Static Device Nodes in /dev.
[  OK  ] Started dracut cmdline hook.
         Starting dracut pre-udev hook...
[    2.898778] input: AT Raw Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    2.905380] device-mapper: uevent: version 1.0.3
[    2.912091] device-mapper: ioctl: 4.39.0-ioctl (2018-04-03) initialised: dm-devel@redhat.com
[  OK  ] Started dracut pre-udev hook.
         Starting udev Kernel Device Manager...
[  OK  ] Started Journal Service.
[    3.252810] audit: type=1130 audit(1594654959.016:2): 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'
[    3.122312] systemd-sysctl[148]: Couldn't write 'fq_codel' to 'net/core/default_qdisc', ignoring: No such file or directory
[    3.129716] systemd-vconsole-setup[152]: KD_FONT_OP_GET failed while trying to get the font metadata: Function not implemented
[    3.137664] systemd-vconsole-setup[152]: Fonts will not be copied to remaining consoles
[    3.140872] dracut-cmdline[156]: dracut-dracut-049
[    3.147232] dracut-cmdline[156]: Using kernel command line parameters: rootflags=rw mount.usrflags=ro rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 reboot=k panic=1 pci=off root=PARTUUID=cf6a426f-c175-42b9-a165-fd3bab6a652c ro virtio_mmio.device=4K@0xd0000000:5
[    3.248446] systemd-udevd[247]: Specified group 'render' unknown
[  OK  ] Started udev Kernel Device Manager.[    3.254684] systemd[1]: Started udev Kernel Device Manager.
[    3.394803] audit: type=1130 audit(1594654959.158:3): 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'
         Starting dracut pre-trigger hook...
[    3.265626] systemd[1]: Starting dracut pre-trigger hook...

[    3.274759] systemd[1]: Starting Network Service...Starting Network Service...

[    3.305288] dracut-pre-trigger[248]: rd.md=0: removing MD RAID activation
[  OK  ] Started dracut pre-trigger hook.[    3.381519] systemd[1]: Started dracut pre-trigger hook.

[    3.521942] audit: type=1130 audit(1594654959.285:4): 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'
[    3.391009] systemd[1]: Starting udev Coldplug all Devices...         Starting udev Coldplug all Devices...

[    3.412491] systemd-udevd[247]: Specified group 'render' unknown
[  OK  ] Started udev Coldplug all Devices.[    3.462722] systemd[1]: Started udev Coldplug all Devices.

[    3.603160] audit: type=1130 audit(1594654959.367:5): 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'
[    3.472438] systemd[1]: Starting dracut initqueue hook...         Starting dracut initqueue hook...

[    3.699731] cryptd: max_cpu_qlen set to 1000
[    3.571741] systemd-udevd[294]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
[    3.769692] AVX2 version of gcm_enc/dec engaged.
[    3.771259] AES CTR mode by8 optimization enabled
[    3.655442] systemd-vconsole-setup[309]: KD_FONT_OP_GET failed while trying to get the font metadata: Function not implemented
[    3.659500] systemd-vconsole-setup[309]: Fonts will not be copied to remaining consoles
[    3.800600] systemd-networkd[254]: Enumeration completed
[  OK  ] Started Network Service.
[    3.943178] audit: type=1130 audit(1594654959.707:6): 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'
[    3.812298] systemd[1]:          Starting Network Name Resolution...Started Network Service.
[    3.815906]
systemd[1]: Starting Network Name Resolution...
[    3.824523] systemd-networkd[254]: lo: Configured
[    4.071296] systemd-resolved[354]: Positive Trust Anchors:
[    4.073581] systemd-resolved[354]: . IN DS 19036 8 2 49aac11d7b6f6446702e54a1607371607a1a41855200fd2ce1cdde32f24e8fb5
[    4.078607] systemd-resolved[  OK  ] Started Network Name Resolution.
[    4.220440] audit: type=1130 audit(1594654959.984:7): 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'
[  OK  ] Reached target Host and Network Name Lookups.[354]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
[  OK  ] Reached target Network.
[    4.096175] systemd-resolved
[354]: 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
[    4.107073] systemd-resolved[354]: Defaulting to hostname 'linux'.
[    4.109499] systemd[1]: Started Network Name Resolution.
[    4.111700] systemd[1]: Reached target Host and Network Name Lookups.
[    4.114082] systemd[1]: Reached target Network.
[   30.112042] random: crng init done
[ TIME ] Timed out waiting for device /dev/disk/by-label/OEM.
[   92.542705] systemd[1]: dev-disk-by\x2dlabel-OEM.device: Job dev-disk-by\x2dlabel-OEM.device/start timed out.[DEPEND
] Dependency failed for Ignition (setup).
[DEPEND[   92.553242] systemd[1]: Timed out waiting for device /dev/disk/by-label/OEM.] Dependency failed for Ignition (files).
[DEPEND
[   92.561981] systemd[1]: Dependency failed for Ignition (setup).] Dependency failed for Popu…orcx store to satisfy profile.
[DEPEND
[   92.572190] systemd[1]: Dependency failed for Ignition (files).] Dependency failed for Initrd Default Target.
[DEPEND
[   92.581574] systemd[1]: Dependency failed for Populate torcx store to satisfy profile.] Dependency failed for Ignition (disks).
[
[   92.590719] systemd[1]: Dependency failed for Initrd Default Target. TIME ] Timed out waiting for device .
[DEPEND
[   92.602527] systemd[1]: initrd.target: Job initrd.target/start failed with result 'dependency'.] Dependency failed for Gene…0-0000-0000-0000-000000000001.
[ TIME
[   92.614652] systemd[1]: initrd.target: Triggering OnFailure= dependencies.] Timed out waiting for device -213a-4e5a-8e26-6cce9662f132.
[DEPEND
[   92.625421] systemd[1]: torcx-profile-populate.service: Job torcx-profile-populate.service/start failed with result 'dependency'.] Dependency failed for Verity Setup for /dev/mapper/usr.
[DEPEND
[   92.638930] ] Dependency failed for /dev/mapper/usr.systemd[1]: ignition-files.service: Job ignition-files.service/start failed with result 'dependency'.
[   92.642939] systemd[1]: Dependency failed for Ignition (disks).
[   92.642987] systemd[1]: ignition-disks.service: Job ignition-disks.service/start failed with result 'dependency'.
[   92.643023] systemd[1]: ignition-setup.service: Job ignition-setup.service/start failed with result 'dependency'.
[   92.643058] systemd[1]: dev-disk-by\x2dlabel-OEM.device: Job dev-disk-by\x2dlabel-OEM.device/start failed with result 'timeout'.

[DEPEND] Dependency failed for File…stem Check on /dev/mapper/usr.
[DEPEND] Dependency failed for /sysroot/usr.
[DEPEND] Dependency failed for Root filesystem setup.
[DEPEND] Dependency failed for Initrd File Systems.[   92.643180] systemd[1]: Unnecessary job for /dev/disk/by-label/EFI-SYSTEM was removed.
[   92.665874]
[  OK  ] Reached target Local File Systems (Pre).systemd[1]: dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.device: Job dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.device/start timed out.

[   92.674023] systemd[1]: Timed out waiting for device /dev/disk/by-diskuuid/00000000-0000-0000-0000-000000000001.
[   92.677408] systemd[  OK  ] Stopped Dispatch Password …ts to Console Directory Watch.
         [1]: Dependency failed for Generate new UUID for disk GPT dev/disk/by-diskuuid/00000000-0000-0000-0000-000000000001.Starting Setup Virtual Console...

[[   92.691426] systemd  OK  [1]: disk-uuid@dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.service: Job disk-uuid@dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.service/start failed with result 'dependency'.] Stopped dracut initqueue hook.
[   92.838288] audit: type=1130 audit(1594655048.602:8): 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'
[  OK
[   92.708060] ] Started Setup Virtual Console.systemd[1]: dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.device: Job dev-disk-by\x2ddiskuuid-00000000\x2d0000\x2d0000\x2d0000\x2d000000000001.device/start failed with result 'timeout'.
[
[   92.719636] systemd  OK  ] [   92.859068] audit: type=1131 audit(1594655048.608:9): 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'
Started Emergency Shell.[1]: dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device: Job dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device/start timed out.
[  OK  ] Reached target Emergency Mode.
[   92.735306] systemd[1]:
[  OK  Timed out waiting for device /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132.] Reached target Remote File Systems (Pre).
[  OK  ] Reached target Remote File Systems.
[   92.743544] systemd[1]: Dependency failed for Verity Setup for /dev/mapper/usr.
[   92.884024] audit: type=1130 audit(1594655048.620:10): 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'
[   92.752522] systemd
[  OK  [1]: Dependency failed for /dev/mapper/usr.] Stopped dracut pre-trigger hook.

[  OK  [   92.758266] systemd[1]: ] Stopped dracut pre-udev hook.Dependency failed for File System Check on /dev/mapper/usr.
[   92.762250] systemd[1]:
[  OK  ] Stopped dracut cmdline hook.Dependency failed for /sysroot/usr.

[   92.767268] systemd[1]: [   92.906275] audit: type=1131 audit(1594655048.620:11): 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'
Dependency failed for Root filesystem setup.
[   92.776004] systemd[1]: initrd-setup-root.service: Job initrd-setup-root.service/start failed with result 'dependency'.
[   92.779804] systemd[1]: Dependency failed for Initrd File Systems.
[   92.782221] systemd[1]: initrd-fs.target: Job initrd-fs.target/start failed with result 'dependency'.[   92.922915] audit: type=1130 audit(1594655048.634:12): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=emergency comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'

[   92.791349] systemd[1]: initrd-fs.target: Triggering OnFailure= dependencies.
[   92.793970] systemd[1]: sysroot-usr.mount: Job sysroot-usr.mount/start failed with result 'dependency'.
[   92.797103] systemd[1]: [   92.936076] audit: type=1131 audit(1594655048.659:13): 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'
systemd-fsck@dev-mapper-usr.service: Job systemd-fsck@dev-mapper-usr.service/start failed with result 'dependency'.
[   92.807301] systemd[1]: dev-mapper-usr.device: Job dev-mapper-usr.device/start failed with result 'dependency'.
[   92.810671] systemd[1]: verity-setup.service: Job verity-setup.service/start failed with result 'dependency'.
[   92.813998] systemd[1]: dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device: Job dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device/start failed with result 'timeout'.[   92.957124] audit: type=1131 audit(1594655048.665:14): 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'

[   92.825662] systemd[1]: Reached target Local File Systems (Pre).
[   92.827999] systemd[1]: systemd-ask-password-console.path: Succeeded.
[   92.830517] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.[   92.970800] audit: type=1131 audit(1594655048.668:15): 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'

[   92.839751] systemd[1]: Starting Setup Virtual Console...
[   92.843522] systemd[1]: dracut-initqueue.service: Main process exited, code=killed, status=1/HUP
[   92.848490] systemd[1]: dracut-initqueue.service: Succeeded.
[   92.850975] systemd[1]: Stopped dracut initqueue hook.
[   92.853308] systemd-vconsole-setup[1369]: KD_FONT_OP_GET failed while trying to get the font metadata: Function not implemented
[   92.857064] systemd-vconsole-setup[1369]: Fonts will not be copied to remaining consoles
[   92.859917] systemd[1]: systemd-vconsole-setup.service: Succeeded.
[   92.862312] systemd[1]: Started Setup Virtual Console.
[   92.864443] systemd[1]: Started Emergency Shell.
[   92.866480] systemd[1]: Reached target Emergency Mode.
[   92.868666] systemd[1]: Reached target Remote File Systems (Pre).
[   92.870980] systemd[1]: Reached target Remote File Systems.
[   92.873310] systemd[1]: dracut-pre-trigger.service: Succeeded.
[   92.875571] systemd[1]: Stopped dracut pre-trigger hook.
[   92.877714] systemd[1]: dracut-pre-udev.service: Succeeded.
[   92.880067] systemd[1]: Stopped dracut pre-udev hook.
[   92.882268] systemd[1]: dracut-cmdline.service: Succeeded.
[   92.884417] systemd[1]: Stopped dracut cmdline hook.
Warning: /dev/disk/by-partuuid/cf6a426f-c175-42b9-a165-fd3bab6a652c does not exist
mazzy89 commented 4 years ago

Changing the log-level to Debug I got in the log

2020-07-13T15:56:28.807267350 [anonymous-instance:WARN:src/devices/src/legacy/i8042.rs:126] Failed to trigger i8042 kbd interrupt (disabled by guest OS)
2020-07-13T15:56:28.822760589 [anonymous-instance:WARN:src/devices/src/legacy/i8042.rs:126] Failed to trigger i8042 kbd interrupt (disabled by guest OS)
mazzy89 commented 4 years ago

I noticed that adding the kernel flags

i8042.noaux i8042.nomux i8042.nopnp i8042.dumbkbd

muted the above warning. but still no luck.

mazzy89 commented 4 years ago

Seems that virtio module is actually loaded (or maybe not)

Warning: /dev/disk/by-partuuid/cf6a426f-c175-42b9-a165-fd3bab6a652c does not exist
Press Enter for emergency shell or wait 5 minutes for reboot.

Generating "/run/initramfs/rdsosreport.txt"

Entering emergency mode. Exit the shell to continue.
Type "journalctl" to view system logs.
You might want to save "/run/initramfs/rdsosreport.txt" to a USB stick or /boot
after mounting them and attach it to a bug report.

:/# insmod /usr/lib64/modules/4.19.128-flatcar/kernel/drivers/block/
aoe/             loop.ko          rbd.ko           zram/
brd.ko           mtip32xx/        virtio_blk.ko
drbd/            nbd.ko           xen-blkfront.ko
insmod: ERROR: could not insert module /usr/lib64/modules/4.19.128-flatcar/kernel/drivers/block/virtio_blk.ko: File exists
tnotw commented 4 years ago

I think it depends on what you are trying to achieve, if it's just to boot a simple image then the following works for me.

1) Use a firecracker kernel (i.e. the hello-world kernel from the get-started page) 2) Use the flatcar-container.tar.gz image 3) Create a rootfs from the container image via virt-make-fs -t ext4 flatcar-container.tar.gz flatcar.ext4, or something simliar 4) Use the following config.json:

{
  "boot-source": {
    "kernel_image_path": "vmlinux",
    "boot_args": "mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 consoleblank=0 flatcar.first_boot=detected flatcar.randomize_disk_guid=00000000-0000-0000-0000-000000000001 verity.usrhash=2ba8709773c62cf8a4feb3651ca220ce633340ec9de142f80c412d43a7f78253 console=ttyS0 noapic reboot=k panic=1 pci=off keep_bootcon"
  },
  "drives": [
    {
      "drive_id": "rootfs",
      "path_on_host": "<full_path_to>/flatcar.ext4",
      "is_root_device": true,
      "is_read_only": false
    }
  ],
  "machine-config": {
    "vcpu_count": 1,
    "mem_size_mib": 1024,
    "ht_enabled": false
  }
}

That gets me as far as the login prompt.

The errors you're getting above makes me suspect that the disk images you're attempting to load have UEFI boot partitions, and I don't know if firecracker supports those.

mazzy89 commented 4 years ago

@tnotw thank you to reply on this.

I haven't tried yet your approach and definitely I will.

What I'm trying to achieve is the following. Flatcar as Fedora or similar has a special way to be bootstrap using Ignition https://docs.flatcar-linux.org/ignition/what-is-ignition/

By using the image having the partitions would have been possible to install in a specific partition usually labeled as OEM https://github.com/flatcar-linux/init/blob/flatcar-master/bin/flatcar-install#L550 the ignition file and at the boot, the instance would be automatically provisioned.

However at this point I was not able to do that. maybe as you say the problem is that the the distro has EFI partitions as showed in here 

lsblk  -o NAME,PARTUUID,LABEL
NAME    PARTUUID                             LABEL
sda
|-sda1  6b95f918-8e69-47aa-8018-99849714e3f3 EFI-SYSTEM
|-sda2  0574adf0-ecbb-4146-95b5-ee2d462ec27e
|-sda3  7130c94a-213a-4e5a-8e26-6cce9662f132
| `-usr
|-sda4  e03dd35c-7c2d-4a47-b3fe-27f15780a57c
|-sda6  a0d1abf1-c361-4525-b18d-1fa9e91a960c OEM
|-sda7  5236fd2f-b3d7-4eae-ad21-54b299e04e8c
`-sda9  cf6a426f-c175-42b9-a165-fd3bab6a652c ROOT

and perhaps Firecracker does not support that.

mazzy89 commented 4 years ago

I've just tried your approach @tnotw and seems true that it boots but it fails for instance in here

[ TIME ] Timed out waiting for device /dev/disk/by-label/OEM.

but overall I get to the login.

So seems that

  1. UEFI partitions are not supported - seeking official confirmation. Maybe we could improve introducing a patch
  2. Firecracker for the moment expects kernel cooked in a certain way. Passing in the kernel like https://stable.release.flatcar-linux.net/amd64-usr/current/flatcar_production_image.vmlinuz does not work.
acatangiu commented 4 years ago

UEFI partitions are not supported - seeking official confirmation. Maybe we could improve introducing a patch

That is correct. Firecracker does not use a boot-loader. It sets up the emulated HW to run straight into kernel code from the provided kernel image. Since we have no use for boot-loaders, there's no need for EFI system partitions support.

Firecracker for the moment expects kernel cooked in a certain way. Passing in the kernel like https://stable.release.flatcar-linux.net/amd64-usr/current/flatcar_production_image.vmlinuz does not work.

Firecracker doesn't support compressed kernel format. Just use the uncompressed image from the same linux build/cook. There was this https://github.com/firecracker-microvm/firecracker/pull/670 attempt to add compressed kernel support but it didn't make it in.

You can also decompress the vmlinuz image you mentioned. Example here https://github.com/firecracker-microvm/firecracker/pull/670#issuecomment-454552113.

mazzy89 commented 4 years ago

Thank you @acatangiu for the reply here.

I've tried to use this https://stable.release.flatcar-linux.net/amd64-usr/current/flatcar_production_image.vmlinuz

I have decompressed it before passing to Firecracker. It boots but then I get to the point that I cannot load the block device.

I have linked an output here https://github.com/firecracker-microvm/firecracker/issues/2021#issuecomment-657639650

I believe that it does not work because the the kernel image is not ready for this kind of scenario.

tnotw commented 4 years ago

I'm not sure this will help either (from your kernel config):

 CONFIG_VIRTIO_MMIO=m
# CONFIG_VIRTIO_MMIO_CMDLINE_DEVICES is not set

Perhaps leading to the following when trying to modprobe virtio_mmio in the dracut emergency shell: 

[  605.120147] virtio_mmio: unknown parameter 'device' ignored

Maybe it's not finding the MMIO bus, and hence the block device? So yeah, maybe the flatcar kernel would need tweaked in order to work.

mazzy89 commented 4 years ago

@tnotw your hint is gold. It must be that the reason. From the doc

Allow virtio-mmio devices instantiation via the kernel command line or module parameters. Be aware that using incorrect parameters (base address in particular) can crash your system - you have been warned. See Documentation/admin-guide/kernel-parameters.rst for details.

and CONFIG_VIRTIO_MMIO_CMDLINE_DEVICES is not set in the Flatcar kernel

mazzy89 commented 4 years ago

At the end @tnotw enable CONFIG_VIRTIO_MMIO_CMDLINE_DEVICES in the kernel made the job done. We can close this. Thanks a lot

pktpls commented 3 years ago

I had the same problem when booting OpenWrt in Firecracker. Enabling CONFIG_VIRTIO_MMIO_CMDLINE_DEVICES worked, thank you :)

echo "CONFIG_VIRTIO_MMIO_CMDLINE_DEVICES=y" >> target/linux/x86/64/config-5.10