Friday, 2021-04-02

*** egernst has quit IRC03:09
*** egernst has joined #kata-dev03:10
*** egernst has quit IRC04:00
*** egernst has joined #kata-dev04:01
*** egernst has quit IRC04:37
*** dklyle has quit IRC05:38
*** egernst has joined #kata-dev05:52
*** egernst has quit IRC05:57
*** amorenoz has quit IRC06:42
*** egernst has joined #kata-dev08:38
*** egernst has quit IRC08:43
*** ricolin has quit IRC08:51
*** Yarboa has quit IRC10:11
*** Yarboa has joined #kata-dev10:11
*** amorenoz has joined #kata-dev11:17
*** amorenoz has quit IRC11:59
*** egernst has joined #kata-dev12:00
*** egernst has quit IRC12:05
*** sameo has joined #kata-dev12:19
*** egernst has joined #kata-dev14:06
*** egernst has quit IRC14:11
*** egernst has joined #kata-dev14:12
*** dklyle has joined #kata-dev14:34
*** amorenoz has joined #kata-dev15:02
*** amorenoz has quit IRC15:19
*** amorenoz has joined #kata-dev15:20
kata-irc-bot2<gmmaharaj> @eric.ernst finally got my system to behave and I am hitting the same issue with crictl as well. ``` sudo crictl --debug runp --runtime kata-qemu katactr.json katapd.json DEBU[0000] get runtime connection DEBU[0000] connect using endpoint 'unix:///run/containerd/containerd.sock' with '2s' timeout DEBU[0000] connected successfully using endpoint: unix:///run/containerd/containerd.sock DEBU[0000] RunPodSandboxRequest:16:55
kata-irc-bot2&RunPodSandboxRequest{Config:&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:test-busybox,Uid:,Namespace:,Attempt:0,},Hostname:,LogDirectory:,DnsConfig:nil,PortMappings:[]*PortMapping{},Labels:map[string]string{},Annotations:map[string]string{},Linux:&LinuxPodSandboxConfig{CgroupParent:,SecurityContext:nil,Sysctls:map[string]string{},},},RuntimeHandler:kata-qemu,} DEBU[0003] RunPodSandboxResponse:16:55
kata-irc-bot2&RunPodSandboxResponse{PodSandboxId:28a3e46ecd7a7598c89abd987e540766727831e90c996012b7303fc993903e36,} 28a3e46ecd7a7598c89abd987e540766727831e90c996012b7303fc993903e36```16:55
kata-irc-bot2<eric.ernst> s/#enable_debug/enable_debug on your toml, enable debug in containerd and check logs?16:56
kata-irc-bot2Action: gmmaharaj goes to do things16:57
kata-irc-bot2<eric.ernst> you using cgroups v1?16:57
kata-irc-bot2<gmmaharaj> I believe so.16:58
kata-irc-bot2<gmmaharaj> let me stick to 1.x kata for now.17:01
kata-irc-bot2<gmmaharaj> when i get more time to debug this, i will dig through this to figure out why things are mis-behaving on my end17:02
kata-irc-bot2<gmmaharaj> @eric.ernst kata 2.x only works with cgroups v2?17:13
kata-irc-bot2<eric.ernst> nah, its happy with v1. was just trying to understand what you're seeing.17:15
kata-irc-bot2<gmmaharaj> aah17:15
kata-irc-bot2<gmmaharaj> with more logigng enabled, these are some of the logs of interest I am seeing  ```Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event                                 Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] fv_queue_worker: elem 0: with 2 out desc of length 46 Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] unique: 52, opcode: LOOKUP (1), nodeid: 3, insize:17:17
kata-irc-bot246, pid: 59             Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] lo_lookup(parent=3, name=pause) Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005]   3/pause -> 10                                                            Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005]    unique: 52, success, outsize: 144                                       Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005]17:17
kata-irc-bot2virtio_send_msg: elem 0: with 2 in desc of length 144                      Apr 02 17:08:21 test-kata kata[41722]: time="2021-04-02T17:08:21.102744372Z" level=warning msg="sandbox's cgroup won't be updated: cgroup path is empty" pid=41722 sandbox=9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a source=virtcontainers subsystem=sandbox Apr 02 17:08:21 test-kata containerd[14892]: time="2021-04-02T17:08:21.102744372Z" level=warning17:17
kata-irc-bot2msg="sandbox's cgroup won't be updated: cgroup path is empty" pid=41722 sandbox=9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a source=virtcontainers subsystem=sandbox```  ```Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] virtio_send_data_iov: elem 1: with 7 in desc of length 24592               Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] virtio_send_data_iov: after skip skip_size=0 in_sg_cpy_count=617:17
kata-irc-bot2in_sg_left=24576                                                                                                                                  Apr 02 17:08:21 test-kata virtiofsd[41752]: [ID: 00000005] virtio_send_data_iov: preadv ret=24576 len=24576                           Apr 02 17:08:23 test-kata containerd[14892]: time="2021-04-02T17:08:23.559214755Z" level=info msg="StopPodSandbox for17:17
kata-irc-bot2\"9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a\""                                                                                 Apr 02 17:08:23 test-kata systemd[1439]: run-containerd-io.containerd.grpc.v1.cri-sandboxes-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-shm.mount: Succeeded.                                                                                          -- Subject: Unit succeeded17:17
kata-irc-bot2                                                                                                     -- Defined-By: systemd                                                                                                                -- Support: http://www.ubuntu.com/support                                                                                             --17:17
kata-irc-bot2                                                    -- The unit UNIT has successfully entered the 'dead' state.                                                                           Apr 02 17:08:23 test-kata systemd[1]: run-containerd-io.containerd.grpc.v1.cri-sandboxes-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-shm.mount: Succeeded.17:17
kata-irc-bot2   -- Subject: Unit succeeded                                                                                                            -- Defined-By: systemd                                                                                                                -- Support: http://www.ubuntu.com/support                                                                                             --17:17
kata-irc-bot2                                                                                        -- The unit run-containerd-io.containerd.grpc.v1.cri-sandboxes-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-shm.mount has successfully entered the 'dead' state.                                                                                        Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Got queue event on17:17
kata-irc-bot2Queue 1                                Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 16 out: 64          Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event                                 Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005] fv_queue_worker: elem 1: with 2 out desc of length 64                      Apr 0217:17
kata-irc-bot217:08:23 test-kata virtiofsd[41752]: [ID: 00000005] unique: 72, opcode: RELEASE (18), nodeid: 10, insize: 64, pid: 0 Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005]    unique: 72, success, outsize: 16                                        Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005] virtio_send_msg: elem 1: with 1 in desc of length 16                       Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004]17:17
kata-irc-bot2fv_queue_thread: Got queue event on Queue 1                                Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 120 out: 56         Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005] fv_queue_worker: elem 1: with 2 out desc of length 56                      Apr17:17
kata-irc-bot202 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005] unique: 74, opcode: GETATTR (3), nodeid: 3, insize: 56, pid: 54 Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005]    unique: 74, success, outsize: 120                                       Apr 02 17:08:23 test-kata virtiofsd[41752]: [ID: 00000005] virtio_send_msg: elem 1: with 2 in desc of length 120                      Apr 02 17:08:23 test-kata kata[41722]:17:17
kata-irc-bot2time="2021-04-02T17:08:23.579770043Z" level=warning msg="Could not remove container share dir" error="no such file or directory" pid=41722 sandbox=9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a share-dir=/run/kata-containers/shared/sandboxes/9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a/9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a source=virtcontainers subsystem=container``` ```Apr 0217:17
kata-irc-bot217:08:23 test-kata systemd[1]: run-kata\x2dcontainers-shared-sandboxes-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-mounts-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-rootfs.mount: Succeeded. -- Subject: Unit succeeded                                                                                                            -- Defined-By: systemd17:17
kata-irc-bot2                                                  -- Support: http://www.ubuntu.com/support                                                                                             --                                                                                                                                    -- The unit17:17
kata-irc-bot2run-kata\x2dcontainers-shared-sandboxes-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-mounts-9ddd776b47a6e7cdc50181d674d2a99aa3001508741f3477747e2deb395b7c5a-rootfs.mount has successfully entered the 'dead' state. Apr 02 17:08:23 test-kata kata[41722]: time="2021-04-02T17:08:23.583025503Z" level=error msg="Failed to read guest console logs" console-protocol=unix17:17
kata-irc-bot2<eric.ernst> you have vsock modprobed?17:19
kata-irc-bot2<eric.ernst> vhost-vsock?17:19
kata-irc-bot2<eric.ernst> i suppose you must if you made it that far.17:19
kata-irc-bot2<gmmaharaj> Yup, it is in ```lsmod | grep vhost_vsock vhost_vsock            24576  0 vmw_vsock_virtio_transport_common    32768  1 vhost_vsock vsock                  36864  2 vmw_vsock_virtio_transport_common,vhost_vsock vhost                  49152  2 vhost_vsock,vhost_net```17:20
kata-irc-bot2<eric.ernst> did you up contaienrd's logs?17:21
kata-irc-bot2<eric.ernst> ie: ```[debug]   address = ""   uid = 0   gid = 0   level = "debug"```17:21
kata-irc-bot2<eric.ernst> in /etc/contaienrd/config.toml (then restart the containerd service)17:21
kata-irc-bot2<gmmaharaj> @eric.ernst sorry about the delay. https://gist.github.com/ganeshmaharaj/e816d62348144e96d50f847a00229c3219:08
kata-irc-bot2<gmmaharaj> @eric.ernst shelve this issue for now. I will try and see if i can find a more solid reproducer on this and then get back to you19:18
*** amorenoz has quit IRC19:30
*** egernst_ has joined #kata-dev20:26
*** egernst has quit IRC20:30
*** egernst_ has quit IRC21:23
*** egernst has joined #kata-dev22:20
*** egernst has quit IRC22:26
*** sameo has quit IRC22:46
*** egernst has joined #kata-dev22:54

Generated by irclog2html.py 2.17.2 by Marius Gedminas - find it at https://mg.pov.lt/irclog2html/!