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
も実行しておきます。
これで下記の3つのバイナリが/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