firecrackerが1.0になったので試してみたでは、firecrackerでゲストOSを動かすところまでやってみました。

今回はfirecracker-containerdを使って、ゲストOS上でコンテナを動作させるところまでやってみたいと思います。

下記の図で、Guest OS & Container workloadと書かれている部分を、Guest 0Sだけではなくて、Container workloadまでちゃんと動かしてみようということになります。

containerdはdockerと同じレイヤの高レベルコンテナランタイムです。
firecracker-containerdはcontainerdをベースに、低レベルコンテナランタイムとしてfirecrackerを使えるようにしたものです。

firecracker本体はrust実装でしたが、firecracker-containerdはGo実装です。

ハマったところ

今回も公式サイトのget-startedにしたがって進めていきましたが、下記の点で軽くハマりました。

get-startedに書かれている方法でS3からダウンロードしたゲスト用vmlinuxはバージョンが4.14で、最新のfirecracker-containerdとの組み合わせでは動作しませんでした。5.10版のvmlinuxを自分でビルドしました。
本家firecrackerで配布されているfirecrackerバイナリとの組み合わせでは動作しませんでした。firecrackerバイナリもビルドし直しました。

事前準備

Dockerのインストール

Dockerの公式サイトにしたがってDockerをインストールします。

$ sudo apt-get install     ca-certificates     curl     gnupg     lsb-release
$ curl -fsSL https://download.docker.com/linux/ubuntu/gpg | sudo gpg --dearmor -o /usr/share/keyrings/docker-archive-keyring.gpg
$ echo   "deb [arch=$(dpkg --print-architecture) signed-by=/usr/share/keyrings/docker-archive-keyring.gpg] https://download.docker.com/linux/ubuntu $(lsb_release -cs) stable" | sudo tee /etc/apt/sources.list.d/docker.list > /dev/null
$ sudo apt update
$ sudo apt-get install docker-ce docker-ce-cli containerd.io
$ sudo usermod -a -G docker $USER

Goのインストール

firecracker-containerdをビルドするためにGo環境をインストールします。

$ rm -rf /usr/local/go && tar -C /usr/local -xzf go1.17.6.linux-amd64.tar.gz
$ export PATH=$PATH:/usr/local/go/bin

gccなどのビルドツールのインストール

firecracker-containerdのビルド時にgccも使うようなので、build-essentialインストールしておきます。

$ sudo apt install build-essential

いろいろビルド

firecracker-containerdのビルド

firecracker-containerのレポジトリをcloneしてビルドします。
submoduleとしてfirecracker本体と、runc本体が定義してあるため、それぞれのレポジトリからcloneされます。

$ git clone --recurse-submodules https://github.com/firecracker-microvm/firecracker-containerd
$ cd firecracker-containerd
$ make all

ビルドに成功したら、make installも実行しておきます。
これで下記の３つのバイナリが/usr/local/bin/にコピーされます。

containerd-shim-aws-firecracker
firecracker-containerd
firecracker-ctr

ctrはcontainerd用のコマンドラインツールです。それのfirecracker-containerd版がfirecracker-ctr。
dockerにおけるdockerコマンドに相当するもので、コンテナやイメージの管理ができます。

firecrackerのビルド

firecrackerもfirecracker-containerdと組み合わせて動作するバージョンをビルドします。
firecracker本家サイトで配布されているv1.0ではうまく動作しませんでした。firecracker-containerdの_submodulesではv.0.25.2が指定されています。

$ make firecracker

make install-firecrackerを実行すると下記のバイナリが/usr/local/binにコピーされます。

firecracker
jailer

$ ls -al /usr/local/bin
total 95332
drwxr-xr-x  2 root root     4096 Feb  5 12:25 .
drwxr-xr-x 11 root root     4096 Feb  5 12:13 ..
-rwxr-xr-x  1 root root 21971841 Feb  5 12:22 containerd-shim-aws-firecracker
-rwxr-xr-x  1 root root  2169472 Feb  5 13:27 firecracker
-rwxr-xr-x  1 root root 41465616 Feb  5 12:22 firecracker-containerd
-rwxr-xr-x  1 root root 30607960 Feb  5 12:22 firecracker-ctr
-rwxr-xr-x  1 root root  1384680 Feb  5 13:27 jailer

firecrackerのゲストOS用rootfsのビルド

firecrackerのゲストOSで使うrootfsイメージをビルドします。
ビルドしたイメージは/var/lib/firecracker-containerd/runtimeに保存しておきます。

$ make image
$ sudo mkdir -p /var/lib/firecracker-containerd/runtime
$ sudo cp tools/image-builder/rootfs.img /var/lib/firecracker-containerd/runtime/default-rootfs.img

firecrackerのゲストOS用カーネルのビルド

firecrackerのゲストOSで使うカーネルイメージをビルドします。
S3からダウンロードできるhello-vmlinuxは4.14で、最新のruncと一緒に動作させようとするとエラーになります。
runcではcgourp v2を使うようになっていて、kernelは5.2以上を推奨、最低でも4.15が必要なためです。

仕方がないので自前でカーネルをビルドします。

firecrackerのrootfs-and-kernel-setup.mdにビルドの方法と、kernelコンフィグファイルのサンプルがあるのでそれをコピーして利用します。

kernelコンフィグのサンプルは4.14用と5.10用だったので、5.10を選択しました。

$ git clone https://github.com/torvalds/linux.git linux.git
$ cd linux.git
$ git checkout v5.10
$ make vmlinux

カーネルのビルドに必要なライブライル群は事前にインストールしておく必要があります。

いろいろ設定

firecracker-containerdの設定

下記の内容のファイルを作成して、config.tomlという名前で保存しておきます。
あとで、firecracker-containerdを起動する時に使用します。

version = 2
disabled_plugins = ["io.containerd.grpc.v1.cri"]
root = "/var/lib/firecracker-containerd/containerd"
state = "/run/firecracker-containerd"
[grpc]
  address = "/run/firecracker-containerd/containerd.sock"
[plugins]
  [plugins."io.containerd.snapshotter.v1.devmapper"]
    pool_name = "fc-dev-thinpool"
    base_image_size = "10GB"
    root_path = "/var/lib/firecracker-containerd/snapshotter/devmapper"

[debug]
  level = "debug"

firecrackerの設定

firecrackerに関する設定ファイルを作成します。/etc/containerd/firecracker-runtime.jsonに保存します。

kernel_image_pathの部分は上で自前ビルドしたカーネルイメージへのパスを設定します。

{
  "firecracker_binary_path": "/usr/local/bin/firecracker",
  "kernel_image_path": "/var/lib/firecracker-containerd/runtime/microvm-vmlinux.bin",
  "kernel_args": "console=ttyS0 noapic reboot=k panic=1 pci=off nomodules ro systemd.journald.forward_to_console systemd.unit=firecracker.target init=/sbin/overlay-init",
  "root_drive": "/var/lib/firecracker-containerd/runtime/default-rootfs.img",
  "cpu_template": "T2",
  "log_fifo": "fc-logs.fifo",
  "log_levels": ["debug"],
  "metrics_fifo": "fc-metrics.fifo"
}

contanerdのストレージドライバ（devmapper)の設定

firecracker-containerdではストレージドライバにdevmapperを使います。
devmapperが使えるように事前設定が必要です。

本家のgetting-startedの説明にしたがって設定します。

コンテナの起動

firecracker-containerdの起動

高レベルコンテナランタイムであるfirecracker-containerdを起動しておきます。dockerデーモンみたいなものです。

config.tomlのところは、上の方で設定したfirecracker-containerd用のtoml設定ファイルを指定します。

$ sudo PATH=$PATH /usr/local/bin/firecracker-containerd --config ./config.toml 
INFO[2022-02-05T17:18:55.414225376Z] starting containerd                           revision=f4f8c99fd90934125b8266ea040fadc1d2b26ad5 version=1.5.9+unknown
INFO[2022-02-05T17:18:55.443293287Z] loading plugin "io.containerd.content.v1.content"...  type=io.containerd.content.v1
INFO[2022-02-05T17:18:55.443383170Z] loading plugin "io.containerd.snapshotter.v1.devmapper"...  type=io.containerd.snapshotter.v1
INFO[2022-02-05T17:18:55.443444786Z] initializing pool device "fc-dev-thinpool"   
INFO[2022-02-05T17:18:55.444977018Z] using dmsetup:
Library version:   1.02.145 (2017-11-03)
Driver version:    4.37.0 
INFO[2022-02-05T17:18:55.450325884Z] loading plugin "io.containerd.snapshotter.v1.overlayfs"...  type=io.containerd.snapshotter.v1
INFO[2022-02-05T17:18:55.450471901Z] loading plugin "io.containerd.metadata.v1.bolt"...  type=io.containerd.metadata.v1
INFO[2022-02-05T17:18:55.450502572Z] metadata content store policy set             policy=shared
INFO[2022-02-05T17:18:55.450600470Z] loading plugin "io.containerd.differ.v1.walking"...  type=io.containerd.differ.v1
INFO[2022-02-05T17:18:55.450626271Z] loading plugin "io.containerd.gc.v1.scheduler"...  type=io.containerd.gc.v1
INFO[2022-02-05T17:18:55.450665508Z] loading plugin "io.containerd.service.v1.introspection-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450691990Z] loading plugin "io.containerd.service.v1.containers-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450716271Z] loading plugin "io.containerd.service.v1.content-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450742093Z] loading plugin "io.containerd.service.v1.diff-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450762957Z] loading plugin "io.containerd.service.v1.images-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450785383Z] loading plugin "io.containerd.service.v1.leases-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450812589Z] loading plugin "io.containerd.service.v1.namespaces-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450829845Z] loading plugin "io.containerd.service.v1.snapshots-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.450849830Z] loading plugin "io.containerd.runtime.v1.linux"...  type=io.containerd.runtime.v1
INFO[2022-02-05T17:18:55.450894374Z] loading plugin "io.containerd.runtime.v2.task"...  type=io.containerd.runtime.v2
DEBU[2022-02-05T17:18:55.450947203Z] loading tasks in namespace                    namespace=default
INFO[2022-02-05T17:18:55.450999924Z] loading plugin "io.containerd.monitor.v1.cgroups"...  type=io.containerd.monitor.v1
INFO[2022-02-05T17:18:55.451366257Z] loading plugin "io.containerd.service.v1.tasks-service"...  type=io.containerd.service.v1
INFO[2022-02-05T17:18:55.451393819Z] loading plugin "io.containerd.service.v1.fc-control"...  type=io.containerd.service.v1
DEBU[2022-02-05T17:18:55.451408226Z] initializing fc-control plugin (root: "/var/lib/firecracker-containerd/containerd/io.containerd.service.v1.fc-control") 
INFO[2022-02-05T17:18:55.469769520Z] loading plugin "io.containerd.internal.v1.restart"...  type=io.containerd.internal.v1
INFO[2022-02-05T17:18:55.469986105Z] loading plugin "io.containerd.grpc.v1.containers"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470049613Z] loading plugin "io.containerd.grpc.v1.content"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470126465Z] loading plugin "io.containerd.grpc.v1.diff"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470172353Z] loading plugin "io.containerd.grpc.v1.events"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470254140Z] loading plugin "io.containerd.grpc.v1.healthcheck"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470336658Z] loading plugin "io.containerd.grpc.v1.images"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470418315Z] loading plugin "io.containerd.grpc.v1.leases"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470485649Z] loading plugin "io.containerd.grpc.v1.namespaces"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470542419Z] loading plugin "io.containerd.internal.v1.opt"...  type=io.containerd.internal.v1
INFO[2022-02-05T17:18:55.470652372Z] loading plugin "io.containerd.grpc.v1.snapshots"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470699406Z] loading plugin "io.containerd.grpc.v1.tasks"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470737854Z] loading plugin "io.containerd.grpc.v1.version"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.470781652Z] loading plugin "io.containerd.grpc.v1.fc-control-service"...  type=io.containerd.grpc.v1
DEBU[2022-02-05T17:18:55.470840659Z] initializing fc-control-service plugin       
INFO[2022-02-05T17:18:55.470925872Z] loading plugin "io.containerd.grpc.v1.introspection"...  type=io.containerd.grpc.v1
INFO[2022-02-05T17:18:55.471466158Z] serving...                                    address=/run/firecracker-containerd/containerd.sock.ttrpc
INFO[2022-02-05T17:18:55.471647159Z] serving...                                    address=/run/firecracker-containerd/containerd.sock
DEBU[2022-02-05T17:18:55.471716947Z] sd notification                               error="<nil>" notified=false state="READY=1"
INFO[2022-02-05T17:18:55.471781069Z] containerd successfully booted in 0.058375s  
DEBU[2022-02-05T17:18:55.555013532Z] garbage collected                             d=4.125831ms

コンテナイメージのPULL

コンテナのイメージをPULLします。

$ sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock images \
  pull --snapshotter devmapper \
  docker.io/library/busybox:latest

イメージの一覧を見ると確かに増えています。

sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock images list
REF                              TYPE                                                      DIGEST                                                                  SIZE      PLATFORMS                                                                                                                          LABELS 
docker.io/library/busybox:latest application/vnd.docker.distribution.manifest.list.v2+json sha256:afcc7f1ac1b49db317a7196c902e61c6c3c4607d63599ee1a82d702d249a0ccb 758.9 KiB linux/386,linux/amd64,linux/arm/v5,linux/arm/v6,linux/arm/v7,linux/arm64/v8,linux/mips64le,linux/ppc64le,linux/riscv64,linux/s390x -

コンテナの起動

コンテナを起動します。

$ sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock \
  run \
  --snapshotter devmapper \
  --runtime aws.firecracker \
  --rm --tty --net-host \
  docker.io/library/busybox:latest busybox-test

上記のコマンドを実行すると、firecrack-containerdを起動しているコンソールに起動ログが出力され、2秒ほどで起動が完了しました！

ログを見ると、firecracker上でゲストOSが起動するところから処理が始まっているのが確認できます。

firecracker-ctrでもコンテナが確認できます。RUNTIMEがaws.firecrackerになっています。

$ sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock containers list
CONTAINER       IMAGE                               RUNTIME            
busybox-test    docker.io/library/busybox:latest    aws.firecracker

コンテナが使っているカーネルはたしかに、ホストのカーネルではなく、firecrackerのゲストOSのカーネルになっています。

/ # uname -a
Linux microvm 5.10.0 #1 SMP Sat Feb 5 15:36:23 UTC 2022 x86_64 GNU/Linux

複数のコンテナの起動

2つ目のコンテンを起動してみます。

$ sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock \
  run \
  --snapshotter devmapper \
  --runtime aws.firecracker \
  --rm --tty --net-host \
  docker.io/library/busybox:latest busybox-test2

$ sudo firecracker-ctr --address /run/firecracker-containerd/containerd.sock containers list
CONTAINER        IMAGE                               RUNTIME            
busybox-test     docker.io/library/busybox:latest    aws.firecracker    
busybox-test2    docker.io/library/busybox:latest    aws.firecracker

ホスト側はfirecrackerのプロセスが増えます。

$ ps axuw | grep fire | grep api-sock
root      2209  1.0  1.3 137820 108948 pts/0   Sl   17:23   0:08 /usr/local/bin/firecracker --api-sock firecracker.sock --id b629ce49-3901-45f4-b77d-2a9235086345
root      2405 64.6  1.3 137820 108944 pts/0   Sl   17:37   0:01 /usr/local/bin/firecracker --api-sock firecracker.sock --id 1707021b-8d0a-4601-9d98-0f8c1d80f8f4

起動時のログ

DEBU[2022-02-05T17:23:35.194605973Z] stat snapshot                                 key="sha256:d31505fd5050f6b96ca3268d1db58fc91ae561ddf14eaabc41d63ea2ef8c1c6d"
DEBU[2022-02-05T17:23:35.194661307Z] stat                                          key="default/2/sha256:d31505fd5050f6b96ca3268d1db58fc91ae561ddf14eaabc41d63ea2ef8c1c6d"
DEBU[2022-02-05T17:23:35.202057874Z] prepare snapshot                              key=busybox-test parent="sha256:d31505fd5050f6b96ca3268d1db58fc91ae561ddf14eaabc41d63ea2ef8c1c6d"
DEBU[2022-02-05T17:23:35.203743651Z] prepare                                       key=default/13/busybox-test parent="default/2/sha256:d31505fd5050f6b96ca3268d1db58fc91ae561ddf14eaabc41d63ea2ef8c1c6d"
DEBU[2022-02-05T17:23:35.203801254Z] creating snapshot device 'fc-dev-thinpool-snap-12' from 'fc-dev-thinpool-snap-1' 
DEBU[2022-02-05T17:23:35.352398716Z] event published                               ns=default topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
DEBU[2022-02-05T17:23:35.359119494Z] get snapshot mounts                           key=busybox-test
DEBU[2022-02-05T17:23:35.359186162Z] mounts                                        key=default/13/busybox-test
DEBU[2022-02-05T17:23:35.404631997Z] event published                               ns=default topic=/containers/create type=containerd.events.ContainerCreate
DEBU[2022-02-05T17:23:35.408373081Z] get snapshot mounts                           key=busybox-test
DEBU[2022-02-05T17:23:35.408451720Z] mounts                                        key=default/13/busybox-test
time="2022-02-05T17:23:35.461761608Z" level=debug msg=StartShim runtime=aws.firecracker task_id=busybox-test
DEBU[2022-02-05T17:23:35.463593174Z] create VM request: VMID:"b629ce49-3901-45f4-b77d-2a9235086345" ContainerCount:1 ExitAfterAllTasksDeleted:true  
DEBU[2022-02-05T17:23:35.463693373Z] using namespace: default                     
DEBU[2022-02-05T17:23:35.464523762Z] starting containerd-shim-aws-firecracker      vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.484732345Z] garbage collected                             d=3.106028ms
DEBU[2022-02-05T17:23:35.509417309Z] registering ttrpc server                     
DEBU[2022-02-05T17:23:35.509546245Z] serving api on socket                         socket="[inherited from parent]"
INFO[2022-02-05T17:23:35.509581852Z] starting signal loop                          namespace=default path="/var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345" pid=2199
INFO[2022-02-05T17:23:35.509811195Z] creating new VM                               runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.509909284Z] noop operation returning shim dir for JailPath  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510005396Z] using socket path: firecracker.sock           runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510029122Z] noop operation returning shim dir for JailPath  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510147522Z] noop operation for StubDrivesOptions          jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510180425Z] noop operation returning shim dir for JailPath  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510256531Z] noop operation for BuildJailedMachine         jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510282166Z] No balloon device is setup                    runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.510360453Z] Called NewMachine()                           runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510380696Z] Called Machine.Start()                        runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510407330Z] Marking Machine as Started                    runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510467059Z] Running handler validate.NetworkCfg           runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510490682Z] Running handler validate.Cfg                  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510524938Z] Running handler fcinit.SetupNetwork           runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510538262Z] Running handler fcinit.SetupKernelArgs        runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510569462Z] Running handler fcinit.StartVMM               runtime=aws.firecracker
INFO[2022-02-05T17:23:35.510583281Z] Called startVMM(), setting up a VMM on firecracker.sock  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510621747Z] Starting [/usr/local/bin/firecracker --api-sock firecracker.sock --id b629ce49-3901-45f4-b77d-2a9235086345]  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510831962Z] VMM started socket path is firecracker.sock   runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.510869184Z] Setting up signal handler: [interrupt quit terminated hangup aborted]  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.522333263Z] returning from startVMM()                     runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.522378404Z] Running handler fcinit.CreateLogFilesHandler  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.522474305Z] Created metrics and logging fifos.            runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.522508906Z] Running handler fcinit.BootstrapLogging       runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.523027104Z] Configured VMM logging to /var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345/fc-logs.fifo  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.523449271Z] Configured VMM metrics to /var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345/fc-metrics.fifo  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.523475141Z] setup logging: success                        runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.523505754Z] Running handler fcinit.CreateMachine          runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.523994340Z] PutMachineConfiguration returned              runtime=aws.firecracker
INFO[2022-02-05T17:23:35.524349713Z] refreshMachineConfiguration: [GET /machine-config][200] getMachineConfigurationOK  &{CPUTemplate:T2 HtEnabled:0xc000039693 MemSizeMib:0xc000039678 TrackDirtyPages:false VcpuCount:0xc000039670}  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.524392170Z] createMachine returning                       runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.524412710Z] Running handler fcinit.CreateBootSource       runtime=aws.firecracker
INFO[2022-02-05T17:23:35.524900125Z] PutGuestBootSource: [PUT /boot-source][204] putGuestBootSourceNoContent   runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.524928152Z] Running handler fcinit.AttachDrives           runtime=aws.firecracker
INFO[2022-02-05T17:23:35.524953987Z] Attaching drive /var/lib/firecracker-containerd/runtime/default-rootfs.img, slot root_drive, root true.  runtime=aws.firecracker
INFO[2022-02-05T17:23:35.525602946Z] Attached drive /var/lib/firecracker-containerd/runtime/default-rootfs.img: [PUT /drives/{drive_id}][204] putGuestDriveByIdNoContent   runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.525631304Z] attachDrive returned for /var/lib/firecracker-containerd/runtime/default-rootfs.img  runtime=aws.firecracker
INFO[2022-02-05T17:23:35.525657404Z] Attaching drive /var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345/ctrstub0, slot MN2HE43UOVRDA, root false.  runtime=aws.firecracker
INFO[2022-02-05T17:23:35.526115972Z] Attached drive /var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345/ctrstub0: [PUT /drives/{drive_id}][204] putGuestDriveByIdNoContent   runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.526189004Z] attachDrive returned for /var/lib/firecracker-containerd/shim-base/default#b629ce49-3901-45f4-b77d-2a9235086345/ctrstub0  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.526219640Z] Running handler fcinit.CreateNetworkInterfaces  runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.526247074Z] Running handler fcinit.AddVsocks              runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.526884809Z] Attach vsock firecracker.vsock successful: [PUT /vsock][204] putGuestVsockNoContent   runtime=aws.firecracker
DEBU[2022-02-05T17:23:35.526912874Z] Running handler firecracker-containerd-jail-pid-handler  runtime=aws.firecracker
INFO[2022-02-05T17:23:35.561225587Z] startInstance successful: [PUT /actions][204] createSyncActionNoContent   runtime=aws.firecracker
INFO[2022-02-05T17:23:35.561264792Z] calling agent                                 runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:35.576863605Z] [    0.000000] Linux version 5.10.0 (beaver) (gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0, GNU ld (GNU Binutils for Ubuntu) 2.30) #1 SMP Sat Feb 5 15:36:23 UTC 2022  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.582173127Z] [    0.000000] Command line: noapic reboot=k nomodules systemd.unit=firecracker.target console=ttyS0 panic=1 pci=off ro systemd.journald.forward_to_console init=/sbin/overlay-init root=/dev/vda ro virtio_mmio.device=4K@0xd0000000:5 virtio_mmio.device=4K@0xd0001000:6 virtio_mmio.device=4K@0xd0002000:7  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.583647363Z] [    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.584916294Z] [    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.586213672Z] [    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.587478049Z] [    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.589392122Z] [    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.590169629Z] [    0.000000] BIOS-provided physical RAM map:  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.591355231Z] [    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.592574615Z] [    0.000000] BIOS-e820: [mem 0x0000000000100000-0x0000000007ffffff] usable  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.593485526Z] [    0.000000] NX (Execute Disable) protection: active  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.594322331Z] [    0.000000] DMI not present or invalid.    jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.595055328Z] [    0.000000] Hypervisor detected: KVM       jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.596145538Z] [    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.597355721Z] [    0.000000] kvm-clock: cpu 0, msr 2a01001, primary cpu clock  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.598451304Z] [    0.000000] kvm-clock: using sched offset of 7414357 cycles  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.600380834Z] [    0.000010] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.601369409Z] [    0.000025] tsc: Detected 2491.904 MHz processor  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.602333385Z] [    0.000269] last_pfn = 0x8000 max_arch_pfn = 0x400000000  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.602745525Z] [    0.000361] Disabled                       jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.603880592Z] [    0.000366] x86/PAT: MTRRs disabled, skipping PAT initialization too.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.604807181Z] [    0.000392] CPU MTRRs all blank - virtualized system.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.606034756Z] [    0.000404] x86/PAT: Configuration [0-7]: WB  WT  UC- UC  WB  WT  UC- UC    jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.607045200Z] [    0.000490] found SMP MP-table at [mem 0x0009fc00-0x0009fc0f]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.608072730Z] [    0.000581] check: Scanning 1 areas for low memory corruption  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.609184223Z] [    0.000772] ACPI: Early table checksum verification disabled  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.610592552Z] [    0.000916] ACPI BIOS Error (bug): A valid RSDP was not found (20200925/tbxfroot-210)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.611269224Z] [    0.001014] No NUMA configuration found    jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.612460428Z] [    0.001017] Faking a node at [mem 0x0000000000000000-0x0000000007ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.613577238Z] [    0.001036] NODE_DATA(0) allocated [mem 0x07fde000-0x07ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.614068317Z] [    0.001288] Zone ranges:                   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.615377050Z] [    0.001294]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.616658302Z] [    0.001297]   DMA32    [mem 0x0000000001000000-0x0000000007ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.617270210Z] [    0.001300]   Normal   empty               jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.618067157Z] [    0.001302] Movable zone start for each node  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.618714797Z] [    0.001309] Early memory node ranges       jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.620064123Z] [    0.001311]   node   0: [mem 0x0000000000001000-0x000000000009efff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.621407539Z] [    0.001315]   node   0: [mem 0x0000000000100000-0x0000000007ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.622624475Z] [    0.001345] Zeroed struct page in unavailable ranges: 98 pages  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.623929612Z] [    0.001348] Initmem setup node 0 [mem 0x0000000000001000-0x0000000007ffffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.624867986Z] [    0.003263] Intel MultiProcessor Specification v1.4  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.625650459Z] [    0.003273] MPTABLE: OEM ID: FC            jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.626572377Z] [    0.003274] MPTABLE: Product ID: 000000000000  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.627319209Z] [    0.003275] MPTABLE: APIC at: 0xFEE00000   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.628087434Z] [    0.003307] Processor #0 (Bootup-CPU)      jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.629502055Z] [    0.003365] IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.630068700Z] [    0.003369] Processors: 1                  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.630887434Z] [    0.003371] TSC deadline timer available   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.631944643Z] [    0.003378] smpboot: Allowing 1 CPUs, 0 hotplug CPUs  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.633503698Z] [    0.003425] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.635063595Z] [    0.003427] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.636281831Z] [    0.003429] [mem 0x08000000-0xffffffff] available for PCI devices  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.637298794Z] [    0.003431] Booting paravirtualized kernel on KVM  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.639283114Z] [    0.003436] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.640675400Z] [    0.003441] setup_percpu: NR_CPUS:128 nr_cpumask_bits:128 nr_cpu_ids:1 nr_node_ids:1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.641861287Z] [    0.005298] percpu: Embedded 44 pages/cpu s143360 r8192 d28672 u2097152  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.642894476Z] [    0.005346] kvm-guest: stealtime: cpu 0, msr 7a22080  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.644015237Z] [    0.005351] kvm-guest: PV spinlocks disabled, single CPU  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.645241147Z] [    0.005366] Built 1 zonelists, mobility grouping on.  Total pages: 32137  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.645883992Z] [    0.005368] Policy zone: DMA32             jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.651295853Z] [    0.005372] Kernel command line: noapic reboot=k nomodules systemd.unit=firecracker.target console=ttyS0 panic=1 pci=off ro systemd.journald.forward_to_console init=/sbin/overlay-init root=/dev/vda ro virtio_mmio.device=4K@0xd0000000:5 virtio_mmio.device=4K@0xd0001000:6 virtio_mmio.device=4K@0xd0002000:7  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.652680902Z] [    0.005683] Dentry cache hash table entries: 16384 (order: 5, 131072 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.653981285Z] [    0.005756] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.655115071Z] [    0.005818] mem auto-init: stack:off, heap alloc:off, heap free:off  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.657626344Z] [    0.006437] Memory: 99044K/130680K available (10243K kernel code, 7811K rwdata, 1868K rodata, 1420K init, 4996K bss, 31380K reserved, 0K cma-reserved)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.659155782Z] [    0.006475] random: get_random_u64 called from __kmem_cache_create+0x2d/0x480 with crng_init=0  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.660319521Z] [    0.006562] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.661304223Z] [    0.006587] Kernel/User page tables isolation: enabled  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.662174844Z] [    0.006785] rcu: Hierarchical RCU implementation.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.663455744Z] [    0.006787] rcu:    RCU restricting CPUs from NR_CPUS=128 to nr_cpu_ids=1.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.664452541Z] [    0.006793]     Tracing variant of Tasks RCU enabled.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.665828511Z] [    0.006797] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.667009810Z] [    0.006798] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.668106718Z] [    0.006834] NR_IRQS: 4352, nr_irqs: 48, preallocated irqs: 16  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.668909782Z] [    0.007200] Console: colour dummy device 80x25  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.669692742Z] [    0.102020] printk: console [ttyS0] enabled  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.670756703Z] [    0.102860] APIC: Switch to symmetric I/O mode setup  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.672146576Z] [    0.103860] Not enabling interrupt remapping due to skipped IO-APIC setup  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.674513165Z] [    0.105411] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x23eb59c9ee2, max_idle_ns: 440795321417 ns  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.676084074Z] [    0.107636] Calibrating delay loop (skipped) preset value.. 4983.80 BogoMIPS (lpj=9967616)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.677052289Z] [    0.109181] pid_max: default: 32768 minimum: 301  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.678099301Z] [    0.110215] LSM: Security Framework initializing  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.678869280Z] [    0.111233] SELinux:  Initializing.        jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.680233825Z] [    0.111627] Mount-cache hash table entries: 512 (order: 0, 4096 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.681613413Z] [    0.111627] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.683416595Z] [    0.111627] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.684759631Z] [    0.111627] Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.686544189Z] [    0.111627] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.687711243Z] [    0.111627] Spectre V2 : Mitigation: Full generic retpoline  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.689395090Z] [    0.111627] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.690866584Z] [    0.111627] Spectre V2 : Enabling Restricted Speculation for firmware calls  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.692658657Z] [    0.111627] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.694375128Z] [    0.111627] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.695173612Z] [    0.111627] MDS: Mitigation: Clear CPU buffers  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.708186332Z] [    0.111627] Freeing SMP alternatives memory: 32K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.711310026Z] [    0.111627] smpboot: CPU0: Intel(R) Xeon(R) Processor @ 2.50GHz (family: 0x6, model: 0x3f, stepping: 0x2)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.713320169Z] [    0.111627] Performance Events: unsupported p6 CPU model 63 no PMU driver, software events only.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.714448287Z] [    0.111733] rcu: Hierarchical SRCU implementation.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.715589978Z] [    0.113087] smp: Bringing up secondary CPUs ...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.716397369Z] [    0.113861] smp: Brought up 1 node, 1 CPU  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.717317519Z] [    0.114674] smpboot: Max logical packages: 1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.718699319Z] [    0.115599] smpboot: Total of 1 processors activated (4983.80 BogoMIPS)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.719590890Z] [    0.115819] devtmpfs: initialized          jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.720582441Z] [    0.116602] x86/mm: Memory block size: 128MB  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.723065351Z] [    0.117943] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.724250772Z] [    0.119645] futex hash table entries: 256 (order: 2, 16384 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.725554426Z] [    0.121154] NET: Registered protocol family 16  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.727161960Z] [    0.122282] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.728674778Z] [    0.123805] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.730316331Z] [    0.125128] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.731477892Z] [    0.126791] audit: initializing netlink subsys (disabled)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.732906080Z] [    0.127795] thermal_sys: Registered thermal governor 'fair_share'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.734176314Z] [    0.127796] thermal_sys: Registered thermal governor 'step_wise'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.735493929Z] [    0.129051] thermal_sys: Registered thermal governor 'user_space'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.736251035Z] [    0.130329] cpuidle: using governor ladder  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.736916523Z] [    0.132356] cpuidle: using governor menu   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.745371398Z] [    0.139675] audit: type=2000 audit(1644081815.593:1): state=initialized audit_enabled=0 res=1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.751785859Z] [    0.146556] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.753669716Z] [    0.148799] ACPI: Interpreter disabled.    jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.754462881Z] [    0.149646] SCSI subsystem initialized     jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.755546791Z] [    0.150331] pps_core: LinuxPPS API ver. 1 registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.757440852Z] [    0.151386] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.758337831Z] [    0.151662] PTP clock support registered   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.759267386Z] [    0.152701] NetLabel: Initializing         jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.760166817Z] [    0.153448] NetLabel:  domain hash size = 128  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.761270537Z] [    0.154344] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.762323703Z] [    0.155482] NetLabel:  unlabeled traffic allowed by default  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.764292529Z] [    0.156454] clocksource: Switched to clocksource kvm-clock  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.765111708Z] [    0.157666] VFS: Disk quotas dquot_6.6.0   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.766357862Z] [    0.158430] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.767136389Z] [    0.159722] pnp: PnP ACPI: disabled        jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.771245075Z] [    0.163609] NET: Registered protocol family 2  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.773198584Z] [    0.164685] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.774804875Z] [    0.166425] TCP established hash table entries: 1024 (order: 1, 8192 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.776318217Z] [    0.168050] TCP bind hash table entries: 1024 (order: 2, 16384 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.777638545Z] [    0.169550] TCP: Hash tables configured (established 1024 bind 1024)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.778865968Z] [    0.170901] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.780328588Z] [    0.172104] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.781306298Z] [    0.173601] NET: Registered protocol family 1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.785214185Z] [    0.176698] virtio-mmio: Registering device virtio-mmio.0 at 0xd0000000-0xd0000fff, IRQ 5.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.786997340Z] [    0.178470] virtio-mmio: Registering device virtio-mmio.1 at 0xd0001000-0xd0001fff, IRQ 6.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.788731439Z] [    0.180258] virtio-mmio: Registering device virtio-mmio.2 at 0xd0002000-0xd0002fff, IRQ 7.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.790864605Z] [    0.182005] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x23eb59c9ee2, max_idle_ns: 440795321417 ns  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.792154339Z] [    0.184312] clocksource: Switched to clocksource tsc  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.793544606Z] [    0.185404] platform rtc_cmos: registered platform RTC device (no PNP device found)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.794953300Z] [    0.186995] check: Scanning for low memory corruption every 60 seconds  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.796182640Z] [    0.188610] Initialise system trusted keyrings  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.796939685Z] [    0.189408] Key type blacklist registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.798571118Z] [    0.190635] workingset: timestamp_bits=36 max_order=15 bucket_order=0  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.801135999Z] [    0.193277] squashfs: version 4.0 (2009/01/31) Phillip Lougher  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.811956567Z] [    0.204309] Key type asymmetric registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.813003170Z] [    0.205180] Asymmetric key parser 'x509' registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.814551126Z] [    0.206246] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.816576248Z] [    0.208454] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.818358419Z] [    0.209983] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.821394427Z] [    0.213989] loop: module loaded            jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.823421887Z] [    0.214973] virtio_blk virtio0: [vda] 136656 512-byte logical blocks (70.0 MB/66.7 MiB)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.824480548Z] [    0.216683] vda: detected capacity change from 0 to 69967872  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.827581987Z] [    0.219307] virtio_blk virtio1: [vdb] 1 512-byte logical blocks (512 B/512 B)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.828553692Z] [    0.220836] vdb: detected capacity change from 0 to 512  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.830091960Z] [    0.222301] Loading iSCSI transport class v2.0-870.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.831464193Z] [    0.223918] iscsi: registered transport (tcp)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.832406174Z] [    0.224704] tun: Universal TUN/TAP device driver, 1.6  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.833557986Z] [    0.225749] i8042: PNP: No PS/2 controller found.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.834420319Z] [    0.226784] i8042: Probing ports directly.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.843512007Z] [    0.235336] i8042: Failed to disable AUX port, but continuing anyway... Is this a SiS?  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:35.844869930Z] [    0.236742] i8042: If AUX port is really absent please use the 'i8042.noaux' option  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.102758831Z] [    0.492297] serio: i8042 KBD port at 0x60,0x64 irq 1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.107322299Z] [    0.496856] intel_pstate: CPU model not supported  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.109423664Z] [    0.500675] hid: raw HID events driver (C) Jiri Kosina  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.110573578Z] [    0.502893] Initializing XFRM netlink socket  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.111618096Z] [    0.503932] NET: Registered protocol family 10  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.113128784Z] [    0.505561] Segment Routing with IPv6      jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.114030749Z] [    0.506348] NET: Registered protocol family 17  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.114769102Z] [    0.507280] Bridge firewalling registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.115794209Z] [    0.508083] NET: Registered protocol family 40  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.117148544Z] [    0.509567] IPI shorthand broadcast: enabled  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.118790726Z] [    0.510409] sched_clock: Marking stable (407429414, 100553820)->(547861254, -39878020)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.119039138Z]                                               attempt=1 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.119990646Z] [    0.512360] registered taskstats version 1  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.120991779Z] [    0.513239] Loading compiled-in X.509 certificates  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.121179320Z]                                               attempt=2 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.124033736Z] [    0.515281] Loaded X.509 cert 'Build time autogenerated kernel key: 015b21f05826d978da2bf8149cb6b79f2ddaae54'  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.124961189Z] [    0.517345] Key type ._fscrypt registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.125758928Z] [    0.518175] Key type .fscrypt registered   jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.126764990Z] [    0.518975] Key type fscrypt-provisioning registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.127747347Z] [    0.520184] Key type encrypted registered  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.163209867Z]                                               attempt=3 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.262857930Z]                                               attempt=4 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.363473061Z]                                               attempt=5 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.463456912Z]                                               attempt=6 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.563356375Z]                                               attempt=7 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.618434448Z] [    1.005345] input: AT Raw Set 2 keyboard as /devices/platform/i8042/serio0/input/input0  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.623218125Z] [    1.014883] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.624261840Z] [    1.016826] devtmpfs: mounted              jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.625595291Z] [    1.017883] Freeing unused decrypted memory: 2036K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.627340298Z] [    1.019286] Freeing unused kernel image (initmem) memory: 1420K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.631563336Z] [    1.023695] Write protecting the kernel read-only data: 14336k  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.634291555Z] [    1.026112] Freeing unused kernel image (text/rodata gap) memory: 2044K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.635903763Z] [    1.027741] Freeing unused kernel image (rodata/data gap) memory: 180K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.636784138Z] [    1.029116] Run /sbin/overlay-init as init process  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.663070348Z]                                               attempt=8 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.752661930Z] SELinux:  Could not open policy file <= /etc/selinux/targeted/policy/policy.33:  No such file or directory  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.762227726Z]                                               attempt=9 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.764841544Z] [    1.156335] systemd[1]: Failed to look up module alias 'autofs4': Function not implemented  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.765778383Z] [    1.158250] random: fast init done         jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.777449545Z] [    1.164529] systemd[1]: systemd 250.3-2 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.778479063Z] [    1.170762] systemd[1]: Detected virtualization kvm.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.779436246Z] [    1.171727] systemd[1]: Detected architecture x86-64.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.780845589Z]                                               jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.781771967Z] Welcome to Debian GNU/Linux bookworm/sid!  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.781912072Z]                                               jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.783115954Z] [    1.175297] systemd[1]: Hostname set to <microvm>.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.862738071Z]                                               attempt=10 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.883861898Z] [    1.274890] systemd[483]: /usr/lib/systemd/system-generators/systemd-gpt-auto-generator failed with exit status 1.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.938290097Z] [    1.329818] systemd[1]: Queued start job for default target Firecracker containerd VM.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.939940401Z] [    1.331764] random: systemd: uninitialized urandom read (16 bytes read)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.944818444Z] [    1.336731] systemd[1]: Created slice Slice /system/modprobe.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.946572428Z] [  OK  ] Created slice Slice /system/modprobe.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.948114650Z] [    1.339926] random: systemd: uninitialized urandom read (16 bytes read)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.950094095Z] [    1.341410] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.951507378Z] [  OK  ] Started Dispatch Password …ts to Console Directory Watch.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.953436452Z] [    1.344864] systemd[1]: Starting of Arbitrary Executable File Formats File System Automount Point unsupported.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.955560767Z] [UNSUPP] Starting of Arbitrary Exec…m Automount Point unsupported.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.957053198Z] [    1.348883] random: systemd: uninitialized urandom read (16 bytes read)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.958309070Z] [    1.350252] systemd[1]: Reached target Local Encrypted Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.959921090Z] [  OK  ] Reached target Local Encrypted Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.961502753Z] [    1.353247] systemd[1]: Reached target Local Integrity Protected Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.961711363Z]                                               attempt=11 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:36.963528539Z] [  OK  ] Reached target Local Integrity Protected Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.964722798Z] [    1.356860] systemd[1]: Reached target Path Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.966026875Z] [  OK  ] Reached target Path Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.967028234Z] [    1.359353] systemd[1]: Reached target Slice Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.968494215Z] [  OK  ] Reached target Slice Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.969539917Z] [    1.361832] systemd[1]: Reached target Swaps.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.970846993Z] [  OK  ] Reached target Swaps.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.972352456Z] [    1.364179] systemd[1]: Reached target Local Verity Protected Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.974162617Z] [  OK  ] Reached target Local Verity Protected Volumes.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.975759088Z] [    1.367582] systemd[1]: Listening on initctl Compatibility Named Pipe.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.977382804Z] [  OK  ] Listening on initctl Compatibility Named Pipe.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.979500850Z] [    1.371514] systemd[1]: Listening on Journal Audit Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.981017171Z] [  OK  ] Listening on Journal Audit Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.982570946Z] [    1.374493] systemd[1]: Listening on Journal Socket (/dev/log).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.984156495Z] [  OK  ] Listening on Journal Socket (/dev/log).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.985533406Z] [    1.377674] systemd[1]: Listening on Journal Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.986910497Z] [  OK  ] Listening on Journal Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.989121187Z] [    1.381131] systemd[1]: Listening on udev Control Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.990635019Z] [  OK  ] Listening on udev Control Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.991961483Z] [    1.384099] systemd[1]: Listening on udev Kernel Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.993465282Z] [  OK  ] Listening on udev Kernel Socket.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.994631112Z] [    1.386785] systemd[1]: Reached target Socket Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.996054097Z] [  OK  ] Reached target Socket Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.998473944Z] [    1.390471] systemd[1]: Mounting Huge Pages File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:36.999707164Z]          Mounting Huge Pages File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.003903172Z] [    1.395760] systemd[1]: Mounting POSIX Message Queue File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.005267702Z]          Mounting POSIX Message Queue File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.012928526Z] [    1.404907] systemd[1]: Mounting Kernel Debug File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.014137226Z]          Mounting Kernel Debug File System...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.025299380Z] [    1.415883] systemd[1]: Kernel Trace File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/tracing).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.028405290Z] [    1.418545] systemd[1]: Create List of Static Device Nodes was skipped because of a failed condition check (ConditionFileNotEmpty=/lib/modules/5.10.0/modules.devname).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.030775411Z] [    1.422762] systemd[1]: Starting Load Kernel Module configfs...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.032092906Z]          Starting Load Kernel Module configfs...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.035191772Z] [    1.427180] systemd[1]: Starting Load Kernel Module fuse...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.036380256Z]          Starting Load Kernel Module fuse...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.039959081Z] [    1.432074] systemd[1]: Starting Journal Service...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.041104630Z]          Starting Journal Service...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.049340083Z] [    1.441393] systemd[1]: Starting Load Kernel Modules...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.050557109Z]          Starting Load Kernel Modules...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.062133291Z]                                               attempt=12 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.068043465Z] [    1.459825] systemd[1]: Starting Remount Root and Kernel File Systems...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.069602999Z]          Starting Remount Root and Kernel File Systems...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.080568502Z] [    1.471821] systemd[1]: Repartition Root Disk was skipped because all trigger condition checks failed.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.085288073Z] [    1.477408] systemd[1]: Starting Coldplug All udev Devices...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.086633352Z]          Starting Coldplug All udev Devices...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.097878664Z] [    1.489958] systemd[1]: Mounted Huge Pages File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.099367571Z] [  OK  ] Mounted Huge Pages File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.108582934Z] [    1.500628] systemd[1]: Mounted POSIX Message Queue File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.110287619Z] [  OK  ] Mounted POSIX Message Queue File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.116209216Z] [    1.406256] systemd[500]: modprobe@configfs.service: Executable /sbin/modprobe missing, skipping: No such file or directory  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.118579409Z] [    1.510781] systemd[1]: Started Journal Service.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.120296177Z] [  OK  ] Started Journal Service.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.122318727Z] [  OK  ] Mounted Kernel Debug File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.129435442Z] [    1.419735] systemd[501]: modprobe@fuse.service: Executable /sbin/modprobe missing, skipping: No such file or directory  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.131654054Z] [  OK  ] Finished Load Kernel Module configfs.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.133926435Z] [  OK  ] Finished Load Kernel Module fuse.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.136419552Z] [    1.427679] systemd[1]: Mounted Kernel Debug File System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.139580242Z] [  OK  ] Finished Load Kernel Modules.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.143641140Z] [    1.434514] systemd[1]: modprobe@configfs.service: Deactivated successfully.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.148204506Z] [  OK  ] Finished Remount Root and Kernel File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.154796309Z] [    1.445878] systemd[1]: Finished Load Kernel Module configfs.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.156737265Z] [    1.447796] systemd[1]: modprobe@fuse.service: Deactivated successfully.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.162256582Z]                                               attempt=13 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.163968103Z]          Starting Flush Journal to Persistent Storage...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.165730223Z] [    1.457050] systemd[1]: Finished Load Kernel Module fuse.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.179380362Z] [    1.570906] systemd-journald[502]: Received client request to flush runtime journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.180913279Z]          Starting Load/Save Random Seed...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.191863647Z]          Starting Apply Kernel Variables...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.213627891Z]          Starting Create System Users...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.224445372Z] [    1.515709] systemd[1]: Finished Load Kernel Modules.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.226768229Z] [  OK  ] Finished Flush Journal to Persistent Storage.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.229657375Z] [    1.520692] systemd[1]: Finished Remount Root and Kernel File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.235586414Z] [  OK  ] Finished Apply Kernel Variables.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.238768510Z] [    1.528653] systemd[1]: FUSE Control File System was skipped because of a failed condition check (ConditionPathExists=/sys/fs/fuse/connections).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.248724918Z] [FAILED] Failed to start Create System Users.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.249886062Z] See 'systemctl status systemd-sysusers.service' for details.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.255041128Z] [    1.544724] systemd[1]: Kernel Configuration File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/config).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.261080235Z] [  OK  ] Finished Coldplug All udev Devices.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.262616680Z]                                               attempt=14 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.264588389Z] [    1.555546] systemd[1]: Starting Flush Journal to Persistent Storage...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.266216837Z]          Starting Create Static Device Nodes in /dev...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.269713196Z] [    1.559405] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.279398111Z] [    1.570587] systemd[1]: Starting Load/Save Random Seed...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.281369651Z] [    1.572494] systemd[1]: Starting Apply Kernel Variables...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.283960198Z] [    1.574468] systemd-random-seed[593]: Kernel entropy pool is not initialized yet, waiting until it is.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.287939170Z] [    1.579274] systemd[1]: Starting Create System Users...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.291363342Z] [    1.582342] systemd[1]: Finished Flush Journal to Persistent Storage.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.294730472Z] [    1.585897] systemd[1]: Finished Apply Kernel Variables.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.299238291Z] [  OK  ] Finished Create Static Device Nodes in /dev.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.301277175Z] [  OK  ] Reached target Preparation for Local File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.303426055Z] [    1.594228] systemd-sysusers[596]: Failed to take /etc/passwd lock: No data available  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.305077741Z] [  OK  ] Reached target Local File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.307501639Z] [    1.598104] systemd[1]: systemd-sysusers.service: Main process exited, code=exited, status=1/FAILURE  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.310654702Z]          Starting Create Volatile Files and Directories...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.312679716Z] [    1.603544] systemd[1]: systemd-sysusers.service: Failed with result 'exit-code'.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.314253595Z] [    1.605494] systemd[1]: Failed to start Create System Users.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.316428091Z] [    1.607041] systemd[1]: run-credentials-systemd\x2dsysusers.service.mount: Deactivated successfully.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.328343357Z]          Starting Rule-based Manage…for Device Events and Files...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.332306054Z] [    1.623365] systemd[1]: Finished Coldplug All udev Devices.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.336584860Z] [    1.627325] systemd[1]: Starting Create Static Device Nodes in /dev...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.345292382Z] [    1.636376] systemd[1]: Finished Create Static Device Nodes in /dev.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.348780913Z] [    1.639767] systemd[1]: Reached target Preparation for Local File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.360056446Z] [    1.651338] systemd[1]: Reached target Local File Systems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.362432137Z] [    1.652897] systemd[1]: Set Up Additional Binary Formats was skipped because all trigger condition checks failed.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.362622992Z]                                               attempt=15 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.365253610Z] [  OK  ] Finished Create Volatile Files and Directories.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.368321115Z] [    1.659354] systemd[1]: Starting Create Volatile Files and Directories...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.372521933Z] [  OK  ] Started Entropy Daemon based on the HAVEGE algorithm.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.374661578Z] [    1.665460] systemd[1]: Starting Rule-based Manager for Device Events and Files...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.389688304Z] [    1.679473] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/lib (owned by root) during canonicalization of /var/lib.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.391370489Z]          Starting Record System Boot/Shutdown in UTMP...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.409776257Z] [    1.699316] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/lib (owned by root) during canonicalization of /var/lib/systemd.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.418352752Z] [    1.707985] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/lib (owned by root) during canonicalization of /var/lib/systemd.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.422177322Z] [FAILED] Failed to start Record System Boot/Shutdown in UTMP.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.427798891Z] See 'systemctl status systemd-update-utmp.service' for details.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.433650465Z] [    1.723216] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/lib (owned by root) during canonicalization of /var/lib.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.441805392Z] [    1.731449] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.449722895Z] [    1.739369] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/cache (owned by root) during canonicalization of /var/cache.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.458882075Z] [    1.748616] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.462428637Z]                                               attempt=16 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.468320365Z] [  OK  ] Started Rule-based Manager for Device Events and Files.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.470136923Z] [  OK  ] Reached target System Initialization.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.471968662Z] [  OK  ] Started Daily dpkg database backup timer.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.477691442Z] [    1.767313] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.479635406Z] [    1.770738] haveged[739]: haveged: command socket is listening at fd 3  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.488670356Z] [  OK  ] Started Periodic ext4 Onli…ata Check for All Filesystems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.490587480Z] [  OK  ] Started Discard unused blocks once a week.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.493726178Z] [    1.783503] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.496866470Z] [    1.786507] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.500411512Z] [  OK  ] Started Daily Cleanup of Temporary Directories.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.501964581Z] [  OK  ] Reached target Basic System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.503608961Z] [  OK  ] Reached target Timer Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.511894760Z] [    1.801456] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.518931972Z] [    1.808415] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.525873215Z] [  OK  ] Started Firecracker VM agent.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.527794129Z] [  OK  ] Reached target Firecracker containerd VM.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.534001819Z] [    1.822975] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal/cc4b38f03d7b4b56a400082914fd3785.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.541519588Z] [    1.830509] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal/cc4b38f03d7b4b56a400082914fd3785.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.551174842Z] [    1.840207] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal/cc4b38f03d7b4b56a400082914fd3785.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.563972599Z] [    1.852691] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal/cc4b38f03d7b4b56a400082914fd3785/system.journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.564140489Z]                                               attempt=17 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.579785651Z] [    1.868647] systemd-tmpfiles[737]: Detected unsafe path transition /var (owned by 1000) → /var/log (owned by root) during canonicalization of /var/log/journal/cc4b38f03d7b4b56a400082914fd3785/system.journal.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.590973646Z] [    1.881980] systemd[1]: Finished Create Volatile Files and Directories.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.600459829Z] [    1.891379] systemd[1]: Started Entropy Daemon based on the HAVEGE algorithm.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.606487060Z] [    1.897460] systemd[1]: Starting Record System Boot/Shutdown in UTMP...  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.614794042Z] [    1.905487] systemd-update-utmp[742]: Failed to write utmp record: No data available  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.620821668Z] [    1.911323] systemd[1]: systemd-update-utmp.service: Main process exited, code=exited, status=1/FAILURE  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.629293038Z] [    1.920062] systemd[1]: systemd-update-utmp.service: Failed with result 'exit-code'.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.638087991Z] [    1.929010] systemd[1]: Failed to start Record System Boot/Shutdown in UTMP.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.644320221Z] [    1.935272] systemd[1]: Started Rule-based Manager for Device Events and Files.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.652154766Z] [    1.943294] systemd[1]: Reached target System Initialization.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.659205835Z] [    1.950242] systemd[1]: Started Daily dpkg database backup timer.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.662674121Z]                                               attempt=18 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.665801640Z] [    1.956599] systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.672478371Z] [    1.963569] systemd[1]: Started Discard unused blocks once a week.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.680339864Z] [    1.971338] systemd[1]: Started Daily Cleanup of Temporary Directories.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.687379702Z] [    1.978660] systemd[1]: Reached target Basic System.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.690069968Z] [    1.981418] systemd[1]: Reached target Timer Units.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.699962364Z] [    1.991255] systemd[1]: Started Firecracker VM agent.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.702588206Z] [    1.993684] systemd[1]: Reached target Firecracker containerd VM.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.762461436Z]                                               attempt=19 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.862168517Z]                                               attempt=20 error="temporary vsock dial failure: vsock ack message failure: failed to read \"OK <port>\" within 1s: EOF" runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.872217003Z] [    2.162776] agent[753]: time="2022-02-05T17:23:37Z" level=info msg="creating task service"  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
INFO[2022-02-05T17:23:37.961797870Z] successfully started the VM                   runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.961910844Z] event published                               ns=default runtime=aws.firecracker topic=/firecracker-vm/start type=VMStart
DEBU[2022-02-05T17:23:37.962338350Z] event forwarded                               ns=default topic=/firecracker-vm/start type=VMStart
time="2022-02-05T17:23:37.962386315Z" level=info msg="successfully started shim (git commit: f4f8c99fd90934125b8266ea040fadc1d2b26ad5). The VM will be torn down after serving a single task." runtime=aws.firecracker task_id=busybox-test vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.963578667Z] creating task                                 bundle=/run/firecracker-containerd/io.containerd.runtime.v2.task/default/busybox-test checkpoint= runtime=aws.firecracker stderr= stdin=/run/containerd/fifo/24667898/busybox-test-stdin stdout=/run/containerd/fifo/24667898/busybox-test-stdout task_id=busybox-test terminal=true vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:37.963821377Z] noop operation for ExposeFileToJail           jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
INFO[2022-02-05T17:23:37.964347742Z] PatchGuestDrive successful                    runtime=aws.firecracker
DEBU[2022-02-05T17:23:37.967041064Z] [    2.357489] virtio_blk virtio1: [vdb] new size: 20971520 512-byte logical blocks (10.7 GB/10.0 GiB)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:37.968340953Z] [    2.360284] vdb: detected capacity change from 512 to 10737418240  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.002960525Z] [    2.394512] EXT4-fs (vdb): mounted filesystem with ordered data mode. Opts: (null)  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.004849143Z] noop operation returning shim dir for JailPath  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:38.005014228Z] skipping proxy io for unset stderr            ExecID= TaskID=busybox-test runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:38.007889017Z] [    2.298180] agent[753]: time="2022-02-05T17:23:37Z" level=info msg=create ExecID= TaskID=busybox-test  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.023740934Z] [    2.313950] haveged[739]: haveged: ver: 1.9.14; arch: x86; vend: GenuineIntel; build: (gcc 10.2.1 ITV); collect: 128K  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.027228525Z] [    2.317464] haveged[739]: haveged: cpu: (L4 VC); data: 32K (L4 V); inst: 32K (L4 V); idx: 24/40; sz: 32154/54019  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.032855820Z] [    2.323155] haveged[739]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B):  last entropy estimate 8.00019  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.036820088Z] [    2.328076] haveged[739]: haveged: fills: 0, generated: 0  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.047190473Z] [    2.439589] random: crng init done         jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.048481349Z] [    2.440355] random: 7 urandom warning(s) missed due to ratelimiting  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.050875414Z] [  OK  ] Finished Load/Save Random Seed.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.052468396Z] [    2.343761] systemd[1]: Finished Load/Save Random Seed.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.055520585Z] [    2.345678] systemd[1]: First Boot Complete was skipped because of a failed condition check (ConditionFirstBoot=yes).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.060842589Z] [    2.349535] systemd[1]: Store a System Token in an EFI Variable was skipped because of a failed condition check (ConditionPathExists=/sys/firmware/efi/efivars/LoaderFeatures-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.068238206Z] [    2.357784] systemd[1]: Commit a transient machine-id on disk was skipped because of a failed condition check (ConditionPathIsMountPoint=/etc/machine-id).  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.074174416Z] [    2.364818] systemd[1]: Startup finished in 1.029s (kernel) + 1.318s (userspace) = 2.348s.  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.106266763Z] begin copying io                              ExecID= TaskID=busybox-test runtime=aws.firecracker stream=stdout vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:38.106273761Z] begin copying io                              ExecID= TaskID=busybox-test runtime=aws.firecracker stream=stdin vmID=b629ce49-3901-45f4-b77d-2a9235086345
INFO[2022-02-05T17:23:38.169865324Z] successfully created task                     ExecID= TaskID=busybox-test pid_in_vm=773 runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345
DEBU[2022-02-05T17:23:38.169941200Z] event forwarded                               ns=default topic=/tasks/create type=containerd.events.TaskCreate
DEBU[2022-02-05T17:23:38.170223378Z] event forwarded                               ns=default topic=/tasks/create type=containerd.events.TaskCreate
DEBU[2022-02-05T17:23:38.170846702Z] start                                         exec_id= runtime=aws.firecracker task_id=busybox-test
DEBU[2022-02-05T17:23:38.170838512Z] wait                                          exec_id= runtime=aws.firecracker task_id=busybox-test
DEBU[2022-02-05T17:23:38.172847688Z] [    2.462656] agent[753]: time="2022-02-05T17:23:38Z" level=info msg="successfully created task" ExecID= TaskID=busybox-test pid_in_vm=773  jailer=noop runtime=aws.firecracker vmID=b629ce49-3901-45f4-b77d-2a9235086345 vmm_stream=stdout
DEBU[2022-02-05T17:23:38.184409112Z] event forwarded                               ns=default topic=/tasks/start type=containerd.events.TaskStart
DEBU[2022-02-05T17:23:38.184422970Z] state                                         exec_id= runtime=aws.firecracker task_id=busybox-test
DEBU[2022-02-05T17:23:38.184691586Z] event forwarded                               ns=default topic=/tasks/start type=containerd.events.TaskStart
DEBU[2022-02-05T17:23:38.185661856Z] proxy is still alive                          exec_id= runtime=aws.firecracker task_id=busybox-test
DEBU[2022-02-05T17:23:38.186243153Z] resize_pty                                    exec_id= runtime=aws.firecracker task_id=busybox-test