virtio-fs: failed to launch kata using -m to specify memory on docker command

[chavafg]

Cannot specify memory when running kata using virtio-fs with and without hugepages

$ sudo docker run -ti --runtime kata-runtime -m 200M ubuntu bash
WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap.
docker: Error response from daemon: OCI runtime create failed: rpc error: code = Unavailable desc = transport is closing: unknown.

On the logs I see: msg="fv_panic: libvhost-user: virtio: invalid address for buffers", complete kata-runtime logs:

May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.878574662Z" level=debug msg="fv_queue_thread: Got queue event on Queue 1" arch=amd64 command=create container=369aebbe675b7b3cf905fa1
4c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.878647763Z" level=debug msg="fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 105" arch=amd64 command=create container
=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.878695764Z" level=debug msg="fv_queue_thread: elem 0: with 2 out desc of length 105" arch=amd64 command=create container=369aebbe675b
7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.878883766Z" level=debug msg="unique: 3, opcode: LOOKUP (1), nodeid: 1, insize: 105, pid: 90" arch=amd64 command=create container=369a
ebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.878938466Z" level=debug msg="lo_lookup(parent=1, name=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a)" arch=amd64 c
ommand=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879000567Z" level=debug msg="  1/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a -> 2" arch=amd64 command=create con
tainer=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879051768Z" level=debug msg="   unique: 3, success, outsize: 144" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b8
2a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879096468Z" level=debug msg="virtio_send_msg: elem 0: with 2 in desc of length 144" arch=amd64 command=create container=369aebbe675b7
b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879158769Z" level=debug msg="fv_queue_thread: Waiting for Queue 1 event" arch=amd64 command=create container=369aebbe675b7b3cf905fa14
c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879203969Z" level=debug msg="fv_queue_thread: Got queue event on Queue 1" arch=amd64 command=create container=369aebbe675b7b3cf905fa1
4c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.87929917Z" level=debug msg="fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 47" arch=amd64 command=create container=3
69aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879369871Z" level=debug msg="fv_queue_thread: elem 0: with 2 out desc of length 47" arch=amd64 command=create container=369aebbe675b7
b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879408571Z" level=debug msg="unique: 4, opcode: LOOKUP (1), nodeid: 2, insize: 47, pid: 90" arch=amd64 command=create container=369ae
bbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879448172Z" level=debug msg="lo_lookup(parent=2, name=rootfs)" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3
b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879504273Z" level=debug msg="  2/rootfs -> 3" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3
179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879550573Z" level=debug msg="   unique: 4, success, outsize: 144" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b8
2a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879592874Z" level=debug msg="virtio_send_msg: elem 0: with 2 in desc of length 144" arch=amd64 command=create container=369aebbe675b7
b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.879633074Z" level=debug msg="fv_queue_thread: Waiting for Queue 1 event" arch=amd64 command=create container=369aebbe675b7b3cf905fa14
c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.921634639Z" level=debug msg="fv_queue_thread: Got queue event on Queue 1" arch=amd64 command=create container=369aebbe675b7b3cf905fa1
4c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.92174274Z" level=debug msg="fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 45" arch=amd64 command=create container=3
69aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.921955843Z" level=debug msg="fv_panic: libvhost-user: virtio: invalid address for buffers" arch=amd64 command=create container=369aeb
be675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtiofsd subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.930432037Z" level=info msg="virtiofsd quits" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.930521638Z" level=info msg="Stopping Sandbox" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.930589238Z" level=info msg="{\"execute\":\"quit\"}" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qmp
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.931012343Z" level=info msg="{\"return\": {}}" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qmp
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.931121544Z" level=info msg="{\"timestamp\": {\"seconds\": 1558990119, \"microseconds\": 930993}, \"event\": \"SHUTDOWN\", \"data\": {\"guest\": false, \"reason\": \"host-qmp-quit\"}}" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qmp
May 27 20:48:39 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:39.931331547Z" level=info msg="cleanup vm path" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a dir=/run/vc/vm/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a link=/run/vc/vm/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066503844Z" level=info msg="Stopping sandbox in the VM" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=virtcontainers subsystem=sandbox
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066628445Z" level=warning msg="Agent did not stop sandbox" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a error="Proxy is not running: no such process" name=kata-runtime pid=47022 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a sandboxid=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=virtcontainers subsystem=sandbox
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066696146Z" level=info msg="Stopping VM" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=virtcontainers subsystem=sandbox
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066741046Z" level=info msg="Stopping Sandbox" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066841648Z" level=error msg="Fail to execute qmp QUIT" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a error="exitting QMP loop, command cancelled" name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066922948Z" level=warning msg="failed to resolve vm path" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a dir=/run/vc/vm/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a error="lstat /run/vc/vm/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a: no such file or directory" name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.066997049Z" level=info msg="cleanup vm path" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a dir=/run/vc/vm/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a link= name=kata-runtime pid=47022 source=virtcontainers subsystem=qemu
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.06706525Z" level=info msg="Detaching endpoint" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a endpoint-type=virtual hotunplug=false name=kata-runtime pid=47022 source=virtcontainers subsystem=network
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.099101105Z" level=debug msg="Network removed" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=network
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.099197706Z" level=info msg="Network namespace \"/var/run/netns/cni-7ea1fd8f-154f-1e54-15fd-f8e7bbfd13d1\" deleted" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=virtcontainers subsystem=network
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.118403519Z" level=debug msg="Deleting sandbox cgroup" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=virtcontainers subsystem=sandbox
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.118459019Z" level=debug msg="Deleting no constraints cgroup" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime path=/kata pid=47022 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=virtcontainers subsystem=sandbox
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.119708233Z" level=info msg="cleanup agent" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime path=/run/kata-containers/shared/sandboxes/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a pid=47022 source=virtcontainers subsystem=kata_agent
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.119940436Z" level=debug msg="Deleting files" arch=amd64 backend=filesystem command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime path=/var/lib/vc/sbs/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a pid=47022 source=virtcontainers/store subsystem=store
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.12036934Z" level=debug msg="Deleting files" arch=amd64 backend=filesystem command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime path=/run/vc/sbs/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a pid=47022 source=virtcontainers/store subsystem=store
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.120622543Z" level=warning msg="failed to cleanup netns" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a error="failed to get netns /var/run/netns/cni-7ea1fd8f-154f-1e54-15fd-f8e7bbfd13d1: failed to Statfs \"/var/run/netns/cni-7ea1fd8f-154f-1e54-15fd-f8e7bbfd13d1\": no such file or directory" name=kata-runtime path=/var/run/netns/cni-7ea1fd8f-154f-1e54-15fd-f8e7bbfd13d1 pid=47022 source=katautils
May 27 20:48:40 virtiofs-tests kata-runtime[47022]: time="2019-05-27T20:48:40.120704844Z" level=error msg="rpc error: code = Unavailable desc = transport is closing" arch=amd64 command=create container=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a name=kata-runtime pid=47022 source=runtime

kata-proxy log:

May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.830934935Z" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a/proxy.sock->@: use of closed network connection" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=proxy
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.84494069Z" level=info msg="[    0.474425] Built 1 zonelists, mobility grouping on.  Total pages: 154879\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.845275493Z" level=info msg="time=\"2019-05-27T20:48:39.833273681Z\" level=info msg=\"Received add uevent\" debug_console=false name=kata-agent pid=77 source=agent subsystem=udevlistener uevent-action=add uevent-devname= uevent-devpath=/devices/system/memory/memory33 uevent-seqnum=737 uevent-subsystem=memory\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.851663664Z" level=info msg="time=\"2019-05-27T20:48:39.839679483Z\" level=debug msg=\"new request\" debug_console=false name=kata-agent pid=77 req= request=/grpc.AgentService/OnlineCPUMem sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.851980268Z" level=info msg="time=\"2019-05-27T20:48:39.839876141Z\" level=debug msg=\"request end\" debug_console=false duration=\"2.867µs\" name=kata-agent pid=77 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.854286293Z" level=info msg="time=\"2019-05-27T20:48:39.842344258Z\" level=debug msg=\"connecting vCPUs\" debug_console=false name=kata-agent pid=77 range-of-vcpus=0 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.854948501Z" level=info msg="time=\"2019-05-27T20:48:39.842887593Z\" level=info msg=\"Received add uevent\" debug_console=false name=kata-agent pid=77 source=agent subsystem=udevlistener uevent-action=add uevent-devname= uevent-devpath=/devices/system/memory/memory34 uevent-seqnum=738 uevent-subsystem=memory\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.871301082Z" level=info msg="time=\"2019-05-27T20:48:39.859129717Z\" level=debug msg=\"new request\" debug_console=false name=kata-agent pid=77 req=\"container_id:\\\"369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a\\\" exec_id:\\\"369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a\\\" OCI:<Version:\\\"1.0.1\\\" Process:<Terminal:true User:<> Args:\\\"bash\\\" Env:\\\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\\\" Env:\\\"HOSTNAME=369aebbe675b\\\" Env:\\\"TERM=xterm\\\" 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/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a/rootfs\\\" > Hostname:\\\"369aebbe675b\\\" 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/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a-1a6fd8afd944edcd-resolv.conf\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/etc/hostname\\\" source:\\\"/run/kata-containers/shared/containers/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a-aa3dfd0e6e9eaf89-hostname\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/etc/hosts\\\" source:\\\"/run/kata-containers/shared/containers/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a-a1df330664b40843-hosts\\\" type:\\\"bind\\\" options:\\\"rbind\\\" options:\\\"rprivate\\\" > Mounts:<destination:\\\"/dev/shm\\\" source:\\\"/run/kata-containers/sandbox/shm\\\" type:\\\"bind\\\" options:\\\"rbind\\\" > Linux:<Resources:<Memory:<Limit:209715200 > CPU:<> > CgroupsPath:\\\"/docker/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a\\\" Namespaces:<Type:\\\"mount\\\" > Namespaces:<Type:\\\"uts\\\" > Namespaces:<Type:\\\"ipc\\\" > MaskedPaths:\\\"/proc/acpi\\\" 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 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent\n" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=agent
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.978645071Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a/proxy.sock->@: use of closed network connection" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=proxy
May 27 20:48:39 virtiofs-tests kata-proxy[47064]: time="2019-05-27T20:48:39.980912896Z" level=fatal msg="channel error" error="session shutdown" name=kata-proxy pid=47064 sandbox=369aebbe675b7b3cf905fa14c0580b82a3b9247f461ac2882d3179eea1bbf71a source=proxy

[devimc]

cc @stefanha

[grahamwhaley]

/cc @ganeshmaharaj

[cblichmann]

I have a similar issue. For me, the docker run just hangs:

root@host:~# docker run --runtime=kata-nemu -it -m 256m debian:stretch-slim                                                  
WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap.        

I don't see anything in the logs, though.

[grahamwhaley]

@cblichmann - just to confirm, are you also using virtio-fs and hugepages as per @chavafg 's original report? I see you are using kata-nemu runtime.

[jodh-intel]

@cblichmann - if you could run sudo kata-collect-data.sh, review the output, and if you are happy paste all the output as a comment here, we'll have a better understanding of you setup and config.

[cblichmann]

@grahamwhaley: Yes, I used sysctl vm.nr_hugepages=1024
@jodh-intel: Will do when I come home and can access the container host.

[cblichmann]

Here it goes, although kata-collect-data.sh does not pick up my NEMU configuration that I have set via runtimeArgs in /etc/docker/daemon.json:

Show kata-collect-data.sh details

Meta details

Running kata-collect-data.sh version 1.7.0 (commit d4f4644312d2acbfed8a150e49831787f8ebdd90) at 2019-06-03.20:11:47.616261287+0200.

---

Runtime is /opt/kata/bin/kata-runtime.

kata-env

Output of "/opt/kata/bin/kata-runtime kata-env":

[Meta]
  Version = "1.0.23"

[Runtime]
  Debug = false
  Trace = false
  DisableGuestSeccomp = true
  DisableNewNetNs = false
  Path = "/opt/kata/bin/kata-runtime"
  [Runtime.Version]
    Semver = "1.7.0"
    Commit = "d4f4644312d2acbfed8a150e49831787f8ebdd90"
    OCI = "1.0.1-dev"
  [Runtime.Config]
    Path = "/opt/kata/share/defaults/kata-containers/configuration-qemu.toml"

[Hypervisor]
  MachineType = "pc"
  Version = "QEMU emulator version 2.11.2(kata-static)\nCopyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers"
  Path = "/opt/kata/bin/qemu-system-x86_64"
  BlockDeviceDriver = "virtio-scsi"
  EntropySource = "/dev/urandom"
  Msize9p = 8192
  MemorySlots = 10
  Debug = false
  UseVSock = false
  SharedFS = "virtio-9p"

[Image]
  Path = "/opt/kata/share/kata-containers/kata-containers-image_clearlinux_1.7.0_agent_43bd707543.img"

[Kernel]
  Path = "/opt/kata/share/kata-containers/vmlinuz-4.19.28-39"
  Parameters = "init=/usr/lib/systemd/systemd systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket systemd.mask=systemd-journald.service systemd.mask=systemd-journald.socket systemd.mask=systemd-journal-flush.service systemd.mask=systemd-journald-dev-log.socket systemd.mask=systemd-udevd.service systemd.mask=systemd-udevd.socket systemd.mask=systemd-udev-trigger.service systemd.mask=systemd-udevd-kernel.socket systemd.mask=systemd-udevd-control.socket systemd.mask=systemd-timesyncd.service systemd.mask=systemd-update-utmp.service systemd.mask=systemd-tmpfiles-setup.service systemd.mask=systemd-tmpfiles-cleanup.service systemd.mask=systemd-tmpfiles-cleanup.timer systemd.mask=tmp.mount systemd.mask=systemd-random-seed.service systemd.mask=systemd-coredump@.service"

[Initrd]
  Path = ""

[Proxy]
  Type = "kataProxy"
  Version = "kata-proxy version 1.7.0-ea2b0bb14ef7906105d9ac808503292096add170"
  Path = "/opt/kata/libexec/kata-containers/kata-proxy"
  Debug = false

[Shim]
  Type = "kataShim"
  Version = "kata-shim version 1.7.0-7f2ab7726d6baf0b82ff2a35bd50c73f6b4a3d3a"
  Path = "/opt/kata/libexec/kata-containers/kata-shim"
  Debug = false

[Agent]
  Type = "kata"
  Debug = false
  Trace = false
  TraceMode = ""
  TraceType = ""

[Host]
  Kernel = "4.19.0-5-amd64"
  Architecture = "amd64"
  VMContainerCapable = true
  SupportVSocks = true
  [Host.Distro]
    Name = "Debian GNU/Linux"
    Version = "10"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Xeon(R) E-2176M  CPU @ 2.70GHz"

[Netmon]
  Version = "kata-netmon version 1.7.0"
  Path = "/opt/kata/libexec/kata-containers/kata-netmon"
  Debug = false
  Enable = false

---

Runtime config files

Runtime default config files

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

Runtime config file contents

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

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

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

[hypervisor.qemu]
path = "/opt/kata/bin/qemu-system-x86_64"
kernel = "/opt/kata/share/kata-containers/vmlinuz.container"
image = "/opt/kata/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 = ""

# 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
#
# Default memory slots per SB/VM.
# If unspecified then it will be set 10.
# This is will determine the times that memory will be hotadded to sandbox/VM.
#memory_slots = 10

# The size in MiB will be plused to max memory of hypervisor.
# It is the memory address space for the NVDIMM devie.
# If set block storage driver (block_device_driver) to "nvdimm",
# should set memory_offset to the size of block device.
# Default 0
#memory_offset = 0

# 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

# Shared file system type:
#   - virtio-9p (default)
#   - virtio-fs
shared_fs = "virtio-9p"

# Path to vhost-user-fs daemon.
virtio_fs_daemon = "/opt/kata/bin/virtiofsd-x86_64"

# Default size of DAX cache in MiB
virtio_fs_cache_size = 1024

# Cache mode:
#
#  - none
#    Metadata, data, and pathname lookup are not cached in guest. They are
#    always fetched from host and any changes are immediately pushed to host.
#
#  - auto
#    Metadata and pathname lookup cache expires after a configured amount of
#    time (default is 1 second). Data is cached while the file is open (close
#    to open consistency).
#
#  - always
#    Metadata, data, and pathname lookup are cached in guest and never expire.
virtio_fs_cache = "always"

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

# Specifies cache-related options will be set to block devices or not.
# Default false
#block_device_cache_set = true

# Specifies cache-related options for block devices.
# Denotes whether use of O_DIRECT (bypass the host page cache) is enabled.
# Default false
#block_device_cache_direct = true

# Specifies cache-related options for block devices.
# Denotes whether flush requests for the device are ignored.
# Default false
#block_device_cache_noflush = true

# 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

# If true and vsocks are supported, use vsocks to communicate directly
# with the agent and no proxy is started, otherwise use unix
# sockets and start a proxy to communicate with the agent.
# Default false
#use_vsock = true

# VFIO devices are hotplugged on a bridge by default.
# Enable hotplugging on root bus. This may be required for devices with
# a large PCI bar, as this is a current limitation with hotplugging on
# a bridge. This value is valid for "pc" machine type.
# Default false
#hotplug_vfio_on_root_bus = true

# If host doesn't support vhost_net, set to true. Thus we won't create vhost fds for nics.
# Default false
#disable_vhost_net = true
#
# Default entropy source.
# The path to a host source of entropy (including a real hardware RNG)
# /dev/urandom and /dev/random are two main options.
# Be aware that /dev/random is a blocking source of entropy.  If the host
# runs out of entropy, the VMs boot time will increase leading to get startup
# timeouts.
# The source of entropy /dev/urandom is non-blocking and provides a
# generally acceptable source of entropy. It should work well for pretty much
# all practical purposes.
#entropy_source= "/dev/urandom"

# Path to OCI hook binaries in the *guest rootfs*.
# This does not affect host-side hooks which must instead be added to
# the OCI spec passed to the runtime.
#
# You can create a rootfs with hooks by customizing the osbuilder scripts:
# https://github.com/kata-containers/osbuilder
#
# Hooks must be stored in a subdirectory of guest_hook_path according to their
# hook type, i.e. "guest_hook_path/{prestart,postart,poststop}".
# The agent will scan these directories for executable files and add them, in
# lexicographical order, to the lifecycle of the guest container.
# Hooks are executed in the runtime namespace of the guest. See the official documentation:
# https://github.com/opencontainers/runtime-spec/blob/v1.0.1/config.md#posix-platform-hooks
# Warnings will be logged if any error is encountered will scanning for hooks,
# but it will not abort container execution.
#guest_hook_path = "/usr/share/oci/hooks"

[factory]
# VM templating support. Once enabled, new VMs are created from template
# using vm cloning. They will share the same initial kernel, initramfs and
# agent memory by mapping it readonly. It helps speeding up new container
# creation and saves a lot of memory if there are many kata containers running
# on the same host.
#
# When disabled, new VMs are created from scratch.
#
# Note: Requires "initrd=" to be set ("image=" is not supported).
#
# Default false
#enable_template = true

# Specifies the path of template.
#
# Default "/run/vc/vm/template"
#template_path = "/run/vc/vm/template"

# The number of caches of VMCache:
# unspecified or == 0   --> VMCache is disabled
# > 0                   --> will be set to the specified number
#
# VMCache is a function that creates VMs as caches before using it.
# It helps speed up new container creation.
# The function consists of a server and some clients communicating
# through Unix socket.  The protocol is gRPC in protocols/cache/cache.proto.
# The VMCache server will create some VMs and cache them by factory cache.
# It will convert the VM to gRPC format and transport it when gets
# requestion from clients.
# Factory grpccache is the VMCache client.  It will request gRPC format
# VM and convert it back to a VM.  If VMCache function is enabled,
# kata-runtime will request VM from factory grpccache when it creates
# a new sandbox.
#
# Default 0
#vm_cache_number = 0

# Specify the address of the Unix socket that is used by VMCache.
#
# Default /var/run/kata-containers/cache.sock
#vm_cache_endpoint = "/var/run/kata-containers/cache.sock"

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

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

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

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

# If enabled, the shim will create opentracing.io traces and spans.
# (See https://www.jaegertracing.io/docs/getting-started).
#
# Note: By default, the shim runs in a separate network namespace. Therefore,
# to allow it to send trace details to the Jaeger agent running on the host,
# it is necessary to set 'disable_new_netns=true' so that it runs in the host
# network namespace.
#
# (default: disabled)
#enable_tracing = true

[agent.kata]
# If enabled, make the agent display debug-level messages.
# (default: disabled)
#enable_debug = true

# Enable agent tracing.
#
# If enabled, the default trace mode is "dynamic" and the
# default trace type is "isolated". The trace mode and type are set
# explicity with the `trace_type=` and `trace_mode=` options.
#
# Notes:
#
# - Tracing is ONLY enabled when `enable_tracing` is set: explicitly
#   setting `trace_mode=` and/or `trace_type=` without setting `enable_tracing`
#   will NOT activate agent tracing.
#
# - See https://github.com/kata-containers/agent/blob/master/TRACING.md for
#   full details.
#
# (default: disabled)
#enable_tracing = true
#
#trace_mode = "dynamic"
#trace_type = "isolated"

[netmon]
# If enabled, the network monitoring process gets started when the
# sandbox is created. This allows for the detection of some additional
# network being added to the existing network namespace, after the
# sandbox has been created.
# (default: disabled)
#enable_netmon = true

# Specify the path to the netmon binary.
path = "/opt/kata/libexec/kata-containers/kata-netmon"

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

[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.
#
#   - none
#     Used when customize network. Only creates a tap device. No veth pair.
#
#   - tcfilter
#     Uses tc filter rules to redirect traffic from the network interface
#     provided by plugin to a tap interface connected to the VM.
#
internetworking_model="tcfilter"

# disable guest seccomp
# Determines whether container seccomp profiles are passed to the virtual
# machine and applied by the kata agent. If set to true, seccomp is not applied
# within the guest
# (default: true)
disable_guest_seccomp=true

# If enabled, the runtime will create opentracing.io traces and spans.
# (See https://www.jaegertracing.io/docs/getting-started).
# (default: disabled)
#enable_tracing = true

# If enabled, the runtime will not create a network namespace for shim and hypervisor processes.
# This option may have some potential impacts to your host. It should only be used when you know what you're doing.
# `disable_new_netns` conflicts with `enable_netmon`
# `disable_new_netns` conflicts with `internetworking_model=bridged` and `internetworking_model=macvtap`. It works only
# with `internetworking_model=none`. The tap device will be in the host network namespace and can connect to a bridge
# (like OVS) directly.
# If you are using docker, `disable_new_netns` only works with `docker run --net=none`
# (default: false)
#disable_new_netns = true

# Enabled experimental feature list, format: ["a", "b"].
# Experimental features are features not stable enough for production,
# They may break compatibility, and are prepared for a big version bump.
# Supported experimental features:
# 1. "newstore": new persist storage driver which breaks backward compatibility,
#                               expected to move out of experimental in 2.0.0.
# (default: [])
experimental=[]

Config file /usr/share/defaults/kata-containers/configuration.toml not found

---

KSM throttler

version

find: ‘/usr/libexec’: No such file or directory
Output of " --version":

/opt/kata/bin/kata-collect-data.sh: line 176: --version: command not found

systemd service

Image details

---
osbuilder:
  url: "https://github.com/kata-containers/osbuilder"
  version: "unknown"
rootfs-creation-time: "2019-05-16T15:45:26.352874446+0000Z"
description: "osbuilder rootfs"
file-format-version: "0.0.2"
architecture: "x86_64"
base-distro:
  name: "Clear"
  version: "29440"
  packages:
    default:
      - "chrony"
      - "iptables-bin"
      - "libudev0-shim"
      - "systemd"
    extra:

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.7.0-43bd7075430fd62ff713daa2708489005cd20042"
  agent-is-init-daemon: "no"
dax-nvdimm-header: "true"

---

Initrd details

No initrd

---

Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2019-06-03T19:57:34.814772392+02:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b error="open /run/vc/sbs/db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b/devices.json: no such file or directory" name=kata-runtime pid=861 sandbox=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b sandboxid=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b source=virtcontainers subsystem=sandbox
time="2019-06-03T19:57:34.901271971+02:00" level=error msg="Unable to launch /opt/kata/bin/nemu-system-x86_64: exit status 1" arch=amd64 command=create container=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b name=kata-runtime pid=861 source=virtcontainers subsystem=qmp
time="2019-06-03T19:57:34.90133607+02:00" level=error msg="nemu-system-x86_64: -object memory-backend-file,id=dimm1,size=2048M,mem-path=/dev/hugepages,share=on,prealloc=on: unable to map backing store for guest RAM: Cannot allocate memory\n" arch=amd64 command=create container=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b name=kata-runtime pid=861 source=virtcontainers subsystem=qmp
time="2019-06-03T19:57:34.95035626+02:00" level=warning msg="failed to cleanup netns" arch=amd64 command=create container=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b error="failed to get netns /var/run/netns/cni-a0ae6626-9025-9f1d-68c0-75abc1fcbaa4: failed to Statfs \"/var/run/netns/cni-a0ae6626-9025-9f1d-68c0-75abc1fcbaa4\": no such file or directory" name=kata-runtime path=/var/run/netns/cni-a0ae6626-9025-9f1d-68c0-75abc1fcbaa4 pid=861 source=katautils
time="2019-06-03T19:57:34.950390192+02:00" level=error msg="nemu-system-x86_64: -object memory-backend-file,id=dimm1,size=2048M,mem-path=/dev/hugepages,share=on,prealloc=on: unable to map backing store for guest RAM: Cannot allocate memory\n" arch=amd64 command=create container=db578889322aa73bebbdf3aaccc7238fa114a9c92d194d0f6bb4ef3d908d287b name=kata-runtime pid=861 source=runtime
time="2019-06-03T19:57:49.550344671+02:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0 error="open /run/vc/sbs/e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0/devices.json: no such file or directory" name=kata-runtime pid=949 sandbox=e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0 sandboxid=e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0 source=virtcontainers subsystem=sandbox
time="2019-06-03T19:57:52.534577543+02:00" level=warning msg="failed to cleanup netns" arch=amd64 command=create container=e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0 error="failed to get netns /var/run/netns/cni-1d7a7548-38d5-4a87-644c-0db6a6761f48: failed to Statfs \"/var/run/netns/cni-1d7a7548-38d5-4a87-644c-0db6a6761f48\": no such file or directory" name=kata-runtime path=/var/run/netns/cni-1d7a7548-38d5-4a87-644c-0db6a6761f48 pid=949 source=katautils
time="2019-06-03T19:57:52.534779023+02:00" level=error msg="rpc error: code = Internal desc = Could not mount none to /run/kata-containers/shared/containers/: no such device" arch=amd64 command=create container=e9d95d87235ff5783f21784b2cb96a5c9450085e51ce3de32128cb66a2bb8ef0 name=kata-runtime pid=949 source=runtime
time="2019-06-03T19:59:31.509305483+02:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=c8361fbbfbbc518003ec91fbc12c1d35c7eee3db2183694cead2d055504b2189 error="open /run/vc/sbs/c8361fbbfbbc518003ec91fbc12c1d35c7eee3db2183694cead2d055504b2189/devices.json: no such file or directory" name=kata-runtime pid=1346 sandbox=c8361fbbfbbc518003ec91fbc12c1d35c7eee3db2183694cead2d055504b2189 sandboxid=c8361fbbfbbc518003ec91fbc12c1d35c7eee3db2183694cead2d055504b2189 source=virtcontainers subsystem=sandbox
time="2019-06-03T20:00:36.772806597+02:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e error="open /run/vc/sbs/3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e/devices.json: no such file or directory" name=kata-runtime pid=1807 sandbox=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e sandboxid=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e source=virtcontainers subsystem=sandbox
time="2019-06-03T20:00:38.934687037+02:00" level=warning msg="failed to cleanup netns" arch=amd64 command=create container=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e error="failed to get netns /var/run/netns/cni-a8ef179c-b863-6530-e358-4cf5694699a1: failed to Statfs \"/var/run/netns/cni-a8ef179c-b863-6530-e358-4cf5694699a1\": no such file or directory" name=kata-runtime path=/var/run/netns/cni-a8ef179c-b863-6530-e358-4cf5694699a1 pid=1807 source=katautils
time="2019-06-03T20:00:38.934739153+02:00" level=error msg="rpc error: code = Internal desc = Could not mount none to /run/kata-containers/shared/containers/: no such device" arch=amd64 command=create container=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e name=kata-runtime pid=1807 source=runtime
time="2019-06-03T20:01:44.1973572+02:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 error="open /run/vc/sbs/4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4/devices.json: no such file or directory" name=kata-runtime pid=1898 sandbox=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 sandboxid=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 source=virtcontainers subsystem=sandbox
time="2019-06-03T20:01:46.262722104+02:00" level=warning msg="failed to cleanup netns" arch=amd64 command=create container=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 error="failed to get netns /var/run/netns/cni-1fa9a55e-b913-e0ae-f52b-d6d7cf3a08e6: failed to Statfs \"/var/run/netns/cni-1fa9a55e-b913-e0ae-f52b-d6d7cf3a08e6\": no such file or directory" name=kata-runtime path=/var/run/netns/cni-1fa9a55e-b913-e0ae-f52b-d6d7cf3a08e6 pid=1898 source=katautils
time="2019-06-03T20:01:46.262758692+02:00" level=error msg="rpc error: code = Internal desc = Could not mount none to /run/kata-containers/shared/containers/: no such device" arch=amd64 command=create container=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 name=kata-runtime pid=1898 source=runtime

Proxy logs

Recent proxy problems found in system journal:

time="2019-06-03T20:00:38.901215784+02:00" level=fatal msg="channel error" error="accept unix /run/vc/sbs/3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e/proxy.sock: use of closed network connection" name=kata-proxy pid=1843 sandbox=3aeca78708fdf5b6b887005c4a975b4e638c2a0088cfd947dfe3a52c14a5969e source=proxy
time="2019-06-03T20:01:46.23931798+02:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4/kata.sock: use of closed network connection" name=kata-proxy pid=1932 sandbox=4f8661914383651673959a52c6ce19149999ecc980741f5e2861bfea342392f4 source=proxy

Shim logs

No recent shim problems found in system journal.

Throttler logs

No recent throttler problems found in system journal.

---

Container manager details

Have docker

Docker

Output of "docker version":

Client:
 Version:           18.09.1
 API version:       1.39
 Go version:        go1.11.6
 Git commit:        4c52b90
 Built:             Sat, 18 May 2019 15:23:52 +0700
 OS/Arch:           linux/amd64
 Experimental:      false

Server:
 Engine:
  Version:          18.09.1
  API version:      1.39 (minimum version 1.12)
  Go version:       go1.11.6
  Git commit:       4c52b90
  Built:            Sat May 18 08:23:52 2019
  OS/Arch:          linux/amd64
  Experimental:     false

Output of "docker info":

Containers: 9
 Running: 0
 Paused: 0
 Stopped: 9
Images: 4
Server Version: 18.09.1
Storage Driver: btrfs
 Build Version: Btrfs v4.20.1
 Library Version: 102
Logging Driver: syslog
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: active
 NodeID: 6ejpfa8nk0ovx1s9xvp5r058p
 Is Manager: true
 ClusterID: synui40b40kr6ofnxq0woyufx
 Managers: 1
 Nodes: 1
 Default Address Pool: 10.0.0.0/8
 SubnetSize: 24
 Orchestration:
  Task History Retention Limit: 5
 Raft:
  Snapshot Interval: 10000
  Number of Old Snapshots to Retain: 0
  Heartbeat Tick: 1
  Election Tick: 10
 Dispatcher:
  Heartbeat Period: 5 seconds
 CA Configuration:
  Expiry Duration: 3 days
  Force Rotate: 0
 Autolock Managers: false
 Root Rotation In Progress: false
 Node Address: 192.168.86.15
 Manager Addresses:
  192.168.86.15:2377
Runtimes: kata-nemu runc runsc
Default Runtime: runsc
Init Binary: docker-init
containerd version: 9754871865f7fe2f4e74d43e2fc7ccd237edcbce
runc version: N/A
init version: v0.18.0 (expected: fec3683b971d9c3ef73f284f176672c44b448662)
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.19.0-5-amd64
Operating System: Debian GNU/Linux 10 (buster)
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 3.854GiB
Name: vcobalt
ID: CPDS:PS3Y:SAJX:6K2I:BIPC:CSR4:X3QO:FBFX:D74X:RQ6E:5QBC:PGRL
Docker Root Dir: /srv/data/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: API is accessible on http://0.0.0.0:2375 without encryption.
         Access to the remote API is equivalent to root access on the host. Refer
         to the 'Docker daemon attack surface' section in the documentation for
         more information: https://docs.docker.com/engine/security/security/#docker-daemon-attack-surface
WARNING: No swap limit support

Output of "systemctl show docker":

Type=notify
Restart=on-failure
NotifyAccess=main
RestartUSec=100ms
TimeoutStartUSec=infinity
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=1480
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestamp=Mon 2019-06-03 20:00:17 CEST
ExecMainStartTimestampMonotonic=261373709
ExecMainExitTimestampMonotonic=0
ExecMainPID=1480
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/sbin/dockerd ; argv[]=/usr/sbin/dockerd -H fd:// $DOCKER_OPTS ; ignore_errors=no ; start_time=[Mon 2019-06-03 20:00:17 CEST] ; stop_time=[n/a] ; pid=1480 ; 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=107950080
CPUUsageNSec=[not set]
TasksCurrent=30
IPIngressBytes=18446744073709551615
IPIngressPackets=18446744073709551615
IPEgressBytes=18446744073709551615
IPEgressPackets=18446744073709551615
Delegate=yes
DelegateControllers=cpu cpuacct io blkio memory devices pids bpf-firewall bpf-devices
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
MemoryMin=0
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=infinity
IPAccounting=no
EnvironmentFiles=/etc/default/docker (ignore_errors=yes)
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=1048576
LimitNOFILESoft=1048576
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=infinity
LimitNPROCSoft=infinity
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=15671
LimitSIGPENDINGSoft=15671
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
LogRateLimitIntervalUSec=0
LogRateLimitBurst=0
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
PrivateMounts=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
FinalKillSignal=9
SendSIGKILL=yes
SendSIGHUP=no
WatchdogSignal=6
Id=docker.service
Names=docker.service
Requires=system.slice sysinit.target docker.socket
Wants=network-online.target
WantedBy=multi-user.target
ConsistsOf=docker.socket
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=systemd-journald.socket system.slice basic.target firewalld.service docker.socket network-online.target sysinit.target
TriggeredBy=docker.socket
Documentation=https://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/docker.service
UnitFileState=enabled
UnitFilePreset=enabled
StateChangeTimestamp=Mon 2019-06-03 20:00:20 CEST
StateChangeTimestampMonotonic=265033102
InactiveExitTimestamp=Mon 2019-06-03 20:00:17 CEST
InactiveExitTimestampMonotonic=261373845
ActiveEnterTimestamp=Mon 2019-06-03 20:00:20 CEST
ActiveEnterTimestampMonotonic=265033102
ActiveExitTimestamp=Mon 2019-06-03 20:00:17 CEST
ActiveExitTimestampMonotonic=261306592
InactiveEnterTimestamp=Mon 2019-06-03 20:00:17 CEST
InactiveEnterTimestampMonotonic=261370375
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=Mon 2019-06-03 20:00:17 CEST
ConditionTimestampMonotonic=261373353
AssertTimestamp=Mon 2019-06-03 20:00:17 CEST
AssertTimestampMonotonic=261373355
Transient=no
Perpetual=no
StartLimitIntervalUSec=1min
StartLimitBurst=3
StartLimitAction=none
FailureAction=none
FailureActionExitStatus=-1
SuccessAction=none
SuccessActionExitStatus=-1
InvocationID=7b72de30608b4d42829037a3e8fcbcdd
CollectMode=inactive

No kubectl
No crio
No containerd

---

Packages

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

No rpm

---

My /etc/docker/daemon.json:

{
  "storage-driver": "btrfs",
  "data-root": "/srv/data/docker",
  "log-driver": "syslog",
  "default-runtime": "runsc",
  "runtimes": {
    "runsc": {
      "path": "/opt/gvisor/runsc",
      "runtimeArgs": [
        "-platform=kvm"
      ]
    },
    "kata-nemu": {
      "path": "/opt/kata/bin/kata-runtime",
      "runtimeArgs": [
        "--kata-config",
        "/etc/opt/alloy/kata/configuration-nemu.toml"
      ]
    }
  }
}

And the /etc/opt/alloy/kata/configuration-nemu.toml:

[hypervisor.qemu]
path = "/opt/kata/bin/nemu-system-x86_64"
kernel = "/opt/alloy/kata/vmlinuz-5.1.6"
image = "/opt/kata/share/kata-containers/kata-containers.img"
machine_type="pc"
kernel_params = ""
firmware = "/opt/kata/share/kata-nemu/OVMF.fd"
machine_accelerators="nosmm,nosmbus,nosata,nopit"
default_vcpus = 1
default_maxvcpus = 0
default_bridges = 1
default_memory = 2048
disable_block_device_use = false
# virtio-fs breaks memory limits currently
shared_fs = "virtio-fs"
#shared_fs = "virtio-9p"
virtio_fs_daemon = "/opt/kata/bin/virtiofsd-x86_64"
virtio_fs_cache_size = 1024
virtio_fs_cache = "always"
# https://github.com/kata-containers/runtime/issues/1203
#use_vsock = true
block_device_driver = "virtio-scsi"
enable_iothreads = false
enable_hugepages = true
[factory]
[proxy.kata]
path = "/opt/kata/libexec/kata-containers/kata-proxy"
[shim.kata]
path = "/opt/kata/libexec/kata-containers/kata-shim"
[agent.kata]
[netmon]
path = "/opt/kata/libexec/kata-containers/kata-netmon"
[runtime]
internetworking_model="tcfilter"
#disable_guest_seccomp=true
disable_guest_seccomp=false
experimental=[]

One more thing: Now that I have rebooted, I consistently get network namespace errors when trying to use virtio-fs:

root@vcobalt:~# docker run --runtime=kata-nemu -it --rm --network=none -m 256m debian:stretch-slim
WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap.
docker: Error response from daemon: OCI runtime create failed: rpc error: code = Internal desc = Could not mount none to /run/kata-containers/shared/containers/: no such device: unknown.

With virtio-9p, everything works as expected.

[grahamwhaley]

@ganeshmaharaj - any ideas here around nemu and virtio-fs failures?

[ganeshmaharaj]

@grahamwhaley Seems to be an issue with virtio-fs & kata. I will look into it asap.

[awprice]

I've run into this issue as well. We are using the default NEMU config, and when specifying memory limits in Kubernetes on our pod, the pod fails to start.

Error log:

Jun 13 03:07:05 ip-10-149-78-152.us-west-2.compute.internal kata[58214]: time="2019-06-13T03:07:05.756798675Z" level=error msg="Wait for process failed" container=5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb error="rpc error: code = Unavailable desc = transport is closing" pid=5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb

When we replace virtio-fs with virtio-9p, everything works fine.

[stefanha]

Please post the log message from kata-runtime showing the QEMU command-line. It should look similar to msg="launching /usr/bin/qemu-system-x86_64 with: [-name ...". On my system I can find these messages in systemd's journalctl (I'm using Docker, not Kubernetes though).

This will allow us to check if the NEMU memory command-line options conflict with virtio-fs. Thanks!

[awprice]

Sure thing @stefanha, here is the line from kata-runtime within containerd -

time="2019-06-13T03:06:49.728152809Z" level=info msg="launching /opt/kata/bin/nemu-system-x86_64 with: [-name sandbox-5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb -uuid 02740fd9-afec-4410-b3e6-596ba3ab8356 -machine virt,accel=kvm,kernel_irqchip,nvdimm -cpu host -qmp unix:/run/vc/vm/5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb/qmp.sock,server,nowait -m 2048M,slots=10,maxmem=516950M -device pcie-pci-bridge,bus=pcie.0,id=pcie-bridge-0,addr=2,romfile= -device virtio-serial-pci,disable-modern=false,id=serial0,romfile= -device virtconsole,chardev=charconsole0,id=console0 -chardev socket,id=charconsole0,path=/run/vc/vm/5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb/console.sock,server,nowait -device nvdimm,id=nv0,memdev=mem0 -object memory-backend-file,id=mem0,mem-path=/opt/kata/share/kata-containers/kata-containers-ubuntu-console.img,size=268435456 -device virtio-scsi-pci,id=scsi0,disable-modern=false,romfile= -object rng-random,id=rng0,filename=/dev/urandom -device virtio-rng,rng=rng0,romfile= -device virtserialport,chardev=charch0,id=channel0,name=agent.channel.0 -chardev socket,id=charch0,path=/run/vc/vm/5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb/kata.sock,server,nowait -chardev socket,id=char-f6196d1ba2ecdae0,path=/run/vc/vm/5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb/vhost-fs.sock -device vhost-user-fs-pci,chardev=char-f6196d1ba2ecdae0,tag=kataShared,cache-size=1024M -netdev tap,id=network-0,vhost=on,vhostfds=3,fds=4 -device driver=virtio-net-pci,netdev=network-0,mac=a6:36:57:8c:5d:63,disable-modern=false,mq=on,vectors=4,romfile= -global kvm-pit.lost_tick_policy=discard -vga none -no-user-config -nodefaults -nographic -daemonize -object memory-backend-file,id=dimm1,size=2048M,mem-path=/dev/shm,share=on -numa node,memdev=dimm1 -kernel /opt/kata/share/kata-containers/vmlinuz-4.19.28-41 -append 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 ro rootfstype=ext4 quiet systemd.show_status=false panic=1 nr_cpus=72 agent.use_vsock=false init=/usr/lib/systemd/systemd systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket -bios /opt/kata/share/kata-nemu/OVMF.fd -pidfile /run/vc/vm/5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb/pid -smp 1,cores=1,threads=1,sockets=72,maxcpus=72]" ID=5786c8c1369687d1ffe6998f096ee484f7e2982e29bccae3c218f44642ea7fbb source=virtcontainers subsystem=qmp	

and here is the pod spec we used that caused the issue -

apiVersion: v1
kind: Pod
metadata:
  name: test
  namespace: default
  annotations:
    io.kubernetes.cri.untrusted-workload: "true"
spec:
  containers:
    - name: sleep
      image: ubuntu
      command:
        - sleep
        - "3600"
      resources:
        limits:
          memory: "8000Mi"
        requests:
          memory: "8000Mi"

[stefanha]

Sure thing @stefanha, here is the line from kata-runtime within containerd -

@awprice I don't see anything suspicious in that command-line. Are any interesting log messages printed when you enable debug options in /etc/kata-containers/configuration.toml?

[egernst]

For easy/quick reproduction, assuming you have Docker installed:

# install kata
 docker run -v /opt/kata:/opt/kata -v /var/run/dbus:/var/run/dbus -v /run/systemd:/run/systemd -v /etc/docker:/etc/docker -it katadocker/kata-deploy kata-deploy-docker install

# verify most basic nemu container works:
docker run --runtime=kata-nemu -it alpine sh -c date

# try with specific memory request, which will result in a QMP hotplug for adding memory:
docker run --runtime=kata-nemu -m 1024M -it alpine sh -c date

[ganeshmaharaj]

Adding more logs from this test. https://gist.github.com/1ac8d5181dc0f06e82f8ab04489317b1

I think the key text is this.

container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.919890144Z" level=debug msg="fv_queue_thread: Waiting for Queue 1 event" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920185125Z" level=debug msg="fv_queue_thread: Got queue event on Queue 1" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920231288Z" level=debug msg="fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 47" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920349516Z" level=debug msg="fv_panic: libvhost-user: virtio: invalid address for buffers" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.944657038Z" level=info msg="virtiofsd quits" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtcontainers subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.944755086Z" level=info msg="Stopping Sandbox" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtcontainers subsystem=qemu

[stefanha]

Adding more logs from this test. https://gist.github.com/1ac8d5181dc0f06e82f8ab04489317b1

I think the key text is this.

container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.919890144Z" level=debug msg="fv_queue_thread: Waiting for Queue 1 event" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920185125Z" level=debug msg="fv_queue_thread: Got queue event on Queue 1" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920231288Z" level=debug msg="fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 47" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.920349516Z" level=debug msg="fv_panic: libvhost-user: virtio: invalid address for buffers" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtiofsd subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.944657038Z" level=info msg="virtiofsd quits" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtcontainers subsystem=qemu
Jun 14 21:15:27 virtiofs kata-runtime[16324]: time="2019-06-14T21:15:27.944755086Z" level=info msg="Stopping Sandbox" arch=amd64 command=create container=3ce995d92832ada9468a18f61ebad3c9a24970f9437aea107621b09554a89579 name=kata-runtime pid=16324 source=virtcontainers subsystem=qemu

Thanks!

This says libvhost-user was unable to translate the guest physical address to an offset in the shared guest RAM. This could be a race between hotplug and a virtqueue request or it could be that hotplug simply doesn't work yet in virtiofsd.

I'll try to reproduce this manually with just QEMU and virtiofsd in order to test to what extent memory hotplug currently works on Monday.

[dagrh]

Hi,
While I've got my concerns about some of our hot-add code in virtiofsd, I think the problem here is simpler.
Kata sets the main RAM up on qemu like this:
-object memory-backend-file,id=dimm1,size=2048M,mem-path=/dev/hugepages,share=on,prealloc=on -numa node,memdev=dimm1

Note that it's file backed, and set with 'share=on' - that's a requirement for vhost-user, which virtio-fs uses.

Now if we look at the hot add what we have:
{"arguments":{
"id":"mem1",
"props":{
"size":1073741824},
"qom-type":"memory-backend-ram"},
"execute":"object-add"}"

That's a boring chunk of 'memory-backend-ram' - no sharing.
So vhost-user isn't going to get passed that.
(Also you're not using huge page for that, which I'm surprised at).