search

kata-containers / runtime

Kata Containers version 1.x runtime (for version 2.x see https://github.com/kata-containers/kata-containers).
https://katacontainers.io/
Apache License 2.0
2.1k stars 375 forks source link

Inject entropy into kata container #445

Closed jcvenegas closed 6 years ago

jcvenegas commented 6 years ago

Description of problem

The entropy inside a kata container is too low

Expected result

Have a better entropy level. See the difference between runc and kata below.

Actual result

host
$ cat /proc/sys/kernel/random/entropy_avail
3089
runc
$ docker run --runtime runc -ti busybox cat /proc/sys/kernel/random/entropy_avail
3093
kata
$docker run --runtime kata-runtime -ti busybox cat /proc/sys/kernel/random/entropy_avail
7

We should consider add a VirtIORNG or a daemon to increase the entropy inside the container.

jcvenegas commented 6 years ago

I tested adding a virtio-rng-pci device. update: https://github.com/jcvenegas/runtime-1/commit/18800fd56dc86e6f6b16a4994b8d3c63c3a8fbc2

but I see the container boot hangs the last call by the kernel is calling virtio_rng_driver_init then I dont see any traces 

level=info msg="time=\"2018-06-27T21:00:31.286175957Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"hostname:\\\"97b0e654fa2d\\\" storages:<driver:\\\"9p\\\" source:\\\"kataShared\\\" fstype:\\\"9p\\\" options:\\\"trans=virtio,version=9p2000.L\\\" options:\\\"nodev\\\" options:\\\"msize=8192\\\" mount_point:\\\"/run/kata-containers/shared/containers/\\\" > storages:<driver:\\\"ephemeral\\\" source:\\\"shm\\\" fstype:\\\"tmpfs\\\" options:\\\"noexec\\\" options:\\\"nosuid\\\" options:\\\"nodev\\\" options:\\\"mode=1777\\\" options:\\\"size=67108864\\\" mount_point:\\\"/run/kata-containers/sandbox/shm\\\" > \" request=/grpc.AgentService/CreateSandbox source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.294158507Z\" level=debug mount-destination=/run/kata-containers/shared/containers/ mount-flags=4 mount-fstype=9p mount-options=\"trans=virtio,version=9p2000.L,msize=8192\" mount-source=kataShared name=kata-agent pid=97 source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.299747104Z\" level=debug mount-destination=/run/kata-containers/sandbox/shm mount-flags=14 mount-fstype=tmpfs mount-options=\"mode=1777,size=67108864\" mount-source=shm name=kata-agent pid=97 source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.301868507Z\" level=debug msg=\"request end\" duration=15.364815ms name=kata-agent pid=97 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.336357522Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" OCI:<Version:\\\"1.0.1\\\" Process:<Terminal:true User:<AdditionalGids:10 > Args:\\\"sh\\\" Env:\\\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\\\" Env:\\\"HOSTNAME=97b0e654fa2d\\\" Env:\\\"TERM=xterm\\\" Env:\\\"HTTP_PROXY=http://proxy-chain.intel.com:911\\\" Env:\\\"http_proxy=http://proxy-chain.intel.com:911\\\" Env:\\\"HTTPS_PROXY=http://proxy-chain.intel.com:912\\\" Env:\\\"https_proxy=http://proxy-chain.intel.com:912\\\" Env:\\\"NO_PROXY=.intel.com,10.0.2.15,10.0.2.2,127.0.0.1,127.3.232.2,intel.com,kernel,localhost\\\" Env:\\\"no_proxy=.intel.com,10.0.2.15,10.0.2.2,127.0.0.1,127.3.232.2,intel.com,kernel,localhost\\\" Cwd:\\\"/\\\" Capabilities:<Bounding:\\\"CAP_CHOWN\\\" Bounding:\\\"CAP_DAC_OVERRIDE\\\" Bounding:\\\"CAP_FSETID\\\" Bounding:\\\"CAP_FOWNER\\\" Bounding:\\\"CAP_MKNOD\\\" Bounding:\\\"CAP_NET_RAW\\\" Bounding:\\\"CAP_SETGID\\\" Bounding:\\\"CAP_SETUID\\\" Bounding:\\\"CAP_SETFCAP\\\" Bounding:\\\"CAP_SETPCAP\\\" Bounding:\\\"CAP_NET_BIND_SERVICE\\\" Bounding:\\\"CAP_SYS_CHROOT\\\" Bounding:\\\"CAP_KILL\\\" Bounding:\\\"CAP_AUDIT_WRITE\\\" Effective:\\\"CAP_CHOWN\\\" Effective:\\\"CAP_DAC_OVERRIDE\\\" Effective:\\\"CAP_FSETID\\\" Effective:\\\"CAP_FOWNER\\\" Effective:\\\"CAP_MKNOD\\\" Effective:\\\"CAP_NET_RAW\\\" Effective:\\\"CAP_SETGID\\\" Effective:\\\"CAP_SETUID\\\" Effective:\\\"CAP_SETFCAP\\\" Effective:\\\"CAP_SETPCAP\\\" Effective:\\\"CAP_NET_BIND_SERVICE\\\" Effective:\\\"CAP_SYS_CHROOT\\\" Effective:\\\"CAP_KILL\\\" Effective:\\\"CAP_AUDIT_WRITE\\\" Inheritable:\\\"CAP_CHOWN\\\" Inheritable:\\\"CAP_DAC_OVERRIDE\\\" Inheritable:\\\"CAP_FSETID\\\" Inheritable:\\\"CAP_FOWNER\\\" Inheritable:\\\"CAP_MKNOD\\\" Inheritable:\\\"CAP_NET_RAW\\\" Inheritable:\\\"CAP_SETGID\\\" Inheritable:\\\"CAP_SETUID\\\" Inheritable:\\\"CAP_SETFCAP\\\" Inheritable:\\\"CAP_SETPCAP\\\" Inheritable:\\\"CAP_NET_BIND_SERVICE\\\" Inheritable:\\\"CAP_SYS_CHROOT\\\" Inheritable:\\\"CAP_KILL\\\" Inheritable:\\\"CAP_AUDIT_WRITE\\\" Permitted:\\\"CAP_CHOWN\\\" Permitted:\\\"CAP_DAC_OVERRIDE\\\" Permitted:\\\"CAP_FSETID\\\" Permitted:\\\"CAP_FOWNER\\\" Permitted:\\\"CAP_MKNOD\\\" Permitted:\\\"CAP_NET_RAW\\\" Permitted:\\\"CAP_SETGID\\\" Permitted:\\\"CAP_SETUID\\\" Permitted:\\\"CAP_SETFCAP\\\" Permitted:\\\"CAP_SETPCAP\\\" Permitted:\\\"CAP_NET_BIND_SERVICE\\\" Permitted:\\\"CAP_SYS_CHROOT\\\" Permitted:\\\"CAP_KILL\\\" Permitted:\\\"CAP_AUDIT_WRITE\\\" > ApparmorProfile:\\\"docker-default\\\" > Root:<Path:\\\"/run/kata-containers/shared/containers/97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1/rootfs\\\" > Hostname:\\\"97b0e654fa2d\\\" Mounts:<destination:\\\"/proc\\\" source:\\\"proc\\\" type:\\\"proc\\\" options:\\\"nosuid\\\" options:\\\"noexec\\\" options:\\\"nodev\\\" > Mounts:<destination:\\\"/dev\\\" source:\\\"tmpfs\\\" type:\\\"tmpfs\\\" options:\\\"nosuid\\\" options:\\\"strictatime\\\" options:\\\"mode=755\\\" options:\\\"size=65536k\\\" > Mounts:<destination:\\\"/dev/pts\\\" source:\\\"devpts\\\" type:\\\"devpts\\\" options:\\\"nosuid\\\" options:\\\"noexec\\\" options:\\\"newinstance\\\" options:\\\"ptmxmode=0666\\\" options:\\\"mode=0620\\\" options:\\\"gid=5\\\" > Mounts:<destination:\\\"/sys\\\" source:\\\"sysfs\\\" type:\\\"sysfs\\\" options:\\\"nosuid\\\" options:\\\"noexec\\\" options:\\\"nodev\\\" options:\\\"ro\\\" > Mounts:<destination:\\\"/sys/fs/cgroup\\\" source:\\\"cgroup\\\" type:\\\"cgroup\\\" options:\\\"ro\\\" options:\\\"nosuid\\\" options:\\\"noexec\\\" options:\\\"nodev\\\" > Mounts:<destination:\\\"/dev/mqueue\\\" source:\\\"mqueue\\\" type:\\\"mqueue\\\" options:\\\"nosuid\\\" options:\\\"noexec\\\" options:\\\"nodev\\\" > Mounts:<destination:\\\"/etc/resolv.conf\\\" source:\\\"/run/kata-containers/shared/containers/97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1-ddf55bd9a5f809c9-resolv.conf\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/etc/hostname\\\" source:\\\"/run/kata-containers/shared/containers/97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1-a933d6bcb2b25a1e-hostname\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/etc/hosts\\\" source:\\\"/run/kata-containers/shared/containers/97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1-b1f3b2788747cbc8-hosts\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/dev/shm\\\" source:\\\"/run/kata-containers/sandbox/shm\\\" type:\\\"bind\\\" options:\\\"rbind\\\" > Linux:<Resources:<CPU:<> > CgroupsPath:\\\"/docker/97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" Namespaces:<Type:\\\"mount\\\" > Namespaces:<Type:\\\"uts\\\" > Namespaces:<Type:\\\"ipc\\\" > MaskedPaths:\\\"/proc/kcore\\\" MaskedPaths:\\\"/proc/keys\\\" MaskedPaths:\\\"/proc/latency_stats\\\" MaskedPaths:\\\"/proc/timer_list\\\" MaskedPaths:\\\"/proc/timer_stats\\\" MaskedPaths:\\\"/proc/sched_debug\\\" MaskedPaths:\\\"/proc/scsi\\\" MaskedPaths:\\\"/sys/firmware\\\" ReadonlyPaths:\\\"/proc/asound\\\" ReadonlyPaths:\\\"/proc/bus\\\" ReadonlyPaths:\\\"/proc/fs\\\" ReadonlyPaths:\\\"/proc/irq\\\" ReadonlyPaths:\\\"/proc/sys\\\" ReadonlyPaths:\\\"/proc/sysrq-trigger\\\" > > \" request=/grpc.AgentService/CreateContainer source=agent\n" name=kata-proxy pid=32493 source=agent
level=info msg="[    1.482721] pci 0000:00:02.0: PCI bridge to [bus 01]\n" name=kata-proxy pid=32493 source=agent
 level=info msg="[    1.483338] pci 0000:00:02.0:   bridge window [io  0xc000-0xcfff]\n" name=kata-proxy pid=32493 source=agent
 level=info msg="[    1.485374] pci 0000:00:02.0:   bridge window [mem 0xfe600000-0xfe7fffff]\n" name=kata-proxy pid=32493 source=agent
level=info msg="[    1.486781] pci 0000:00:02.0:   bridge window [mem 0xfea00000-0xfebfffff 64bit pref]\n" name=kata-proxy pid=32493 source=agent
level=info msg="time=\"2018-06-27T21:00:31.423813504Z\" level=debug msg=\"request end\" duration=86.829353ms name=kata-agent pid=97 request=/grpc.AgentService/CreateContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.424470024Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=97 signal=\"child exited\" source=agent\n" name=kata-proxy pid=32493 source=agent
level=info msg="time=\"2018-06-27T21:00:31.456476586Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" \" request=/grpc.AgentService/TtyWinResize source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.460206943Z\" level=debug msg=\"request end\" duration=\"34.631µs\" name=kata-agent pid=97 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.469949625Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" len:32768 \" request=/grpc.AgentService/ReadStdout source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.495934668Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" \" request=/grpc.AgentService/StartContainer source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.513767669Z\" level=debug msg=\"request end\" duration=17.460131ms name=kata-agent pid=97 request=/grpc.AgentService/StartContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.521995598Z\" level=debug msg=\"request end\" duration=51.737837ms name=kata-agent pid=97 request=/grpc.AgentService/ReadStdout resp=\"data:\\\"/ # \\\" \" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.533373561Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" len:32768 \" request=/grpc.AgentService/ReadStdout source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.571141166Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" row:36 column:271 \" request=/grpc.AgentService/TtyWinResize source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.571476086Z\" level=debug msg=\"request end\" duration=\"80.797µs\" name=kata-agent pid=97 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.573362677Z\" level=debug msg=\"request end\" duration=38.862301ms name=kata-agent pid=97 request=/grpc.AgentService/ReadStdout resp=\"data:\\\"\\\\r/ # \\\\033[J\\\" \" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:00:31.575795011Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" len:32768 \" request=/grpc.AgentService/ReadStdout source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.23076555Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" data:\\\"\\\\004\\\" \" request=/grpc.AgentService/WriteStdin source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.231339358Z\" level=debug msg=\"request end\" duration=\"235.586µs\" name=kata-agent pid=97 request=/grpc.AgentService/WriteStdin resp=\"len:1 \" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.235330014Z\" level=debug msg=\"request end\" duration=33.658971553s error=\"read /dev/ptmx: input/output error\" name=kata-agent pid=97 request=/grpc.AgentService/ReadStdout resp= source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.236308013Z\" level=debug msg=\"process exited\" name=kata-agent pid=129 source=agent status=0\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.237651611Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=97 signal=\"child exited\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.239190617Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" exec_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" \" request=/grpc.AgentService/WaitProcess source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.240958298Z\" level=debug msg=\"request end\" duration=1.447061ms name=kata-agent pid=97 request=/grpc.AgentService/WaitProcess resp= source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.262644449Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" signal:9 \" request=/grpc.AgentService/SignalProcess source=agent\n" name=kata-proxy pid=32493 source=agent
level=info msg="time=\"2018-06-27T21:01:05.265775677Z\" level=info msg=\"discarding signal as container stopped\" containerID=97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1 name=kata-agent pid=97 sandbox=97b0e654fa2d signal=killed source=agent\n" name=kata-proxy pid=32493 source=agent
level=info msg="time=\"2018-06-27T21:01:05.266695077Z\" level=debug msg=\"request end\" duration=1.530976ms name=kata-agent pid=97 request=/grpc.AgentService/SignalProcess resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
level=info msg="time=\"2018-06-27T21:01:05.274775819Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req=\"container_id:\\\"97b0e654fa2d24f339353150412414ea04d648a44553c5d02e7a5b4eebe721c1\\\" \" request=/grpc.AgentService/RemoveContainer source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.277389421Z\" level=debug msg=\"request end\" duration=2.139421ms name=kata-agent pid=97 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.417113619Z\" level=debug msg=\"new request\" name=kata-agent pid=97 req= request=/grpc.AgentService/DestroySandbox source=agent\n" name=kata-proxy pid=32493 source=agent
 level=info msg="time=\"2018-06-27T21:01:05.423141471Z\" level=debug msg=\"request end\" duration=5.823417ms name=kata-agent pid=97 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=32493 source=agent
 level=debug msg="shutting down" name=kata-proxy pid=32493 source=proxy
level=info name=kata-proxy pid=2214 source=proxy version=1.0.0-4b80b0f6b4a527e58a63a49398b742e0db6199eb
level=info msg="[    0.243108] initcall hwrng_modinit+0x0/0x6e returned 0 after 1833 usecs\n" name=kata-proxy pid=2214 source=agent
level=info msg="[    0.243455] calling  mod_init+0x0/0x1cd @ 1\n" name=kata-proxy pid=2214 source=agent
level=info msg="[    0.243690] initcall mod_init+0x0/0x1cd returned -19 after 17 usecs\n" name=kata-proxy pid=2214 source=agent
level=info msg="[    0.244158] calling  virtio_rng_driver_init+0x0/0xc @ 1\n" name=kata-proxy pid=2214 source=agent
sboeuf commented 6 years ago

@jcvenegas make sure the syntax is correct as in the qemu doc: https://wiki.qemu.org/Features/VirtIORNG

amshinde commented 6 years ago

@jcvenegas So I tried this:

config.qemuParams = append(config.qemuParams, "-device")
config.qemuParams = append(config.qemuParams, "virtio-rng-pci")

This uses host /dev/random. This worked for me. With this:

sudo docker run -it --runtime=kata-runtime debian sh
# cat /proc/sys/kernel/random/entropy_avail
1040

I also tried with /dev/urandom as:

config.qemuParams = append(config.qemuParams, "-object")
config.qemuParams = append(config.qemuParams, "rng-random,filename=/dev/urandom,id=rng0")
config.qemuParams = append(config.qemuParams, "-device")
config.qemuParams = append(config.qemuParams, "virtio-rng-pci,rng=rng0"

With this the entropy is 

sudo docker run -it --runtime=kata-runtime debian sh
# cat /proc/sys/kernel/random/entropy_avail
1065
jcvenegas commented 6 years ago

@amshinde interesting I will test again with an old kernel

jcvenegas commented 6 years ago

same result with an old kernel

jcvenegas commented 6 years ago

Created a "test" PR to verify is not my environment #451

amshinde commented 6 years ago

@jcvenegas I tested this with the newer kernel version on bare-metal 4.14..51. It works. Maybe this has to do with your nested environment. The VM itself may not have enough entropy. This is just my guess though.

sboeuf commented 6 years ago

@amshinde @jcvenegas cool :) One thing before we submit a PR for that, should we consider limiting the guest so that we don't end up draining the entire entropy from the host in case we have several VMs running. With something like:

-device virtio-rng-pci,max-bytes=1024,period=1000
jcvenegas commented 6 years ago

@sboeuf sure will add it. @amshinde similar result in baremetal. I see the proxy only show the following:

Jun 28 10:37:25 jcvenega-nuc.zpn.intel.com kata-proxy[21949]: time="2018-06-28T10:37:25.584553246-05:00" level=info name=kata-proxy pid=21949 source=proxy version=1.0.0-15459f4b4ac6f6a242445ff284fec14135bc0045
Jun 28 10:37:29 jcvenega-nuc.zpn.intel.com kata-proxy[21949]: time="2018-06-28T10:37:29.722010363-05:00" level=info msg="[    1.120107] tsc: Refined TSC clocksource calibration: 1895.607 MHz\n" name=kata-proxy pid=21949 source=agent
Jun 28 10:37:29 jcvenega-nuc.zpn.intel.com kata-proxy[21949]: time="2018-06-28T10:37:29.723750764-05:00" level=info msg="[    1.121788] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x36a5ec0fe57, max_idle_ns: 881590722870 ns\n" name=kata-proxy pid=21949 source=agent

and runtime:

Jun 28 10:37:25 jcvenega-nuc.zpn.intel.com kata-runtime[21904]: time="2018-06-28T10:37:25.555007981-05:00" level=info msg="{\"execute\":\"qmp_capabilities\"}" arch=amd64 name=kata-runtime pid=21904 source=virtcontainers subsystem=qmp
Jun 28 10:37:25 jcvenega-nuc.zpn.intel.com kata-runtime[21904]: time="2018-06-28T10:37:25.558280517-05:00" level=info msg="{\"return\": {}}" arch=amd64 name=kata-runtime pid=21904 source=virtcontainers subsystem=qmp
Jun 28 10:37:25 jcvenega-nuc.zpn.intel.com kata-runtime[21904]: time="2018-06-28T10:37:25.558520427-05:00" level=info msg="VM started" arch=amd64 name=kata-runtime pid=21904 sandbox-id=5806db38d3b2050722eb8373e44f99b30c87e0c1e6792043f82ac9a5d374e398 source=virtcontainers subsystem=sandbox
Jun 28 10:37:25 jcvenega-nuc.zpn.intel.com kata-runtime[21904]: time="2018-06-28T10:37:25.561526156-05:00" level=info msg="proxy started" arch=amd64 name=kata-runtime pid=21904 proxy-pid=21949 proxy-url="unix:///run/vc/sbs/5806db38d3b2050722eb8373e44f99b30c87e0c1e6792043f82ac9a5d374e398/proxy.sock" sandbox-id=5806db38d3b2050722eb8373e44f99b30c87e0c1e6792043f82ac9a5d374e398 source=virtcontainers subsystem=kata_agent

kata-collect-data output

Meta details

Running kata-collect-data.sh version 1.0.0 (commit 93775487c8c205a399fb4abb2a3940336098e380-dirty) at 2018-06-28.10:39:16.476561642-0500.

Runtime is /usr/local/bin/kata-runtime.

kata-env

Output of "/usr/local/bin/kata-runtime kata-env":

[Meta]
  Version = "1.0.12"

[Runtime]
  Debug = false
  [Runtime.Version]
    Semver = "1.0.0"
    Commit = "93775487c8c205a399fb4abb2a3940336098e380-dirty"
    OCI = "1.0.1"
  [Runtime.Config]
    Path = "/usr/share/defaults/kata-containers/configuration.toml"

[Hypervisor]
  MachineType = "pc"
  Version = "QEMU emulator version 2.11.0\nCopyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers"
  Path = "/usr/bin/qemu-lite-system-x86_64"
  BlockDeviceDriver = "virtio-scsi"
  Msize9p = 8192
  Debug = false

[Image]
  Path = "/usr/share/kata-containers/kata-containers-image_clearlinux_agent_a099747.img"

[Kernel]
  Path = "/usr/share/kata-containers/vmlinuz.container"
  Parameters = "agent.log=debug"

[Initrd]
  Path = ""

[Proxy]
  Type = "kataProxy"
  Version = "kata-proxy version 1.0.0-15459f4b4ac6f6a242445ff284fec14135bc0045"
  Path = "/usr//libexec/kata-containers/kata-proxy"
  Debug = true

[Shim]
  Type = "kataShim"
  Version = "kata-shim version 1.0.0-5296edac3823b31eecebd90ad0b3e7ad81d6e88a"
  Path = "/usr/libexec/kata-containers/kata-shim"
  Debug = true

[Agent]
  Type = "kata"

[Host]
  Kernel = "4.16.13-300.fc28.x86_64"
  Architecture = "amd64"
  VMContainerCapable = true
  [Host.Distro]
    Name = "Fedora"
    Version = "28"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Core(TM) i5-4250U CPU @ 1.30GHz"

Runtime config files

Runtime default config files

/etc/kata-containers/configuration.toml
/usr/share/defaults/kata-containers/configuration.toml

Runtime config file contents

Config file /etc/kata-containers/configuration.toml not found Output of "cat "/usr/share/defaults/kata-containers/configuration.toml"":

# Copyright (c) 2017-2018 Intel Corporation
#
# SPDX-License-Identifier: Apache-2.0
#

# XXX: WARNING: this file is auto-generated.
# XXX:
# XXX: Source file: "cli/config/configuration.toml.in"
# XXX: Project:
# XXX:   Name: Kata Containers
# XXX:   Type: kata

[hypervisor.qemu]
path = "/usr//bin/qemu-lite-system-x86_64"
kernel = "/usr//share/kata-containers/vmlinuz.container"
image = "/usr//share/kata-containers/kata-containers.img"
machine_type = "pc"

# Optional space-separated list of options to pass to the guest kernel.
# For example, use `kernel_params = "vsyscall=emulate"` if you are having
# trouble running pre-2.15 glibc.
#
# WARNING: - any parameter specified here will take priority over the default
# parameter value of the same name used to start the virtual machine.
# Do not set values here unless you understand the impact of doing so as you
# may stop the virtual machine from booting.
# To see the list of default parameters, enable hypervisor debug, create a
# container and look for 'default-kernel-parameters' log entries.
kernel_params = " agent.log=debug"

# Path to the firmware.
# If you want that qemu uses the default firmware leave this option empty
firmware = ""

# Machine accelerators
# comma-separated list of machine accelerators to pass to the hypervisor.
# For example, `machine_accelerators = "nosmm,nosmbus,nosata,nopit,static-prt,nofw"`
machine_accelerators=""

# Default number of vCPUs per SB/VM:
# unspecified or 0                --> will be set to 1
# < 0                             --> will be set to the actual number of physical cores
# > 0 <= number of physical cores --> will be set to the specified number
# > number of physical cores      --> will be set to the actual number of physical cores
default_vcpus = 1

# Default maximum number of vCPUs per SB/VM:
# unspecified or == 0             --> will be set to the actual number of physical cores or to the maximum number
#                                     of vCPUs supported by KVM if that number is exceeded
# > 0 <= number of physical cores --> will be set to the specified number
# > number of physical cores      --> will be set to the actual number of physical cores or to the maximum number
#                                     of vCPUs supported by KVM if that number is exceeded
# WARNING: Depending of the architecture, the maximum number of vCPUs supported by KVM is used when
# the actual number of physical cores is greater than it.
# WARNING: Be aware that this value impacts the virtual machine's memory footprint and CPU
# the hotplug functionality. For example, `default_maxvcpus = 240` specifies that until 240 vCPUs
# can be added to a SB/VM, but the memory footprint will be big. Another example, with
# `default_maxvcpus = 8` the memory footprint will be small, but 8 will be the maximum number of
# vCPUs supported by the SB/VM. In general, we recommend that you do not edit this variable,
# unless you know what are you doing.
default_maxvcpus = 0

# Bridges can be used to hot plug devices.
# Limitations:
# * Currently only pci bridges are supported
# * Until 30 devices per bridge can be hot plugged.
# * Until 5 PCI bridges can be cold plugged per VM.
#   This limitation could be a bug in qemu or in the kernel
# Default number of bridges per SB/VM:
# unspecified or 0   --> will be set to 1
# > 1 <= 5           --> will be set to the specified number
# > 5                --> will be set to 5
default_bridges = 1

# Default memory size in MiB for SB/VM.
# If unspecified then it will be set 2048 MiB.
#default_memory = 2048

# Disable block device from being used for a container's rootfs.
# In case of a storage driver like devicemapper where a container's 
# root file system is backed by a block device, the block device is passed
# directly to the hypervisor for performance reasons. 
# This flag prevents the block device from being passed to the hypervisor, 
# 9pfs is used instead to pass the rootfs.
disable_block_device_use = false

# Block storage driver to be used for the hypervisor in case the container
# rootfs is backed by a block device. This is either virtio-scsi or 
# virtio-blk.
block_device_driver = "virtio-scsi"

# Enable iothreads (data-plane) to be used. This causes IO to be
# handled in a separate IO thread. This is currently only implemented
# for SCSI.
#
enable_iothreads = false

# Enable pre allocation of VM RAM, default false
# Enabling this will result in lower container density
# as all of the memory will be allocated and locked
# This is useful when you want to reserve all the memory
# upfront or in the cases where you want memory latencies
# to be very predictable
# Default false
#enable_mem_prealloc = true

# Enable huge pages for VM RAM, default false
# Enabling this will result in the VM memory
# being allocated using huge pages.
# This is useful when you want to use vhost-user network
# stacks within the container. This will automatically 
# result in memory pre allocation
#enable_hugepages = true

# Enable swap of vm memory. Default false.
# The behaviour is undefined if mem_prealloc is also set to true
#enable_swap = true

# This option changes the default hypervisor and kernel parameters
# to enable debug output where available. This extra output is added
# to the proxy logs, but only when proxy debug is also enabled.
# 
# Default false
enable_debug = true

# Disable the customizations done in the runtime when it detects
# that it is running on top a VMM. This will result in the runtime
# behaving as it would when running on bare metal.
# 
#disable_nesting_checks = true

# This is the msize used for 9p shares. It is the number of bytes 
# used for 9p packet payload.
#msize_9p = 8192

[proxy.kata]
path = "/usr//libexec/kata-containers/kata-proxy"

# If enabled, proxy messages will be sent to the system log
# (default: disabled)
enable_debug = true

[shim.kata]
path = "/usr//libexec/kata-containers/kata-shim"

# If enabled, shim messages will be sent to the system log
# (default: disabled)
enable_debug = true

[agent.kata]
# There is no field for this section. The goal is only to be able to
# specify which type of agent the user wants to use.

[runtime]
# If enabled, the runtime will log additional debug messages to the
# system log
# (default: disabled)
enable_debug = true
#
# Internetworking model
# Determines how the VM should be connected to the
# the container network interface
# Options:
#
#   - bridged
#     Uses a linux bridge to interconnect the container interface to
#     the VM. Works for most cases except macvlan and ipvlan.
#
#   - macvtap
#     Used when the Container network interface can be bridged using
#     macvtap.
internetworking_model="macvtap"

Image details

---
osbuilder:
  url: "https://github.com/kata-containers/osbuilder"
  version: "unknown"
rootfs-creation-time: "2018-06-12T03:55:46.913416409+0000Z"
description: "osbuilder rootfs"
file-format-version: "0.0.2"
architecture: "x86_64"
base-distro:
  name: "Clear"
  version: "22950"
  packages:
    default:
      - "iptables-bin"
      - "libudev0-shim"
      - "systemd"
    extra:

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.0.0-a099747be287d30d7f1efcd6ba2bda88fc4a0f15"
  agent-is-init-daemon: "no"

Initrd details

No initrd

Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2018-06-28T10:15:15.074905652-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=18048 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:15:15.305536841-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=18048 source=virtcontainers subsystem=qemu
time="2018-06-28T10:15:32.74437162-05:00" level=error msg="Container not ready, running or paused, impossible to signal the container" command=kill name=kata-runtime pid=18159 source=runtime
time="2018-06-28T10:15:32.831883688-05:00" level=error msg="Container f2f76b02c22627630b638af11320adb1511c3f2567ce6c2a28df83dc1ea10ee7 not ready, running or paused, cannot send a signal" command=kill name=kata-runtime pid=18190 source=runtime
time="2018-06-28T10:17:44.539854007-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=18709 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:17:44.734602783-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=18709 source=virtcontainers subsystem=qemu
time="2018-06-28T10:19:35.713136211-05:00" level=error msg="update interface request failed" arch=amd64 error="rpc error: code = Unavailable desc = transport is closing" interface-requested="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " name=kata-runtime pid=18709 resulting-interface="<nil>" source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:19:35.714095163-05:00" level=error msg="rpc error: code = Unavailable desc = transport is closing" command=create name=kata-runtime pid=18709 source=runtime
time="2018-06-28T10:21:31.900853568-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=19674 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:21:32.070157886-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=19674 source=virtcontainers subsystem=qemu
time="2018-06-28T10:22:47.195633271-05:00" level=error msg="update interface request failed" arch=amd64 error="rpc error: code = Unavailable desc = transport is closing" interface-requested="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " name=kata-runtime pid=19674 resulting-interface="<nil>" source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:22:47.196152023-05:00" level=error msg="rpc error: code = Unavailable desc = transport is closing" command=create name=kata-runtime pid=19674 source=runtime
time="2018-06-28T10:23:15.089836883-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=19790 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:23:15.271462122-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=19790 source=virtcontainers subsystem=qemu
time="2018-06-28T10:25:11.457806014-05:00" level=error msg="update interface request failed" arch=amd64 error="rpc error: code = Unavailable desc = transport is closing" interface-requested="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " name=kata-runtime pid=19790 resulting-interface="<nil>" source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:25:11.458386531-05:00" level=error msg="rpc error: code = Unavailable desc = transport is closing" command=create name=kata-runtime pid=19790 source=runtime
time="2018-06-28T10:25:50.160772182-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=19959 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:25:50.3262247-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=19959 source=virtcontainers subsystem=qemu
time="2018-06-28T10:28:52.500068309-05:00" level=error msg="update interface request failed" arch=amd64 error="rpc error: code = Unavailable desc = transport is closing" interface-requested="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " name=kata-runtime pid=19959 resulting-interface="<nil>" source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:28:52.500675842-05:00" level=error msg="rpc error: code = Unavailable desc = transport is closing" command=create name=kata-runtime pid=19959 source=runtime
time="2018-06-28T10:30:22.609788613-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=20132 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:30:22.818089348-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=20132 source=virtcontainers subsystem=qemu
time="2018-06-28T10:31:23.556867189-05:00" level=error msg="update interface request failed" arch=amd64 error="rpc error: code = Unavailable desc = transport is closing" interface-requested="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " name=kata-runtime pid=20132 resulting-interface="<nil>" source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:31:23.557060272-05:00" level=error msg="rpc error: code = Unavailable desc = transport is closing" command=create name=kata-runtime pid=20132 source=runtime
time="2018-06-28T10:32:45.76577178-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=20625 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:32:45.949595564-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=20625 source=virtcontainers subsystem=qemu
time="2018-06-28T10:35:16.694604034-05:00" level=error msg="Container not ready, running or paused, impossible to signal the container" command=kill name=kata-runtime pid=20732 source=runtime
time="2018-06-28T10:35:16.83018716-05:00" level=error msg="Container 7fe6e14bd6e6e875bf0a7ffb3f95dea3132e886c309f4ba0d3674337bc226c4d not ready, running or paused, cannot send a signal" command=kill name=kata-runtime pid=20760 source=runtime
time="2018-06-28T10:37:25.274940018-05:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 name=kata-runtime pid=21904 source=virtcontainers subsystem=kata_agent
time="2018-06-28T10:37:25.458426729-05:00" level=debug arch=amd64 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=21904 source=virtcontainers subsystem=qemu

Proxy logs

Recent proxy problems found in system journal:

time="2018-06-28T10:15:18.211770894-05:00" level=info msg="[    0.979659] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:18.217278598-05:00" level=info msg="[    0.982115] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:18.368078525-05:00" level=info msg="[    1.135835] systemd[69]: tmp.mount: Failed to execute command: No such file or directory\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:18.394141489-05:00" level=info msg="[    1.161331] systemd-journald[72]: Failed to open configuration file '/etc/systemd/journald.conf': No such file or directory\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:18.43571356-05:00" level=info msg="[\x1b[0;1;31mFAILED\x1b[0m] Failed to mount Temporary Directory (/tmp).\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:18.441304449-05:00" level=info msg="[\x1b[0;1;33mDEPEND\x1b[0m] Dependency failed for Network Time Synchronization.\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.446462238-05:00" level=info msg="time=\"2018-06-28T15:15:19.312299452Z\" level=debug msg=\"request end\" duration=197.547423ms name=kata-agent pid=94 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.642519954-05:00" level=info msg="time=\"2018-06-28T15:15:19.50836649Z\" level=debug msg=\"request end\" duration=129.031554ms name=kata-agent pid=94 request=/grpc.AgentService/CreateContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.644081559-05:00" level=info msg="time=\"2018-06-28T15:15:19.510011987Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=94 signal=\"child exited\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.715680912-05:00" level=info msg="time=\"2018-06-28T15:15:19.581600599Z\" level=debug msg=\"request end\" duration=\"7.917µs\" name=kata-agent pid=94 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.772101716-05:00" level=info msg="time=\"2018-06-28T15:15:19.638026704Z\" level=debug msg=\"request end\" duration=6.853667ms name=kata-agent pid=94 request=/grpc.AgentService/StartContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:19.832273035-05:00" level=info msg="time=\"2018-06-28T15:15:19.698164114Z\" level=debug msg=\"request end\" duration=\"529.576µs\" name=kata-agent pid=94 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:26.940516119-05:00" level=info msg="time=\"2018-06-28T15:15:26.806079074Z\" level=debug msg=\"request end\" duration=\"19.666µs\" name=kata-agent pid=94 request=/grpc.AgentService/ReadStdout resp=\"data:\\\"sh: unmae: not found\\\\r\\\\n/ # \\\" \" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.648088217-05:00" level=info msg="time=\"2018-06-28T15:15:32.513991309Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=94 signal=\"child exited\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.656241861-05:00" level=info msg="time=\"2018-06-28T15:15:32.522134301Z\" level=debug msg=\"request end\" duration=\"20.069µs\" error=\"read /dev/ptmx: input/output error\" name=kata-agent pid=94 request=/grpc.AgentService/ReadStdout resp= source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.704866975-05:00" level=info msg="time=\"2018-06-28T15:15:32.570641039Z\" level=debug msg=\"request end\" duration=\"583.117µs\" name=kata-agent pid=94 request=/grpc.AgentService/SignalProcess resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.708957935-05:00" level=info msg="time=\"2018-06-28T15:15:32.574861018Z\" level=debug msg=\"request end\" duration=\"800.931µs\" name=kata-agent pid=94 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.868037165-05:00" level=info msg="time=\"2018-06-28T15:15:32.73391001Z\" level=debug msg=\"request end\" duration=5.194593ms name=kata-agent pid=94 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=18100 source=agent
time="2018-06-28T10:15:32.871415663-05:00" level=fatal msg="accept unix /run/vc/sbs/f2f76b02c22627630b638af11320adb1511c3f2567ce6c2a28df83dc1ea10ee7/proxy.sock: use of closed network connection" name=kata-proxy pid=18100 source=proxy
time="2018-06-28T10:32:49.560590767-05:00" level=info msg="[    0.772851] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:49.574196828-05:00" level=info msg="[    0.779708] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:49.741939579-05:00" level=info msg="[    0.955469] systemd[70]: tmp.mount: Failed to execute command: No such file or directory\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:49.778341398-05:00" level=info msg="[    0.991353] systemd-journald[73]: Failed to open configuration file '/etc/systemd/journald.conf': No such file or directory\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:49.79557347-05:00" level=info msg="[\x1b[0;1;31mFAILED\x1b[0m] Failed to mount Temporary Directory (/tmp).\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:49.798942768-05:00" level=info msg="[\x1b[0;1;33mDEPEND\x1b[0m] Dependency failed for Network Time Synchronization.\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:50.729408715-05:00" level=info msg="time=\"2018-06-28T15:32:50.619273198Z\" level=debug msg=\"request end\" duration=79.311029ms name=kata-agent pid=99 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:51.134349568-05:00" level=info msg="time=\"2018-06-28T15:32:51.023741856Z\" level=debug msg=\"request end\" duration=327.398132ms name=kata-agent pid=99 request=/grpc.AgentService/CreateContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:51.135391777-05:00" level=info msg="time=\"2018-06-28T15:32:51.024258143Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=99 signal=\"child exited\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:51.199461079-05:00" level=info msg="time=\"2018-06-28T15:32:51.08923335Z\" level=debug msg=\"request end\" duration=\"8.293µs\" name=kata-agent pid=99 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:51.265513993-05:00" level=info msg="time=\"2018-06-28T15:32:51.15515233Z\" level=debug msg=\"request end\" duration=3.36621ms name=kata-agent pid=99 request=/grpc.AgentService/StartContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:32:51.328328221-05:00" level=info msg="time=\"2018-06-28T15:32:51.218168237Z\" level=debug msg=\"request end\" duration=\"899.272µs\" name=kata-agent pid=99 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:33:03.976655671-05:00" level=info msg="time=\"2018-06-28T15:33:03.86648054Z\" level=debug msg=\"request end\" duration=\"46.467µs\" name=kata-agent pid=99 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:33:05.073398949-05:00" level=info msg="time=\"2018-06-28T15:33:04.96322536Z\" level=debug msg=\"request end\" duration=\"56.209µs\" name=kata-agent pid=99 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.582567485-05:00" level=info msg="time=\"2018-06-28T15:35:16.472346875Z\" level=debug msg=\"request end\" duration=2m11.505451364s error=\"read /dev/ptmx: input/output error\" name=kata-agent pid=99 request=/grpc.AgentService/ReadStdout resp= source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.591933458-05:00" level=info msg="time=\"2018-06-28T15:35:16.48178396Z\" level=info msg=\"ignoring unexpected signal\" name=kata-agent pid=99 signal=\"child exited\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.636730101-05:00" level=info msg="time=\"2018-06-28T15:35:16.526590145Z\" level=debug msg=\"request end\" duration=2.751868ms name=kata-agent pid=99 request=/grpc.AgentService/SignalProcess resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.64232345-05:00" level=info msg="time=\"2018-06-28T15:35:16.530095096Z\" level=debug msg=\"request end\" duration=\"609.892µs\" name=kata-agent pid=99 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.876332262-05:00" level=info msg="time=\"2018-06-28T15:35:16.765713167Z\" level=debug msg=\"request end\" duration=5.790204ms name=kata-agent pid=99 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" source=agent\n" name=kata-proxy pid=20670 source=agent
time="2018-06-28T10:35:16.879379076-05:00" level=fatal msg="accept unix /run/vc/sbs/7fe6e14bd6e6e875bf0a7ffb3f95dea3132e886c309f4ba0d3674337bc226c4d/proxy.sock: use of closed network connection" name=kata-proxy pid=20670 source=proxy

Shim logs

Recent shim problems found in system journal:

time="2018-06-28T10:15:32.657170553-05:00" level=info msg="copy stdout failed" container=f2f76b02c22627630b638af11320adb1511c3f2567ce6c2a28df83dc1ea10ee7 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f2f76b02c22627630b638af11320adb1511c3f2567ce6c2a28df83dc1ea10ee7 name=kata-shim pid=1 source=shim
time="2018-06-28T10:35:16.583320324-05:00" level=info msg="copy stdout failed" container=7fe6e14bd6e6e875bf0a7ffb3f95dea3132e886c309f4ba0d3674337bc226c4d error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=7fe6e14bd6e6e875bf0a7ffb3f95dea3132e886c309f4ba0d3674337bc226c4d name=kata-shim pid=1 source=shim

Container manager details

Have docker

Docker

Output of "docker version":

Client:
 Version:      18.03.1-ce
 API version:  1.37
 Go version:   go1.9.5
 Git commit:   9ee9f40
 Built:        Thu Apr 26 07:19:31 2018
 OS/Arch:      linux/amd64
 Experimental: false
 Orchestrator: swarm

Server:
 Engine:
  Version:      18.03.1-ce
  API version:  1.37 (minimum version 1.12)
  Go version:   go1.9.5
  Git commit:   9ee9f40
  Built:        Thu Apr 26 07:23:21 2018
  OS/Arch:      linux/amd64
  Experimental: false

Output of "docker info":

Containers: 8
 Running: 0
 Paused: 0
 Stopped: 8
Images: 1
Server Version: 18.03.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc kata-runtime
Default Runtime: kata-runtime
Init Binary: docker-init
containerd version: 773c489c9c1b21a6d78b5c538cd395416ec50f88
runc version: 93775487c8c205a399fb4abb2a3940336098e380-dirty (expected: 4fc53a81fb7c994640722ac585fa9ca548971871)
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.16.13-300.fc28.x86_64
Operating System: Fedora 28 (Workstation Edition)
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 15.59GiB
Name: jcvenega-nuc.zpn.intel.com
ID: GHP7:C7Q7:66J3:TLLY:3YAZ:PZRK:7LSM:NYUX:ZVKX:AWT3:575R:4KBJ
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 29
 Goroutines: 57
 System Time: 2018-06-28T10:39:17.208600069-05:00
 EventsListeners: 0
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

Output of "systemctl show docker":

Type=notify
Restart=on-failure
NotifyAccess=main
RestartUSec=100ms
TimeoutStartUSec=infinity
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestamp=Thu 2018-06-28 10:14:19 CDT
WatchdogTimestampMonotonic=1901887364153
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=17679
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestamp=Thu 2018-06-28 10:14:17 CDT
ExecMainStartTimestampMonotonic=1901885900959
ExecMainExitTimestampMonotonic=0
ExecMainPID=17679
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/dockerd ; argv[]=/usr/bin/dockerd -D --add-runtime kata-runtime=/usr/local/bin/kata-runtime --default-runtime=kata-runtime --storage-driver=overlay2 ; ignore_errors=no ; start_time=[Thu 2018-06-28 10:14:17 CDT] ; stop_time=[n/a] ; pid=17679 ; code=(null) ; status=0/0 }
ExecReload={ path=/bin/kill ; argv[]=/bin/kill -s HUP $MAINPID ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
ControlGroup=/system.slice/docker.service
MemoryCurrent=263172096
CPUUsageNSec=[not set]
TasksCurrent=65
IPIngressBytes=18446744073709551615
IPIngressPackets=18446744073709551615
IPEgressBytes=18446744073709551615
IPEgressPackets=18446744073709551615
Delegate=yes
DelegateControllers=cpu cpuacct io blkio memory devices pids
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=yes
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=infinity
IPAccounting=no
UMask=0022
LimitCPU=infinity
LimitCPUSoft=infinity
LimitFSIZE=infinity
LimitFSIZESoft=infinity
LimitDATA=infinity
LimitDATASoft=infinity
LimitSTACK=infinity
LimitSTACKSoft=8388608
LimitCORE=infinity
LimitCORESoft=infinity
LimitRSS=infinity
LimitRSSSoft=infinity
LimitNOFILE=infinity
LimitNOFILESoft=infinity
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=infinity
LimitNPROCSoft=infinity
LimitMEMLOCK=16777216
LimitMEMLOCKSoft=16777216
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=62823
LimitSIGPENDINGSoft=62823
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=0
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
KillMode=process
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=docker.service
Names=docker.service
Requires=sysinit.target system.slice
Wants=network-online.target
WantedBy=multi-user.target
Conflicts=shutdown.target
Before=shutdown.target multi-user.target
After=systemd-journald.socket network-online.target firewalld.service system.slice sysinit.target basic.target
Documentation=https://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/usr/lib/systemd/system/docker.service
DropInPaths=/etc/systemd/system/docker.service.d/kata-containers.conf
UnitFileState=enabled
UnitFilePreset=disabled
StateChangeTimestamp=Thu 2018-06-28 10:14:19 CDT
StateChangeTimestampMonotonic=1901887364155
InactiveExitTimestamp=Thu 2018-06-28 10:14:17 CDT
InactiveExitTimestampMonotonic=1901885901021
ActiveEnterTimestamp=Thu 2018-06-28 10:14:19 CDT
ActiveEnterTimestampMonotonic=1901887364155
ActiveExitTimestamp=Thu 2018-06-28 10:13:54 CDT
ActiveExitTimestampMonotonic=1901863061048
InactiveEnterTimestamp=Thu 2018-06-28 10:13:55 CDT
InactiveEnterTimestampMonotonic=1901864085578
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Thu 2018-06-28 10:14:17 CDT
ConditionTimestampMonotonic=1901885899246
AssertTimestamp=Thu 2018-06-28 10:14:17 CDT
AssertTimestampMonotonic=1901885899247
Transient=no
Perpetual=no
StartLimitIntervalUSec=1min
StartLimitBurst=3
StartLimitAction=none
FailureAction=none
SuccessAction=none
InvocationID=e9a9ed0046394bc08f5493ea6dd4387a
CollectMode=inactive

No kubectl

Packages

Have dpkg Output of "dpkg -l|egrep "(cc-oci-runtimecc-runtimerunv|kata-proxy|kata-runtime|kata-shim|kata-containers-image|linux-container|qemu-)"":

Have rpm Output of "rpm -qa|egrep "(cc-oci-runtimecc-runtimerunv|kata-proxy|kata-runtime|kata-shim|kata-containers-image|linux-container|qemu-)"":

qemu-common-2.11.1-2.fc28.x86_64
qemu-block-ssh-2.11.1-2.fc28.x86_64
qemu-block-dmg-2.11.1-2.fc28.x86_64
qemu-lite-2.11.0+git.6ba2bfbee9-43.1.x86_64
qemu-block-iscsi-2.11.1-2.fc28.x86_64
qemu-block-gluster-2.11.1-2.fc28.x86_64
qemu-lite-bin-2.11.0+git.6ba2bfbee9-43.1.x86_64
qemu-system-x86-core-2.11.1-2.fc28.x86_64
qemu-block-nfs-2.11.1-2.fc28.x86_64
ipxe-roms-qemu-20170710-3.git0600d3ae.fc28.noarch
qemu-lite-data-2.11.0+git.6ba2bfbee9-43.1.x86_64
qemu-block-curl-2.11.1-2.fc28.x86_64
libvirt-daemon-driver-qemu-4.1.0-2.fc28.x86_64
qemu-guest-agent-2.11.1-2.fc28.x86_64
qemu-system-x86-2.11.1-2.fc28.x86_64
qemu-block-rbd-2.11.1-2.fc28.x86_64
qemu-img-2.11.1-2.fc28.x86_64
kata-containers-image-1.0.0-29.1.x86_64
qemu-kvm-2.11.1-2.fc28.x86_64
jcvenegas commented 6 years ago

I was able to get a container working using qemu-vanilla probably something is missing in qemu-lite...

jcvenegas commented 6 years ago

ok , I just tested using an old qemu-lite version (2.7) and it works.

jcvenegas commented 6 years ago

@anthonyzxu ping

anthonyzxu commented 6 years ago

@jcvenegas Ying Liu will take a look at this issue.

liujing2 commented 6 years ago

I will take a look at this issue.

jodh-intel commented 6 years ago

Thanks @liujing2!

liujing2 commented 6 years ago

Could you give me a qemu reproducing process of this issue? Because we don't have kata environment now and need lots of time setting it up and understanding it. Or if I can use your machine to do the reproduce? BTW, could you give detailed steps for the reproduce? Thanks very much!

jodh-intel commented 6 years ago

Hi @liujing2 - it's very quick and easy to install Kata Containers:

But if you really want to install it fast, you could use our kata-manager.sh utility:

Assuming an Ubuntu 18.04 system with sudo access for your user, this will give you a working Kata Containers installation:

$ sudo apt-get -y install golang
$ repo="github.com/kata-containers/tests"
$ go get -d "$repo"
$ PATH=$PATH:$GOPATH/src/${repo}/cmd/kata-manager
$ kata-manager.sh install-docker-system
jodh-intel commented 6 years ago

... which will include qemu-lite and qemu-vanilla packages btw ;)

For the qemu source and dev guides see:

liujing2 commented 6 years ago

@jcvenegas @jodh-intel Thanks @jodh-intel for the information. Before starting to set up the environment, I would like to confirm the issue. From the qemu/kvm point of view, you want to know why launching the guest(container) with virtio-rng failed? If so, which platform of qemu do you use, pc, q35, or qemu-lite? Which kernel version as guest, and qemu version? Thanks!

jodh-intel commented 6 years ago

Hi @liujing2 - We want to know why launching qemu with this patch:

and qemu-vanillla works, but launching with that patch and qemu-lite hangs. We're using pc for qemu-lite and qemu-vanilla.

If you follow my instructions above to install a system, just run the following command to show all details of the environment (including machine types and versions).

For reference, I'm seeing the hang with guest kernel 4.14.22 and qemu version 2.11.0.

liujing2 commented 6 years ago

@jodh-intel Thanks for clarifying, really useful to me. For quickly debugging, I'd like to firstly try to use qemu commands with virtio-rng device which will be more helpful for me to directly debug and see if we can reproduce it. I will ping you then.

liujing2 commented 6 years ago

Hi @jodh-intel Already got the reason in qemu-lite. The root cause is using static_prt. You can disable it by Qemu commands like -machine pc,xxx,static_prt=false Or -machine pc,xxx,nostatic_prt

Thanks, Jing From: James O. D. Hunt [mailto:notifications@github.com] Sent: Monday, July 2, 2018 3:33 PM To: kata-containers/runtime runtime@noreply.github.com Cc: Liu, Jing2 jing2.liu@intel.com; Mention mention@noreply.github.com Subject: Re: [kata-containers/runtime] Container entropy is low (#445)

Hi @liujing2https://github.com/liujing2 - We want to know why launching qemu with this patch:

and qemu-vanillla works, but launching with that patch and qemu-lite hangs. We're using pc for qemu-lite and qemu-vanilla.

If you follow my instructions above to install a system, just run the following command to show all details of the environment (including machine types and versions).

For reference, I'm seeing the hang with guest kernel 4.14.22 and qemu version 2.11.0.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/kata-containers/runtime/issues/445#issuecomment-401697129, or mute the threadhttps://github.com/notifications/unsubscribe-auth/Al2KKbGm84UTWsuhJ1g1nvwHBUCmD6_Iks5uCcyugaJpZM4U4wnn.

sboeuf commented 6 years ago

@jcvenegas could you confirm that following @liujing2 advice, you can get virtio-rng running with qemu-lite ? And in case it works, could you please submit the appropriate PR on the runtime repo to disable static_prt for qemu-lite.

@liujing2 is there any drawback (footprint, performance or functionally wise) by disabling static PRT ? PRT being the PCI routing table I guess that static might have been there for a good reason.

liujing2 commented 6 years ago

@sboeuf https://lists.gnu.org/archive/html/qemu-devel/2016-08/msg03818.html for the drawback. Booting time will be longer (8ms) by disabling static PRT.

grahamwhaley commented 6 years ago

Hi @liujing2 - do we understand why the static PRT makes a difference to the entropy? If feels like maybe there is something not being mapped in the static PRT that is mapped when it is dynamic? Looking at the thread you referenced (thanks!), it seem the static PRT should be the same as the base dynamic Q35 one: https://github.com/kata-containers/runtime/issues/445#issuecomment-405517454

Maybe it is something to do with a non-base Q35 item that needs/can only be dynamically discovered? It would be nice if we knew exactly what though, if it is easy to figure out?

liujing2 commented 6 years ago

Hi Graham, @grahamwhaley static PRT is just for fixing the virtio-rng-pci device adding issue. See James's comments above. Actually I was also curious why static PRT makes it broken. I didn't get the root cause yet.

grahamwhaley commented 6 years ago

Just for reference @jcvenegas , this just fell into my inbox: https://www.phoronix.com/scan.php?page=news_item&px=Linux-Protect-User-Entropy

egernst commented 6 years ago

Can we quantify the minimum amount of entropy that is acceptable? Clearly something between where we are today and what is available on the host. As @sboeuf mentioned earlier, we may exhaust this finite resource, causing boot times to fall off a cliff as the host seeks to provide the level of entropy we are seeking.

This becomes especially relevant also in the templating discussion. Normally I'd seek input from Ben Armstrong, but he's OOO. @scooley

jcvenegas commented 6 years ago

because we know it works with qemu-vanilla , I'll ope a PR enable it optionally.

jcvenegas commented 6 years ago

@liujing2 some news about it, yep disable static PRT works. But because this is a new flag introduced by patches and it affects pc machine type (not only pc-lite). We can not add this flag in every single qemu launch, so I recommend set this disabled by default in our fork.

Do you get any chance to know the root cause static PTR is having issues adding rng devices? I did some testing and found that it was happening with our qemu-vanilla package too. I updated the qemu package to the latest release qemu 2.11.2 and the issue has gone (in qemu-vanilla). I tried to do the same with our fork and rebased our patches on top of 2.11.2 (https://github.com/kata-containers/qemu/commits/qemu-lite-2.11.2) but qemu still get stuck.

liujing2 commented 6 years ago

@jcvenegas yes, the cause is by the patch which set static_prt by default. qemu-vanilla doesn't have that patch. Sorry, I didn't have much time to figure out the root cause for now. And recording to the investigation last time, I guess pc machine type got a wrong routing table when using the patch. When we looking at the build_prt, we can see that q35 and pc are not the same when dynamically building prt.

sboeuf commented 6 years ago

@jcvenegas @liujing2 this would need some debug from the qemu codebase, but for now I agree that simply disabling the static_prt by default is the best thing we can do.

liujing2 commented 6 years ago

@sboeuf @jcvenegas After discussing and investigating the codes, we got a final conclusion: we couldn't build static PRT on pc platform because it is dynamically built. We can build static PRT on q35. So disabling it on pc platform is the only way and performance will be declined.

sboeuf commented 6 years ago

Ok makes sense, thanks for your time @liujing2

jcvenegas commented 6 years ago

@liujing2 thanks for the investigation, lets then lets keep static PTR in pc.