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

killing a qemu process while a container is running leaves pod information #2611

Closed GabyCT closed 3 years ago

GabyCT commented 4 years ago

The SLES and openSUSE CI are having issues with https://github.com/kata-containers/tests/blob/master/integration/stability/hypervisor_stability_kill_test.sh. It seems that a container is launched and then we kill the process of qemu https://github.com/kata-containers/tests/blob/master/integration/stability/hypervisor_stability_kill_test.sh and then we remove the container, however, after it finishes the test is leaving information at /run/vc/sbs (pod information). This are the steps to reproduce this issue

$ sudo docker run --runtime=kata-runtime -d --name test busybox tail -f /dev/null
da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee
$ pidof qemu-system-x86_64
pid=119162
$ sudo kill -KILL 119162
$ sudo docker rm -f test
test

Here are the logs,

Show kata-collect-data.sh details

# Meta details Running `kata-collect-data.sh` version `1.11.0-alpha1 (commit c369692924c09267354b1e06c3e9caa00b96bcf7)` at `2020-04-14.21:04:15.925224900+0000`. --- Runtime is `/usr/local/bin/kata-runtime`. # `kata-env` Output of "`/usr/local/bin/kata-runtime kata-env`": ```toml [Meta] Version = "1.0.24" [Runtime] Debug = true Trace = false DisableGuestSeccomp = true DisableNewNetNs = false SandboxCgroupOnly = false Path = "/usr/local/bin/kata-runtime" [Runtime.Version] OCI = "1.0.1-dev" [Runtime.Version.Version] Semver = "1.11.0-alpha1" Major = 1 Minor = 11 Patch = 0 Commit = "c369692924c09267354b1e06c3e9caa00b96bcf7" [Runtime.Config] Path = "/usr/share/defaults/kata-containers/configuration.toml" [Hypervisor] MachineType = "pc" Version = "QEMU emulator version 4.1.1 (kata-static)\nCopyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers" Path = "/usr/bin/qemu-system-x86_64" BlockDeviceDriver = "virtio-scsi" EntropySource = "/dev/urandom" SharedFS = "virtio-9p" VirtioFSDaemon = "/usr/bin/virtiofsd" Msize9p = 8192 MemorySlots = 10 PCIeRootPort = 0 HotplugVFIOOnRootBus = false Debug = true UseVSock = false [Image] Path = "/usr/share/kata-containers/kata-containers-clearlinux-32830-osbuilder-891b61c-agent-5bf8d4c.img" [Kernel] Path = "/usr/share/kata-containers/vmlinuz-5.4.15-72" Parameters = "systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket agent.log=debug agent.log=debug" [Initrd] Path = "" [Proxy] Type = "kataProxy" Path = "/usr/libexec/kata-containers/kata-proxy" Debug = true [Proxy.Version] Semver = "1.11.0-alpha1-e7d2214f303fe9dfc433f9045659218e75f4d779" Major = 1 Minor = 11 Patch = 0 Commit = "e7d2214f303fe9dfc433f9045659218e75f4d779" [Shim] Type = "kataShim" Path = "/usr/libexec/kata-containers/kata-shim" Debug = true [Shim.Version] Semver = "1.11.0-alpha1-6a828a430c3d35e6ee22ee50a4fd2ed61280ad42" Major = 1 Minor = 11 Patch = 0 Commit = "6a828a430c3d35e6ee22ee50a4fd2ed61280ad42" [Agent] Type = "kata" Debug = true Trace = false TraceMode = "" TraceType = "" [Host] Kernel = "4.12.14-lp151.28.7-default" Architecture = "amd64" VMContainerCapable = true SupportVSocks = true [Host.Distro] Name = "openSUSE Leap" Version = "15.1" [Host.CPU] Vendor = "GenuineIntel" Model = "Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz" [Netmon] Path = "/usr/libexec/kata-containers/kata-netmon" Debug = true Enable = false [Netmon.Version] Semver = "1.11.0-alpha1" Major = 1 Minor = 11 Patch = 0 Commit = "<>" ``` --- # 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"`": ```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 = "/usr/bin/qemu-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 # # 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 # Specifies virtio-mem will be enabled or not. # Please note that this option should be used with the command # "echo 1 > /proc/sys/vm/overcommit_memory". # Default false #enable_virtio_mem = true # 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 = "/usr/bin/virtiofsd" # Default size of DAX cache in MiB virtio_fs_cache_size = 1024 # Extra args for virtiofsd daemon # # Format example: # ["-o", "arg1=xxx,arg2", "-o", "hello world", "--arg3=yyy"] # # see `virtiofsd -h` for possible options. virtio_fs_extra_args = [] # 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 vhost-user storage device, default false # Enabling this will result in some Linux reserved block type # major range 240-254 being chosen to represent vhost-user devices. enable_vhost_user_store = false # The base directory specifically used for vhost-user devices. # Its sub-path "block" is used for block devices; "block/sockets" is # where we expect vhost-user sockets to live; "block/devices" is where # simulated block device nodes for vhost-user devices to live. vhost_user_store_path = "/var/run/kata-containers/vhost-user" # Enable file based guest memory support. The default is an empty string which # will disable this feature. In the case of virtio-fs, this is enabled # automatically and '/dev/shm' is used as the backing folder. # This option will be ignored if VM templating is enabled. #file_mem_backend = "" # 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 # If false and nvdimm is supported, use nvdimm device to plug guest image. # Otherwise virtio-block device is used. # Default is false #disable_image_nvdimm = 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 # Before hot plugging a PCIe device, you need to add a pcie_root_port device. # Use this parameter when using some large PCI bar devices, such as Nvidia GPU # The value means the number of pcie_root_port # This value is valid when hotplug_vfio_on_root_bus is true and machine_type is "q35" # Default 0 #pcie_root_port = 2 # If vhost-net backend for virtio-net is not desired, set to true. Default is false, which trades off # security (vhost-net runs ring0) for network I/O performance. #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 = "/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 # 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" # Comma separated list of kernel modules and their parameters. # These modules will be loaded in the guest kernel using modprobe(8). # The following example can be used to load two kernel modules with parameters # - kernel_modules=["e1000e InterruptThrottleRate=3000,3000,3000 EEE=1", "i915 enable_ppgtt=0"] # The first word is considered as the module name and the rest as its parameters. # Container will not be started when: # * A kernel module is specified and the modprobe command is not installed in the guest # or it fails loading the module. # * The module is not available in the guest or it doesn't met the guest kernel # requirements, like architecture and version. # kernel_modules=[] [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 = "/usr/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: # # - 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=tcfilter` 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 # if enabled, the runtime will add all the kata processes inside one dedicated cgroup. # The container cgroups in the host are not created, just one single cgroup per sandbox. # The runtime caller is free to restrict or collect cgroup stats of the overall Kata sandbox. # The sandbox cgroup path is the parent cgroup of a container with the PodSandbox annotation. # The sandbox cgroup is constrained if there is no container type annotation. # See: https://godoc.org/github.com/kata-containers/runtime/virtcontainers#ContainerType sandbox_cgroup_only=false # 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: # (default: []) experimental=[] ``` --- # KSM throttler ## version Output of "` --version`": ``` ./kata-collect-data.sh: line 178: --version: command not found ``` ## systemd service # Image details ```yaml --- osbuilder: url: "https://github.com/kata-containers/osbuilder" version: "unknown" rootfs-creation-time: "2020-04-14T19:06:56.404404002+0000Z" description: "osbuilder rootfs" file-format-version: "0.0.2" architecture: "x86_64" base-distro: name: "Clear" version: "32830" packages: default: - "chrony" - "iptables-bin" - "kmod-bin" - "libudev0-shim" - "systemd" - "util-linux-bin" extra: agent: url: "https://github.com/kata-containers/agent" name: "kata-agent" version: "1.11.0-alpha1-5bf8d4cc4614d0e0b3202f0a39d723195e341df8" agent-is-init-daemon: "no" ``` --- # Initrd details No initrd --- # Logfiles ## Runtime logs Recent runtime problems found in system journal: ``` time="2020-04-14T20:51:16.9664277Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:16.9682614Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=start container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122368 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers time="2020-04-14T20:51:16.9691233Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.0186757Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=state container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122378 source=virtcontainers time="2020-04-14T20:51:17.0212357Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.1644318Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=state container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122404 source=virtcontainers time="2020-04-14T20:51:17.1662118Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.2188349Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122413 source=virtcontainers time="2020-04-14T20:51:17.220655Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.2224228Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers time="2020-04-14T20:51:17.2233422Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.2246749Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers time="2020-04-14T20:51:17.2258767Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:51:17.2287133Z" level=warning msg="Agent did not stop sandbox" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 error="Proxy is not running" name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 sandboxid=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers subsystem=sandbox time="2020-04-14T20:51:17.2290087Z" level=warning msg="Unable to connect to unix socket (/run/vc/vm/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/qmp.sock): dial unix /run/vc/vm/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/qmp.sock: connect: connection refused" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers subsystem=qmp time="2020-04-14T20:51:17.2290863Z" level=error msg="Failed to connect to QEMU instance" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 error="dial unix /run/vc/vm/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/qmp.sock: connect: connection refused" name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=virtcontainers subsystem=qemu time="2020-04-14T20:51:17.229359Z" level=error msg="dial unix /run/vc/vm/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/qmp.sock: connect: connection refused" arch=amd64 command=delete container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122413 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=runtime time="2020-04-14T20:51:17.4116713Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/config.json: no such file or directory" arch=amd64 command=state container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-runtime pid=122446 source=virtcontainers time="2020-04-14T20:51:17.4138832Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:30.4321418Z" level=debug msg="restore sandbox failed" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="open /run/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/persist.json: no such file or directory" name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=sandbox time="2020-04-14T20:55:30.4635622Z" level=debug arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 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 ro rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=123327 source=virtcontainers subsystem=qemu time="2020-04-14T20:55:30.5177957Z" level=info msg="sanner return error: read unix @->/run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock: use of closed network connection" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123327 source=virtcontainers subsystem=qmp time="2020-04-14T20:55:31.7521801Z" level=debug msg="no loop device" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="open /sys/dev/block/8:4/loop/backing_file: no such file or directory" mount-source=/var/lib/docker/containers/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/resolv.conf name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=container time="2020-04-14T20:55:31.7523759Z" level=debug msg="no loop device" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="open /sys/dev/block/8:4/loop/backing_file: no such file or directory" mount-source=/var/lib/docker/containers/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/hostname name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=container time="2020-04-14T20:55:31.7525486Z" level=debug msg="no loop device" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="open /sys/dev/block/8:4/loop/backing_file: no such file or directory" mount-source=/var/lib/docker/containers/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/hosts name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=container time="2020-04-14T20:55:31.7526794Z" level=debug msg="no loop device" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="open /sys/dev/block/0:44/loop/backing_file: no such file or directory" mount-source=/var/lib/docker/containers/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/mounts/shm name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=container time="2020-04-14T20:55:31.8828803Z" level=warning msg="sandbox's cgroup won't be updated: cgroup path is empty" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123327 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=sandbox time="2020-04-14T20:55:31.8839573Z" level=info msg="sanner return error: read unix @->/run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock: use of closed network connection" arch=amd64 command=create container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123327 source=virtcontainers subsystem=qmp time="2020-04-14T20:55:31.9277463Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=state container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123401 source=virtcontainers time="2020-04-14T20:55:31.9295099Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:31.9708731Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=start container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123408 source=virtcontainers time="2020-04-14T20:55:31.9726983Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:31.9745683Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=start container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123408 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers time="2020-04-14T20:55:31.97525Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.0267088Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=state container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123418 source=virtcontainers time="2020-04-14T20:55:32.0284901Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.1729458Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=state container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123442 source=virtcontainers time="2020-04-14T20:55:32.1746417Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.2169812Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123451 source=virtcontainers time="2020-04-14T20:55:32.2189165Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.2204612Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers time="2020-04-14T20:55:32.2213701Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.2226401Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers time="2020-04-14T20:55:32.223336Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups time="2020-04-14T20:55:32.2254348Z" level=warning msg="Agent did not stop sandbox" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="Proxy is not running" name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 sandboxid=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=sandbox time="2020-04-14T20:55:32.2257317Z" level=warning msg="Unable to connect to unix socket (/run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock): dial unix /run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock: connect: connection refused" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=qmp time="2020-04-14T20:55:32.2258219Z" level=error msg="Failed to connect to QEMU instance" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="dial unix /run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock: connect: connection refused" name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=virtcontainers subsystem=qemu time="2020-04-14T20:55:32.2267466Z" level=error msg="dial unix /run/vc/vm/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/qmp.sock: connect: connection refused" arch=amd64 command=delete container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123451 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=runtime time="2020-04-14T20:55:32.4707886Z" level=warning msg="failed to get sandbox config from old store: open /var/lib/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/config.json: no such file or directory" arch=amd64 command=state container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-runtime pid=123483 source=virtcontainers time="2020-04-14T20:55:32.472282Z" level=warning msg="cgroups have not been created and cgroup path is empty" source=virtcontainers/pkg/cgroups ``` ## Proxy logs Recent proxy problems found in system journal: ``` time="2020-04-14T20:20:27.1103954Z" level=info msg="time=\"2020-04-14T20:20:27.085854825Z\" level=debug msg=\"request end\" debug_console=false duration=\"32.863µs\" name=kata-agent pid=42 request=/grpc.AgentService/CloseStdin resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=agent\n" name=kata-proxy pid=119169 sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=agent time="2020-04-14T20:20:27.2072396Z" level=info msg="time=\"2020-04-14T20:20:27.182745559Z\" level=debug msg=\"request end\" debug_console=false duration=4.757965ms name=kata-agent pid=42 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=agent\n" name=kata-proxy pid=119169 sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=agent time="2020-04-14T20:20:27.3134239Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee/proxy.sock->@: use of closed network connection" name=kata-proxy pid=119169 sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=proxy time="2020-04-14T20:20:27.314936Z" level=fatal msg="channel error" error="session shutdown" name=kata-proxy pid=119169 sandbox=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee source=proxy time="2020-04-14T20:45:07.7836542Z" level=info msg="[ 0.361892] intel_pstate: CPU model not supported\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:07.7953377Z" level=info msg="[ 0.373457] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:07.7962921Z" level=info msg="[ 0.374343] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:07.8435778Z" level=info msg="[ 0.420608] systemd[1]: Failed to stat /etc/localtime, ignoring: No such file or directory\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:07.9221713Z" level=info msg="[ 0.500254] systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/systemd-boot-check-no-failures.service\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:07.9807463Z" level=info msg="[ 0.558883] systemd-sysctl[39]: Couldn't write '16' to 'kernel/sysrq', ignoring: No such file or directory\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.0953068Z" level=info msg="time=\"2020-04-14T20:45:08.071951201Z\" level=debug msg=\"request end\" debug_console=false duration=11.369506ms name=kata-agent pid=42 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.2038758Z" level=info msg="time=\"2020-04-14T20:45:08.180826986Z\" level=debug msg=\"request end\" debug_console=false duration=90.529307ms name=kata-agent pid=42 request=/grpc.AgentService/CreateContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.2042581Z" level=info msg="time=\"2020-04-14T20:45:08.181200298Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 signal=\"child exited\" source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.2045438Z" level=info msg="time=\"2020-04-14T20:45:08.181395783Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 signal=\"child exited\" source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.2236166Z" level=info msg="time=\"2020-04-14T20:45:08.200413191Z\" level=debug msg=\"request end\" debug_console=false duration=\"4.993µs\" name=kata-agent pid=42 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.2274859Z" level=info msg="time=\"2020-04-14T20:45:08.204220192Z\" level=debug msg=\"request end\" debug_console=false duration=\"8.836µs\" name=kata-agent pid=42 request=/grpc.AgentService/CloseStdin resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:08.3227563Z" level=info msg="time=\"2020-04-14T20:45:08.299650879Z\" level=debug msg=\"request end\" debug_console=false duration=4.571693ms name=kata-agent pid=42 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent\n" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=agent time="2020-04-14T20:45:43.8990629Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399/proxy.sock->@: use of closed network connection" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=proxy time="2020-04-14T20:45:43.8992349Z" level=fatal msg="channel error" error="session shutdown" name=kata-proxy pid=121330 sandbox=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 source=proxy time="2020-04-14T20:51:16.4305885Z" level=info msg="[ 0.391872] intel_pstate: CPU model not supported\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.44185Z" level=info msg="[ 0.402888] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.4432291Z" level=info msg="[ 0.404066] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.4994265Z" level=info msg="[ 0.460457] systemd[1]: Failed to stat /etc/localtime, ignoring: No such file or directory\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.5791529Z" level=info msg="[ 0.540170] systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/systemd-boot-check-no-failures.service\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.6360759Z" level=info msg="[ 0.597225] systemd-sysctl[39]: Couldn't write '16' to 'kernel/sysrq', ignoring: No such file or directory\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.7446478Z" level=info msg="time=\"2020-04-14T20:51:16.723760843Z\" level=debug msg=\"request end\" debug_console=false duration=3.921635ms name=kata-agent pid=42 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.8560804Z" level=info msg="time=\"2020-04-14T20:51:16.835143814Z\" level=debug msg=\"request end\" debug_console=false duration=92.097093ms name=kata-agent pid=42 request=/grpc.AgentService/CreateContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.8564084Z" level=info msg="time=\"2020-04-14T20:51:16.835404479Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 signal=\"child exited\" source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.8566507Z" level=info msg="time=\"2020-04-14T20:51:16.835617296Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 signal=\"child exited\" source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.8691591Z" level=info msg="time=\"2020-04-14T20:51:16.848120387Z\" level=debug msg=\"request end\" debug_console=false duration=\"4.923µs\" name=kata-agent pid=42 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.8778973Z" level=info msg="time=\"2020-04-14T20:51:16.856797438Z\" level=debug msg=\"request end\" debug_console=false duration=\"10.905µs\" name=kata-agent pid=42 request=/grpc.AgentService/CloseStdin resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.9770015Z" level=info msg="time=\"2020-04-14T20:51:16.956003428Z\" level=debug msg=\"request end\" debug_console=false duration=3.816003ms name=kata-agent pid=42 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent\n" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=agent time="2020-04-14T20:51:16.9808777Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/proxy.sock->@: read: connection reset by peer" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=proxy time="2020-04-14T20:51:17.0913199Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325/proxy.sock->@: use of closed network connection" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=proxy time="2020-04-14T20:51:17.0917165Z" level=fatal msg="channel error" error="session shutdown" name=kata-proxy pid=122342 sandbox=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 source=proxy time="2020-04-14T20:55:31.4286434Z" level=info msg="[ 0.403214] intel_pstate: CPU model not supported\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.4402229Z" level=info msg="[ 0.414720] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.4412012Z" level=info msg="[ 0.415591] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.4944015Z" level=info msg="[ 0.468771] systemd[1]: Failed to stat /etc/localtime, ignoring: No such file or directory\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.5689165Z" level=info msg="[ 0.543225] systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/systemd-boot-check-no-failures.service\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.6283686Z" level=info msg="[ 0.602772] systemd-sysctl[39]: Couldn't write '16' to 'kernel/sysrq', ignoring: No such file or directory\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.7457797Z" level=info msg="time=\"2020-04-14T20:55:31.728056913Z\" level=debug msg=\"request end\" debug_console=false duration=4.201852ms name=kata-agent pid=42 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.8670129Z" level=info msg="time=\"2020-04-14T20:55:31.849245747Z\" level=debug msg=\"request end\" debug_console=false duration=100.252958ms name=kata-agent pid=42 request=/grpc.AgentService/CreateContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.8673995Z" level=info msg="time=\"2020-04-14T20:55:31.849615179Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 signal=\"child exited\" source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.8675466Z" level=info msg="time=\"2020-04-14T20:55:31.849830323Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=42 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 signal=\"child exited\" source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.8822958Z" level=info msg="time=\"2020-04-14T20:55:31.864290396Z\" level=debug msg=\"request end\" debug_console=false duration=\"12.828µs\" name=kata-agent pid=42 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.8882275Z" level=info msg="time=\"2020-04-14T20:55:31.870376379Z\" level=debug msg=\"request end\" debug_console=false duration=\"28.87µs\" name=kata-agent pid=42 request=/grpc.AgentService/CloseStdin resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:31.9851381Z" level=info msg="time=\"2020-04-14T20:55:31.967435866Z\" level=debug msg=\"request end\" debug_console=false duration=4.675365ms name=kata-agent pid=42 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent\n" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=agent time="2020-04-14T20:55:32.0960453Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6/proxy.sock->@: use of closed network connection" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=proxy time="2020-04-14T20:55:32.0972436Z" level=fatal msg="channel error" error="session shutdown" name=kata-proxy pid=123377 sandbox=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 source=proxy ``` ## Shim logs Recent shim problems found in system journal: ``` time="2020-04-14T20:13:40.4875885Z" level=info msg="copy stdout failed" container=b12cfac814879f8a7a4ecb6bf7779b0a2fd5755536edd0e3d72ca49f98190e25 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=b12cfac814879f8a7a4ecb6bf7779b0a2fd5755536edd0e3d72ca49f98190e25 name=kata-shim pid=1 source=shim time="2020-04-14T20:13:40.5445509Z" level=info msg="copy stdout failed" container=6f535e0be524ba4b38d1e9a12e4668128d0a3b33d98ce116b6ec254cfeef6d37 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6f535e0be524ba4b38d1e9a12e4668128d0a3b33d98ce116b6ec254cfeef6d37 name=kata-shim pid=1 source=shim time="2020-04-14T20:13:40.5587248Z" level=info msg="copy stdout failed" container=f04414141af8d600c3b4167dc51977d619dd9603519d8a9238c1ae763094c6fd error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f04414141af8d600c3b4167dc51977d619dd9603519d8a9238c1ae763094c6fd name=kata-shim pid=1 source=shim time="2020-04-14T20:13:40.6110632Z" level=info msg="copy stdout failed" container=f0f8366bc7362b0d9c04b55720fadeb16cee06e70262fa6f7215c9e8c13e59a0 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f0f8366bc7362b0d9c04b55720fadeb16cee06e70262fa6f7215c9e8c13e59a0 name=kata-shim pid=1 source=shim time="2020-04-14T20:13:40.7651385Z" level=info msg="copy stdout failed" container=9d20838a00278a8f8a9fe200a0178642109875a298d2793125ed6f92f155c75f error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=9d20838a00278a8f8a9fe200a0178642109875a298d2793125ed6f92f155c75f name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.3976031Z" level=info msg="copy stdout failed" container=f10f797bbb9d229ee0bab3a36238cc9be78ec7df07f53483086da79688c42261 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f10f797bbb9d229ee0bab3a36238cc9be78ec7df07f53483086da79688c42261 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.4929112Z" level=info msg="copy stdout failed" container=119633afdb8412ec4e441567a432a4b1e6e795af7a2627318fbd5e73a5bcc47c error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=119633afdb8412ec4e441567a432a4b1e6e795af7a2627318fbd5e73a5bcc47c name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.5096444Z" level=info msg="copy stdout failed" container=abc800008fa28ae9ec323103e473ed9548dbf92969571382b20473fa5c16f228 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=abc800008fa28ae9ec323103e473ed9548dbf92969571382b20473fa5c16f228 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.5486685Z" level=info msg="copy stdout failed" container=cf851be1572e4949210b39ec7e21575b1417c517edfa36866df79f0720163b83 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=cf851be1572e4949210b39ec7e21575b1417c517edfa36866df79f0720163b83 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.577993Z" level=info msg="copy stdout failed" container=cfc086b1de82dde6bce38fd48167984a5e0673a7fc7d21775978e4c6bd33e366 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=cfc086b1de82dde6bce38fd48167984a5e0673a7fc7d21775978e4c6bd33e366 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.5829179Z" level=info msg="copy stdout failed" container=abb370e022ca153dd2bff3d8d260fc73d9de043d1d189494ecbf2dbf0e408da1 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=abb370e022ca153dd2bff3d8d260fc73d9de043d1d189494ecbf2dbf0e408da1 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.5900191Z" level=info msg="copy stdout failed" container=f10704ec5eb0653e4a43d477037d81502dbf92db697ce0746f7c0a03ba1fc417 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f10704ec5eb0653e4a43d477037d81502dbf92db697ce0746f7c0a03ba1fc417 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.6208493Z" level=info msg="copy stdout failed" container=587d12f41f917e35ac21b72485828afa676f35d3633ef434620224dc2e782864 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=587d12f41f917e35ac21b72485828afa676f35d3633ef434620224dc2e782864 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.6694007Z" level=info msg="copy stdout failed" container=259665f8024e1f4994ffe5de449fab5f6c6340404138d334b2c2a38f0ebac71e error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=259665f8024e1f4994ffe5de449fab5f6c6340404138d334b2c2a38f0ebac71e name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.6823711Z" level=info msg="copy stdout failed" container=d6f41c50ca0b1e642520a25cac2d1757b462140ac7609722f152c9f9c3814100 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=d6f41c50ca0b1e642520a25cac2d1757b462140ac7609722f152c9f9c3814100 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.6974574Z" level=info msg="copy stdout failed" container=da208fb2bc75e1e94f1540beb32cb686d8adc0d22a7a4eb3aa6bbfc5728e2ce4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=da208fb2bc75e1e94f1540beb32cb686d8adc0d22a7a4eb3aa6bbfc5728e2ce4 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7121597Z" level=info msg="copy stdout failed" container=e1f07a7b0c2faa02326ed00414bebb47a29f0fca7f3e814a70d26cc6a4702039 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=e1f07a7b0c2faa02326ed00414bebb47a29f0fca7f3e814a70d26cc6a4702039 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7181538Z" level=info msg="copy stdout failed" container=a3342253b2367c2f1d335854cf654e95ddd98a8db47b989bd5a23e33f4ea5faf error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=a3342253b2367c2f1d335854cf654e95ddd98a8db47b989bd5a23e33f4ea5faf name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7373268Z" level=info msg="copy stdout failed" container=e0a747224f942d1e45dd7f2e5207bf00f06c6a5711e9a381c2092b71c32adeeb error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=e0a747224f942d1e45dd7f2e5207bf00f06c6a5711e9a381c2092b71c32adeeb name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7496539Z" level=info msg="copy stdout failed" container=3508c1e7e839576f9ebdbb384be7f228305f4d1442d2eed07db4b9d506f433a9 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=3508c1e7e839576f9ebdbb384be7f228305f4d1442d2eed07db4b9d506f433a9 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7513911Z" level=info msg="copy stdout failed" container=f3f386273315f565888300688f8024448852f01f8b6c0c871546e80bc8294a3e error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f3f386273315f565888300688f8024448852f01f8b6c0c871546e80bc8294a3e name=kata-shim pid=1 source=shim time="2020-04-14T20:14:35.7573301Z" level=info msg="copy stdout failed" container=8e5ae47678cf9007eaf4e505134acc79962f15fe43a8381fb60b72bdae558da8 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=8e5ae47678cf9007eaf4e505134acc79962f15fe43a8381fb60b72bdae558da8 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:36.0106728Z" level=info msg="copy stdout failed" container=e274bd80d9587b07f08d599cfe8fd944110fa5b1c704aa8db806229e067c72bd error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=e274bd80d9587b07f08d599cfe8fd944110fa5b1c704aa8db806229e067c72bd name=kata-shim pid=1 source=shim time="2020-04-14T20:14:36.2437651Z" level=info msg="copy stdout failed" container=6b4c7f944b369c05b414ce0b4af268e06c584727d34c0e79717944104e2a95fd error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6b4c7f944b369c05b414ce0b4af268e06c584727d34c0e79717944104e2a95fd name=kata-shim pid=1 source=shim time="2020-04-14T20:14:36.2728823Z" level=info msg="copy stdout failed" container=6f27186ee2201897c7f0916e9fb1a8f642b5b6626650f0ba9efda6964f1ce53d error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6f27186ee2201897c7f0916e9fb1a8f642b5b6626650f0ba9efda6964f1ce53d name=kata-shim pid=1 source=shim time="2020-04-14T20:14:42.5383767Z" level=info msg="copy stderr failed" container=7ae955745858542ae26735c6a247c8379f69c8fe3260f55b9633beb91908b10f error="rpc error: code = Unknown desc = EOF" exec-id=7ae955745858542ae26735c6a247c8379f69c8fe3260f55b9633beb91908b10f name=kata-shim pid=1 source=shim time="2020-04-14T20:14:42.5391553Z" level=info msg="copy stdout failed" container=7ae955745858542ae26735c6a247c8379f69c8fe3260f55b9633beb91908b10f error="rpc error: code = Unknown desc = EOF" exec-id=7ae955745858542ae26735c6a247c8379f69c8fe3260f55b9633beb91908b10f name=kata-shim pid=1 source=shim time="2020-04-14T20:14:46.0049467Z" level=info msg="copy stdout failed" container=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 error="rpc error: code = Unavailable desc = transport is closing" exec-id=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:46.0054442Z" level=info msg="copy stderr failed" container=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 error="rpc error: code = Unavailable desc = transport is closing" exec-id=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:46.0069011Z" level=error msg="failed waiting for process" container=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 error="rpc error: code = Unavailable desc = transport is closing" exec-id=2509c43097a2c50f969d5f1d59bfd3bfb599274e960c9c9d2b54f3fd9c4a3ba7 name=kata-shim pid=1 source=shim time="2020-04-14T20:14:52.1734701Z" level=info msg="copy stderr failed" container=z3xMsKxoY4PTnLll8bXZ error="rpc error: code = Unknown desc = EOF" exec-id=z3xMsKxoY4PTnLll8bXZ name=kata-shim pid=1 source=shim time="2020-04-14T20:14:52.173927Z" level=info msg="copy stdout failed" container=z3xMsKxoY4PTnLll8bXZ error="rpc error: code = Unknown desc = EOF" exec-id=z3xMsKxoY4PTnLll8bXZ name=kata-shim pid=1 source=shim time="2020-04-14T20:16:23.5386448Z" level=info msg="copy stdout failed" container=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 error="rpc error: code = Unavailable desc = transport is closing" exec-id=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 name=kata-shim pid=1 source=shim time="2020-04-14T20:16:23.538753Z" level=info msg="copy stderr failed" container=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 error="rpc error: code = Unavailable desc = transport is closing" exec-id=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 name=kata-shim pid=1 source=shim time="2020-04-14T20:16:23.5405185Z" level=error msg="failed waiting for process" container=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 error="rpc error: code = Unavailable desc = transport is closing" exec-id=d641c31ec3fd0044b220941271e4da39f9177275c285fb97c4d3667b5c50b505 name=kata-shim pid=1 source=shim time="2020-04-14T20:19:02.8901253Z" level=info msg="copy stdout failed" container=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b error="rpc error: code = Unavailable desc = transport is closing" exec-id=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b name=kata-shim pid=1 source=shim time="2020-04-14T20:19:02.8908346Z" level=info msg="copy stderr failed" container=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b error="rpc error: code = Unavailable desc = transport is closing" exec-id=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b name=kata-shim pid=1 source=shim time="2020-04-14T20:19:02.892273Z" level=error msg="failed waiting for process" container=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b error="rpc error: code = Unavailable desc = transport is closing" exec-id=1d019c133132d1ad2da12203d89cba641ed6a0346e16058b4a6113288a0fed2b name=kata-shim pid=1 source=shim time="2020-04-14T20:20:27.313995Z" level=info msg="copy stdout failed" container=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee error="rpc error: code = Unavailable desc = transport is closing" exec-id=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee name=kata-shim pid=1 source=shim time="2020-04-14T20:20:27.3141673Z" level=info msg="copy stderr failed" container=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee error="rpc error: code = Unavailable desc = transport is closing" exec-id=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee name=kata-shim pid=1 source=shim time="2020-04-14T20:20:27.315734Z" level=error msg="failed waiting for process" container=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee error="rpc error: code = Unavailable desc = transport is closing" exec-id=da464f7234ac268a9dc8c92b7973321fd7514546212385597f8356f5242010ee name=kata-shim pid=1 source=shim time="2020-04-14T20:45:43.8982178Z" level=info msg="copy stdout failed" container=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 error="rpc error: code = Unavailable desc = transport is closing" exec-id=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 name=kata-shim pid=1 source=shim time="2020-04-14T20:45:43.8983101Z" level=info msg="copy stderr failed" container=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 error="rpc error: code = Unavailable desc = transport is closing" exec-id=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 name=kata-shim pid=1 source=shim time="2020-04-14T20:45:43.9006632Z" level=error msg="failed waiting for process" container=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 error="rpc error: code = Unavailable desc = transport is closing" exec-id=e46db807658329ebcd9a91e554f487451ca5665191d73df01c81a9a77389c399 name=kata-shim pid=1 source=shim time="2020-04-14T20:51:17.0913677Z" level=info msg="copy stdout failed" container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 error="rpc error: code = Unavailable desc = transport is closing" exec-id=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-shim pid=1 source=shim time="2020-04-14T20:51:17.0914998Z" level=info msg="copy stderr failed" container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 error="rpc error: code = Unavailable desc = transport is closing" exec-id=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-shim pid=1 source=shim time="2020-04-14T20:51:17.0928064Z" level=error msg="failed waiting for process" container=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 error="rpc error: code = Unavailable desc = transport is closing" exec-id=71c857940da9973bcfff1520119f7831f7760fbe0c2fbe07def718a343f77325 name=kata-shim pid=1 source=shim time="2020-04-14T20:55:32.0962433Z" level=info msg="copy stdout failed" container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="rpc error: code = Unavailable desc = transport is closing" exec-id=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-shim pid=1 source=shim time="2020-04-14T20:55:32.0969433Z" level=info msg="copy stderr failed" container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="rpc error: code = Unavailable desc = transport is closing" exec-id=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-shim pid=1 source=shim time="2020-04-14T20:55:32.0979359Z" level=error msg="failed waiting for process" container=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 error="rpc error: code = Unavailable desc = transport is closing" exec-id=6d2197029b2f20271ae2ab7f56bf3597f4d89abf5957d4e951f9727d1335e5d6 name=kata-shim pid=1 source=shim ``` ## Throttler logs No recent throttler problems found in system journal. --- # Container manager details Have `docker` ## Docker Output of "`docker version`": ``` Client: Version: 18.09.6 API version: 1.39 Go version: go1.10.8 Git commit: 481bc7715621 Built: Wed Jul 24 12:00:00 2019 OS/Arch: linux/amd64 Experimental: false Server: Engine: Version: 18.09.6 API version: 1.39 (minimum version 1.12) Go version: go1.10.8 Git commit: 481bc7715621 Built: Wed Jul 24 12:00:00 2019 OS/Arch: linux/amd64 Experimental: false ``` Output of "`docker info`": ``` Containers: 0 Running: 0 Paused: 0 Stopped: 0 Images: 2 Server Version: 18.09.6 Storage Driver: overlay2 Backing Filesystem: xfs 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 local logentries splunk syslog Swarm: inactive Runtimes: kata-runtime runc Default Runtime: runc Init Binary: docker-init containerd version: bb71b10fd8f58240ca47fbb579b9d1028eea7c84 runc version: 2b18fe1d885ee5083ef9f0838fee39b62d653e30 init version: v0.1.3_catatonit (expected: fec3683b971d9c3ef73f284f176672c44b448662) Security Options: apparmor seccomp Profile: default Kernel Version: 4.12.14-lp151.28.7-default Operating System: openSUSE Leap 15.1 OSType: linux Architecture: x86_64 CPUs: 4 Total Memory: 15.63GiB Name: gabyopensuse ID: A6LA:NVTB:XQAL:7S4G:KDGC:TGWT:6NBX:NWHF:D4S2:AWAJ:ZUFB:ME3Y Docker Root Dir: /var/lib/docker Debug Mode (client): false Debug Mode (server): true File Descriptors: 22 Goroutines: 44 System Time: 2020-04-14T21:04:19.5971843Z EventsListeners: 0 Registry: https://index.docker.io/v1/ Labels: Experimental: false Insecure Registries: 127.0.0.0/8 Live Restore Enabled: false WARNING: No swap limit support ``` Output of "`systemctl show docker`": ``` Type=notify Restart=on-failure NotifyAccess=main RestartUSec=100ms TimeoutStartUSec=1min 30s TimeoutStopUSec=1min 30s RuntimeMaxUSec=infinity WatchdogUSec=0 WatchdogTimestamp=Tue 2020-04-14 19:21:46 UTC WatchdogTimestampMonotonic=883883791 FailureAction=none PermissionsStartOnly=no RootDirectoryStartOnly=no RemainAfterExit=no GuessMainPID=yes MainPID=44205 ControlPID=0 FileDescriptorStoreMax=0 NFileDescriptorStore=0 StatusErrno=0 Result=success UID=4294967295 GID=4294967295 ExecMainStartTimestamp=Tue 2020-04-14 19:21:38 UTC ExecMainStartTimestampMonotonic=876141889 ExecMainExitTimestampMonotonic=0 ExecMainPID=44205 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=runc --storage-driver=overlay2 ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; 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=351531008 CPUUsageNSec=542403511041 TasksCurrent=188 Delegate=yes CPUAccounting=no CPUWeight=18446744073709551615 StartupCPUWeight=18446744073709551615 CPUShares=18446744073709551615 StartupCPUShares=18446744073709551615 CPUQuotaPerSecUSec=infinity IOAccounting=no IOWeight=18446744073709551615 StartupIOWeight=18446744073709551615 BlockIOAccounting=no BlockIOWeight=18446744073709551615 StartupBlockIOWeight=18446744073709551615 MemoryAccounting=no MemoryLow=0 MemoryHigh=18446744073709551615 MemoryMax=18446744073709551615 MemorySwapMax=18446744073709551615 MemoryLimit=18446744073709551615 DevicePolicy=auto TasksAccounting=yes TasksMax=18446744073709551615 EnvironmentFile=/etc/sysconfig/docker (ignore_errors=no) UMask=0022 LimitCPU=18446744073709551615 LimitCPUSoft=18446744073709551615 LimitFSIZE=18446744073709551615 LimitFSIZESoft=18446744073709551615 LimitDATA=18446744073709551615 LimitDATASoft=18446744073709551615 LimitSTACK=18446744073709551615 LimitSTACKSoft=8388608 LimitCORE=18446744073709551615 LimitCORESoft=18446744073709551615 LimitRSS=18446744073709551615 LimitRSSSoft=18446744073709551615 LimitNOFILE=1048576 LimitNOFILESoft=1048576 LimitAS=18446744073709551615 LimitASSoft=18446744073709551615 LimitNPROC=18446744073709551615 LimitNPROCSoft=18446744073709551615 LimitMEMLOCK=65536 LimitMEMLOCKSoft=65536 LimitLOCKS=18446744073709551615 LimitLOCKSSoft=18446744073709551615 LimitSIGPENDING=63869 LimitSIGPENDINGSoft=63869 LimitMSGQUEUE=819200 LimitMSGQUEUESoft=819200 LimitNICE=0 LimitNICESoft=0 LimitRTPRIO=0 LimitRTPRIOSoft=0 LimitRTTIME=18446744073709551615 LimitRTTIMESoft=18446744073709551615 OOMScoreAdjust=0 Nice=0 IOSchedulingClass=0 IOSchedulingPriority=0 CPUSchedulingPolicy=0 CPUSchedulingPriority=0 TimerSlackNSec=50000 CPUSchedulingResetOnFork=no NonBlocking=no StandardInput=null StandardOutput=journal StandardError=inherit TTYReset=no TTYVHangup=no TTYVTDisallocate=no SyslogPriority=30 SyslogLevelPrefix=yes SyslogLevel=6 SyslogFacility=3 SecureBits=0 CapabilityBoundingSet=18446744073709551615 AmbientCapabilities=0 DynamicUser=no RemoveIPC=no MountFlags=0 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 RuntimeDirectoryMode=0755 MemoryDenyWriteExecute=no RestrictRealtime=no RestrictNamespaces=no MountAPIVFS=no KillMode=process KillSignal=15 SendSIGKILL=yes SendSIGHUP=no Id=docker.service Names=docker.service Requires=system.slice sysinit.target Conflicts=shutdown.target Before=shutdown.target After=sysinit.target SuSEfirewall2.service lvm2-monitor.service system.slice systemd-journald.socket network.target basic.target Documentation=http://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=disabled UnitFilePreset=disabled StateChangeTimestamp=Tue 2020-04-14 19:21:46 UTC StateChangeTimestampMonotonic=883883793 InactiveExitTimestamp=Tue 2020-04-14 19:21:38 UTC InactiveExitTimestampMonotonic=876141925 ActiveEnterTimestamp=Tue 2020-04-14 19:21:46 UTC ActiveEnterTimestampMonotonic=883883793 ActiveExitTimestampMonotonic=0 InactiveEnterTimestampMonotonic=0 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=Tue 2020-04-14 19:21:38 UTC ConditionTimestampMonotonic=876140171 AssertTimestamp=Tue 2020-04-14 19:21:38 UTC AssertTimestampMonotonic=876140172 Transient=no Perpetual=no StartLimitIntervalSec=60000000 StartLimitBurst=3 StartLimitAction=none InvocationID=cc295a39f3304fc5b1a5a9b3c862c4ab ``` No `kubectl` Have `crio` ## crio Output of "`crio --version`": ``` crio version 1.17.0-dev commit: 0eec454168e381e460b3d6de07bf50bfd9b0d082 ``` Output of "`systemctl show crio`": ``` Type=simple Restart=on-failure NotifyAccess=none RestartUSec=5s TimeoutStartUSec=1min 30s TimeoutStopUSec=1min 30s RuntimeMaxUSec=infinity WatchdogUSec=0 WatchdogTimestampMonotonic=0 FailureAction=none PermissionsStartOnly=no RootDirectoryStartOnly=no RemainAfterExit=no GuessMainPID=yes MainPID=0 ControlPID=0 FileDescriptorStoreMax=0 NFileDescriptorStore=0 StatusErrno=0 Result=success UID=4294967295 GID=4294967295 ExecMainStartTimestampMonotonic=0 ExecMainExitTimestampMonotonic=0 ExecMainPID=0 ExecMainCode=0 ExecMainStatus=0 ExecStart={ path=/usr/local/bin/crio ; argv[]=/usr/local/bin/crio --log-level debug ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 } Slice=system.slice MemoryCurrent=18446744073709551615 CPUUsageNSec=18446744073709551615 TasksCurrent=18446744073709551615 Delegate=no CPUAccounting=no CPUWeight=18446744073709551615 StartupCPUWeight=18446744073709551615 CPUShares=18446744073709551615 StartupCPUShares=18446744073709551615 CPUQuotaPerSecUSec=infinity IOAccounting=no IOWeight=18446744073709551615 StartupIOWeight=18446744073709551615 BlockIOAccounting=no BlockIOWeight=18446744073709551615 StartupBlockIOWeight=18446744073709551615 MemoryAccounting=no MemoryLow=0 MemoryHigh=18446744073709551615 MemoryMax=18446744073709551615 MemorySwapMax=18446744073709551615 MemoryLimit=18446744073709551615 DevicePolicy=auto TasksAccounting=yes TasksMax=19660 UMask=0022 LimitCPU=18446744073709551615 LimitCPUSoft=18446744073709551615 LimitFSIZE=18446744073709551615 LimitFSIZESoft=18446744073709551615 LimitDATA=18446744073709551615 LimitDATASoft=18446744073709551615 LimitSTACK=18446744073709551615 LimitSTACKSoft=8388608 LimitCORE=18446744073709551615 LimitCORESoft=18446744073709551615 LimitRSS=18446744073709551615 LimitRSSSoft=18446744073709551615 LimitNOFILE=4096 LimitNOFILESoft=1024 LimitAS=18446744073709551615 LimitASSoft=18446744073709551615 LimitNPROC=63869 LimitNPROCSoft=63869 LimitMEMLOCK=65536 LimitMEMLOCKSoft=65536 LimitLOCKS=18446744073709551615 LimitLOCKSSoft=18446744073709551615 LimitSIGPENDING=63869 LimitSIGPENDINGSoft=63869 LimitMSGQUEUE=819200 LimitMSGQUEUESoft=819200 LimitNICE=0 LimitNICESoft=0 LimitRTPRIO=0 LimitRTPRIOSoft=0 LimitRTTIME=18446744073709551615 LimitRTTIMESoft=18446744073709551615 OOMScoreAdjust=0 Nice=0 IOSchedulingClass=0 IOSchedulingPriority=0 CPUSchedulingPolicy=0 CPUSchedulingPriority=0 TimerSlackNSec=50000 CPUSchedulingResetOnFork=no NonBlocking=no StandardInput=null StandardOutput=journal StandardError=inherit TTYReset=no TTYVHangup=no TTYVTDisallocate=no SyslogPriority=30 SyslogLevelPrefix=yes SyslogLevel=6 SyslogFacility=3 SecureBits=0 CapabilityBoundingSet=18446744073709551615 AmbientCapabilities=0 DynamicUser=no RemoveIPC=no MountFlags=0 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 RuntimeDirectoryMode=0755 MemoryDenyWriteExecute=no RestrictRealtime=no RestrictNamespaces=no MountAPIVFS=no KillMode=control-group KillSignal=15 SendSIGKILL=yes SendSIGHUP=no Id=crio.service Names=crio.service Requires=system.slice sysinit.target Conflicts=shutdown.target Before=shutdown.target After=systemd-journald.socket basic.target system.slice sysinit.target Documentation=https://github.com/cri-o/cri-o Description=CRI-O daemon LoadState=loaded ActiveState=inactive SubState=dead FragmentPath=/etc/systemd/system/crio.service UnitFileState=disabled UnitFilePreset=disabled StateChangeTimestampMonotonic=0 InactiveExitTimestampMonotonic=0 ActiveEnterTimestampMonotonic=0 ActiveExitTimestampMonotonic=0 InactiveEnterTimestampMonotonic=0 CanStart=yes CanStop=yes CanReload=no 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=no AssertResult=no ConditionTimestampMonotonic=0 AssertTimestampMonotonic=0 Transient=no Perpetual=no StartLimitIntervalSec=10000000 StartLimitBurst=5 StartLimitAction=none ``` Output of "`cat /etc/crio/crio.conf`": ``` # The CRI-O configuration file specifies all of the available configuration # options and command-line flags for the crio(8) OCI Kubernetes Container Runtime # daemon, but in a TOML format that can be more easily modified and versioned. # # Please refer to crio.conf(5) for details of all configuration options. # CRI-O supports partial configuration reload during runtime, which can be # done by sending SIGHUP to the running process. Currently supported options # are explicitly mentioned with: 'This option supports live configuration # reload'. # CRI-O reads its storage defaults from the containers-storage.conf(5) file # located at /etc/containers/storage.conf. Modify this storage configuration if # you want to change the system's defaults. If you want to modify storage just # for CRI-O, you can change the storage configuration options here. [crio] # Path to the "root directory". CRI-O stores all of its data, including # containers images, in this directory. #root = "/var/lib/containers/storage" # Path to the "run directory". CRI-O stores all of its state in this directory. #runroot = "/var/run/containers/storage" # Storage driver used to manage the storage of images and containers. Please # refer to containers-storage.conf(5) to see all available storage drivers. #storage_driver = "" # List to pass options to the storage driver. Please refer to # containers-storage.conf(5) to see all available storage options. #storage_option = [ #] # The default log directory where all logs will go unless directly specified by # the kubelet. The log directory specified must be an absolute directory. log_dir = "/var/log/crio/pods" # Location for CRI-O to lay down the version file version_file = "/var/run/crio/version" # The crio.api table contains settings for the kubelet/gRPC interface. [crio.api] # Path to AF_LOCAL socket on which CRI-O will listen. listen = "/var/run/crio/crio.sock" # IP address on which the stream server will listen. stream_address = "127.0.0.1" # The port on which the stream server will listen. If the port is set to "0", then # CRI-O will allocate a random free port number. stream_port = "0" # Enable encrypted TLS transport of the stream server. stream_enable_tls = false # Path to the x509 certificate file used to serve the encrypted stream. This # file can change, and CRI-O will automatically pick up the changes within 5 # minutes. stream_tls_cert = "" # Path to the key file used to serve the encrypted stream. This file can # change and CRI-O will automatically pick up the changes within 5 minutes. stream_tls_key = "" # Path to the x509 CA(s) file used to verify and authenticate client # communication with the encrypted stream. This file can change and CRI-O will # automatically pick up the changes within 5 minutes. stream_tls_ca = "" # Maximum grpc send message size in bytes. If not set or <=0, then CRI-O will default to 16 * 1024 * 1024. grpc_max_send_msg_size = 16777216 # Maximum grpc receive message size. If not set or <= 0, then CRI-O will default to 16 * 1024 * 1024. grpc_max_recv_msg_size = 16777216 # The crio.runtime table contains settings pertaining to the OCI runtime used # and options for how to set up and manage the OCI runtime. [crio.runtime] manage_network_ns_lifecycle = true # A list of ulimits to be set in containers by default, specified as # "=:", for example: # "nofile=1024:2048" # If nothing is set here, settings will be inherited from the CRI-O daemon #default_ulimits = [ #] # default_runtime is the _name_ of the OCI runtime to be used as the default. # The name is matched against the runtimes map below. default_runtime = "runc" # If true, the runtime will not use pivot_root, but instead use MS_MOVE. no_pivot = false # decryption_keys_path is the path where the keys required for # image decryption are stored. decryption_keys_path = "/etc/crio/keys/" # Path to the conmon binary, used for monitoring the OCI runtime. # Will be searched for using $PATH if empty. conmon = "" # Cgroup setting for conmon conmon_cgroup = "system.slice" # Environment variable list for the conmon process, used for passing necessary # environment variables to conmon or the runtime. conmon_env = [ "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", ] # If true, SELinux will be used for pod separation on the host. selinux = false # Path to the seccomp.json profile which is used as the default seccomp profile # for the runtime. If not specified, then the internal default seccomp profile # will be used. seccomp_profile = "" # Used to change the name of the default AppArmor profile of CRI-O. The default # profile name is "crio-default-" followed by the version string of CRI-O. This # profile only takes effect if the user does not specify a profile via the # Kubernetes Pod's metadata annotation. apparmor_profile = "crio-default-1.17.0-dev" # Cgroup management implementation used for the runtime. cgroup_manager = "cgroupfs" # List of default capabilities for containers. If it is empty or commented out, # only the capabilities defined in the containers json file by the user/kube # will be added. default_capabilities = [ "CHOWN", "DAC_OVERRIDE", "FSETID", "FOWNER", "NET_RAW", "SETGID", "SETUID", "SETPCAP", "NET_BIND_SERVICE", "SYS_CHROOT", "KILL", ] # List of default sysctls. If it is empty or commented out, only the sysctls # defined in the container json file by the user/kube will be added. default_sysctls = [ ] # List of additional devices. specified as # "::", for example: "--device=/dev/sdc:/dev/xvdc:rwm". #If it is empty or commented out, only the devices # defined in the container json file by the user/kube will be added. additional_devices = [ ] # Path to OCI hooks directories for automatically executed hooks. If one of the # directories does not exist, then CRI-O will automatically skip them. hooks_dir = [ "/usr/share/containers/oci/hooks.d", ] # List of default mounts for each container. **Deprecated:** this option will # be removed in future versions in favor of default_mounts_file. default_mounts = [ ] # Path to the file specifying the defaults mounts for each container. The # format of the config is /SRC:/DST, one mount per line. Notice that CRI-O reads # its default mounts from the following two files: # # 1) /etc/containers/mounts.conf (i.e., default_mounts_file): This is the # override file, where users can either add in their own default mounts, or # override the default mounts shipped with the package. # # 2) /usr/share/containers/mounts.conf: This is the default file read for # mounts. If you want CRI-O to read from a different, specific mounts file, # you can change the default_mounts_file. Note, if this is done, CRI-O will # only add mounts it finds in this file. # #default_mounts_file = "" # Maximum number of processes allowed in a container. pids_limit = 1024 # Maximum sized allowed for the container log file. Negative numbers indicate # that no size limit is imposed. If it is positive, it must be >= 8192 to # match/exceed conmon's read buffer. The file is truncated and re-opened so the # limit is never exceeded. log_size_max = -1 # Whether container output should be logged to journald in addition to the kuberentes log file log_to_journald = false # Path to directory in which container exit files are written to by conmon. container_exits_dir = "/var/run/crio/exits" # Path to directory for container attach sockets. container_attach_socket_dir = "/var/run/crio" # The prefix to use for the source of the bind mounts. bind_mount_prefix = "" # If set to true, all containers will run in read-only mode. read_only = false # Changes the verbosity of the logs based on the level it is set to. Options # are fatal, panic, error, warn, info, debug and trace. This option supports # live configuration reload. log_level = "info" # Filter the log messages by the provided regular expression. # This option supports live configuration reload. log_filter = "" # The UID mappings for the user namespace of each container. A range is # specified in the form containerUID:HostUID:Size. Multiple ranges must be # separated by comma. uid_mappings = "" # The GID mappings for the user namespace of each container. A range is # specified in the form containerGID:HostGID:Size. Multiple ranges must be # separated by comma. gid_mappings = "" # The minimal amount of time in seconds to wait before issuing a timeout # regarding the proper termination of the container. ctr_stop_timeout = 0 # **DEPRECATED** this option is being replaced by manage_ns_lifecycle, which is described below. # #manage_network_ns_lifecycle = false # manage_ns_lifecycle determines whether we pin and remove namespaces # and manage their lifecycle manage_ns_lifecycle = false # The directory where the state of the managed namespaces gets tracked. # Only used when manage_ns_lifecycle is true. namespaces_dir = "/var/run/crio/ns" # pinns_path is the path to find the pinns binary, which is needed to manage namespace lifecycle pinns_path = "" # The "crio.runtime.runtimes" table defines a list of OCI compatible runtimes. # The runtime to use is picked based on the runtime_handler provided by the CRI. # If no runtime_handler is provided, the runtime will be picked based on the level # of trust of the workload. Each entry in the table should follow the format: # #[crio.runtime.runtimes.runtime-handler] # runtime_path = "/usr/local/bin/crio-runc" # runtime_type = "oci" # runtime_root = "/path/to/the/root" # # Where: # - runtime-handler: name used to identify the runtime # - runtime_path (optional, string): absolute path to the runtime executable in # the host filesystem. If omitted, the runtime-handler identifier should match # the runtime executable name, and the runtime executable should be placed # in $PATH. # - runtime_type (optional, string): type of runtime, one of: "oci", "vm". If # omitted, an "oci" runtime is assumed. # - runtime_root (optional, string): root directory for storage of containers # state. [crio.runtime.runtimes.runc] runtime_path = "/usr/local/bin/crio-runc" runtime_type = "oci" runtime_root = "/run/runc" [crio.runtime.runtimes.kata] runtime_path = "/usr/local/bin/kata-runtime" runtime_root = "/run/vc" runtime_type = "oci" # Kata Containers is an OCI runtime, where containers are run inside lightweight # VMs. Kata provides additional isolation towards the host, minimizing the host attack # surface and mitigating the consequences of containers breakout. # Kata Containers with the default configured VMM #[crio.runtime.runtimes.kata-runtime] # Kata Containers with the QEMU VMM #[crio.runtime.runtimes.kata-qemu] # Kata Containers with the Firecracker VMM #[crio.runtime.runtimes.kata-fc] # The crio.image table contains settings pertaining to the management of OCI images. # # CRI-O reads its configured registries defaults from the system wide # containers-registries.conf(5) located in /etc/containers/registries.conf. If # you want to modify just CRI-O, you can change the registries configuration in # this file. Otherwise, leave insecure_registries and registries commented out to # use the system's defaults from /etc/containers/registries.conf. [crio.image] # Default transport for pulling images from a remote container storage. default_transport = "docker://" # The path to a file containing credentials necessary for pulling images from # secure registries. The file is similar to that of /var/lib/kubelet/config.json global_auth_file = "" # The image used to instantiate infra containers. # This option supports live configuration reload. pause_image = "k8s.gcr.io/pause:3.1" # The path to a file containing credentials specific for pulling the pause_image from # above. The file is similar to that of /var/lib/kubelet/config.json # This option supports live configuration reload. pause_image_auth_file = "" # The command to run to have a container stay in the paused state. # When explicitly set to "", it will fallback to the entrypoint and command # specified in the pause image. When commented out, it will fallback to the # default: "/pause". This option supports live configuration reload. pause_command = "/pause" # Path to the file which decides what sort of policy we use when deciding # whether or not to trust an image that we've pulled. It is not recommended that # this option be used, as the default behavior of using the system-wide default # policy (i.e., /etc/containers/policy.json) is most often preferred. Please # refer to containers-policy.json(5) for more details. signature_policy = "" # List of registries to skip TLS verification for pulling images. Please # consider configuring the registries via /etc/containers/registries.conf before # changing them here. #insecure_registries = "[]" # Controls how image volumes are handled. The valid values are mkdir, bind and # ignore; the latter will ignore volumes entirely. image_volumes = "mkdir" # List of registries to be used when pulling an unqualified image (e.g., # "alpine:latest"). By default, registries is set to "docker.io" for # compatibility reasons. Depending on your workload and usecase you may add more # registries (e.g., "quay.io", "registry.fedoraproject.org", # "registry.opensuse.org", etc.). registries = [ "docker.io" ] # ] # The crio.network table containers settings pertaining to the management of # CNI plugins. [crio.network] # Path to the directory where CNI configuration files are located. network_dir = "/etc/cni/net.d/" # Paths to directories where CNI plugin binaries are located. plugin_dirs = [ "/opt/cni/bin/", ] # A necessary configuration for Prometheus based metrics retrieval [crio.metrics] # Globally enable or disable metrics support. enable_metrics = false # The port on which the metrics server will listen. metrics_port = 9090 ``` Have `containerd` ## containerd Output of "`containerd --version`": ``` containerd github.com/containerd/containerd v1.2.5 bb71b10fd8f58240ca47fbb579b9d1028eea7c84 ``` Output of "`systemctl show containerd`": ``` Restart=no NotifyAccess=none RestartUSec=100ms TimeoutStartUSec=1min 30s TimeoutStopUSec=1min 30s RuntimeMaxUSec=infinity WatchdogUSec=0 WatchdogTimestampMonotonic=0 FailureAction=none PermissionsStartOnly=no RootDirectoryStartOnly=no RemainAfterExit=no GuessMainPID=yes MainPID=0 ControlPID=0 FileDescriptorStoreMax=0 NFileDescriptorStore=0 StatusErrno=0 Result=success UID=4294967295 GID=4294967295 ExecMainStartTimestampMonotonic=0 ExecMainExitTimestampMonotonic=0 ExecMainPID=0 ExecMainCode=0 ExecMainStatus=0 MemoryCurrent=18446744073709551615 CPUUsageNSec=18446744073709551615 TasksCurrent=18446744073709551615 Delegate=no CPUAccounting=no CPUWeight=18446744073709551615 StartupCPUWeight=18446744073709551615 CPUShares=18446744073709551615 StartupCPUShares=18446744073709551615 CPUQuotaPerSecUSec=infinity IOAccounting=no IOWeight=18446744073709551615 StartupIOWeight=18446744073709551615 BlockIOAccounting=no BlockIOWeight=18446744073709551615 StartupBlockIOWeight=18446744073709551615 MemoryAccounting=no MemoryLow=0 MemoryHigh=18446744073709551615 MemoryMax=18446744073709551615 MemorySwapMax=18446744073709551615 MemoryLimit=18446744073709551615 DevicePolicy=auto TasksAccounting=yes TasksMax=19660 UMask=0022 LimitCPU=18446744073709551615 LimitCPUSoft=18446744073709551615 LimitFSIZE=18446744073709551615 LimitFSIZESoft=18446744073709551615 LimitDATA=18446744073709551615 LimitDATASoft=18446744073709551615 LimitSTACK=18446744073709551615 LimitSTACKSoft=8388608 LimitCORE=18446744073709551615 LimitCORESoft=18446744073709551615 LimitRSS=18446744073709551615 LimitRSSSoft=18446744073709551615 LimitNOFILE=1048576 LimitNOFILESoft=1048576 LimitAS=18446744073709551615 LimitASSoft=18446744073709551615 LimitNPROC=63869 LimitNPROCSoft=63869 LimitMEMLOCK=65536 LimitMEMLOCKSoft=65536 LimitLOCKS=18446744073709551615 LimitLOCKSSoft=18446744073709551615 LimitSIGPENDING=63869 LimitSIGPENDINGSoft=63869 LimitMSGQUEUE=819200 LimitMSGQUEUESoft=819200 LimitNICE=0 LimitNICESoft=0 LimitRTPRIO=0 LimitRTPRIOSoft=0 LimitRTTIME=18446744073709551615 LimitRTTIMESoft=18446744073709551615 OOMScoreAdjust=0 Nice=0 IOSchedulingClass=0 IOSchedulingPriority=0 CPUSchedulingPolicy=0 CPUSchedulingPriority=0 TimerSlackNSec=50000 CPUSchedulingResetOnFork=no NonBlocking=no StandardInput=null StandardOutput=inherit StandardError=inherit TTYReset=no TTYVHangup=no TTYVTDisallocate=no SyslogPriority=30 SyslogLevelPrefix=yes SyslogLevel=6 SyslogFacility=3 SecureBits=0 CapabilityBoundingSet=18446744073709551615 AmbientCapabilities=0 DynamicUser=no RemoveIPC=no MountFlags=0 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 RuntimeDirectoryMode=0755 MemoryDenyWriteExecute=no RestrictRealtime=no RestrictNamespaces=no MountAPIVFS=no KillMode=control-group KillSignal=15 SendSIGKILL=yes SendSIGHUP=no Id=containerd.service Names=containerd.service Description=containerd.service LoadState=not-found ActiveState=inactive SubState=dead StateChangeTimestampMonotonic=0 InactiveExitTimestampMonotonic=0 ActiveEnterTimestampMonotonic=0 ActiveExitTimestampMonotonic=0 InactiveEnterTimestampMonotonic=0 CanStart=no CanStop=yes CanReload=no 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=no AssertResult=no ConditionTimestampMonotonic=0 AssertTimestampMonotonic=0 LoadError=org.freedesktop.DBus.Error.FileNotFound "No such file or directory" Transient=no Perpetual=no StartLimitIntervalSec=10000000 StartLimitBurst=5 StartLimitAction=none ``` Output of "`cat /etc/containerd/config.toml`": ``` # See containerd-config.toml(5) for documentation. ``` --- # Packages No `dpkg` Have `rpm` Output of "`rpm -qa|egrep "(cc-oci-runtimecc-runtimerunv|kata-proxy|kata-runtime|kata-shim|kata-ksm-throttler|kata-containers-image|linux-container|qemu-)"`": ``` ``` ---

/cc @bergwolf

chavafg commented 4 years ago

I think this is related to #2314

GabyCT commented 4 years ago

yes @chavafg it seems like the same issue

egernst commented 4 years ago

This was easy to reproduce on 1.11.1 along with Docker version 19.03.12 (on Ubuntu). In the case of QEMU, the corresponding containerd shim process is left running on the system. Latest message from the shim:

Aug 17 21:43:49 ubuntu kata-shim[352596]: time="2020-08-17T21:43:49.362281847-07:00" level=info msg="copy stdout failed" container=69a94b89b92c6483a728d80ce8702f2c9112b90d327e4f7771882ebab26c6d33 error="rpc error: code = Unavailable desc = transport is closing" exec-id=69a94b89b92c6483a728d80ce8702f2c9112b90d327e4f7771882ebab26c6d33 name=kata-shim pid=1 source=shim
Aug 17 21:43:49 ubuntu kata-shim[352596]: time="2020-08-17T21:43:49.36360816-07:00" level=error msg="failed waiting for process" container=69a94b89b92c6483a728d80ce8702f2c9112b90d327e4f7771882ebab26c6d33 error="rpc error: code = Unavailable desc = transport is closing" exec-id=69a94b89b92c6483a728d80ce8702f2c9112b90d327e4f7771882ebab26c6d33 name=kata-shim pid=1 source=shim

When doing same test with CLH, I see both the corresponding containerd shim process as well as kata-shim left running on the host. Last message from shim:

Aug 17 21:41:06 ubuntu kata-shim[350116]: time="2020-08-17T21:41:06.984121559-07:00" level=debug msg="handling signal" container=91b9a01e7cf1dbb4d9dd8be16a98d2a2c70d5447f0fbc3820ce25baf29961a72 exec-id=91b9a01e7cf1dbb4d9dd8be16a98d2a2c70d5447f0fbc3820ce25baf29961a72 name=kata-shim pid=1 signal="urgent I/O condition" source=shim

Not sure why the reaping/signal handling isn't happening here -- Containerd-shim should clean up once kata-shim is killed, AFAIU....

rhafer commented 4 years ago

IIUC this can be attributed to this commit in containerd: https://github.com/containerd/containerd/commit/b5ccc66c2c814cfc21d58678c854272427814b59#diff-6a93af2fa6a81ffa3592c6ba4c7f628976e9ac0363a9532589b0fc96f3059ad1 which is vendored into newer docker releases. Basically with that containerd will no longer endup calling kata-runtime kill --all .... but kata-runtime delete ... when the QEMU process is killed. And delete will not succeed if kata-runtime fails to connect to the QEMU socket.

I am not sure exactly how to fix that in kata-runtime, but I guess one way would be to just ignore the connection error and consider the sandbox stopped (similar to what kata-runtime delete --force already does).