Runtime: kata-runtime hung after container creation failure
Description of problem
I am using the kata-runtime with containerd and kubernetes:
after a failure in pod creation, the kata-runtime hung after pod creation failure due to invalid command in pod spec
peter@ubuntu:~/k8s$ sudo kata-runtime list
^C
the kata-runtime list will never return
Expected result
The kata-runtime should remove any left-over if failed and the should not block the further pod creation
Actual result
# logs from containerd
35525 Jan 03 22:48:55 ubuntu containerd[1019]: time="2019-01-03T22:48:55.305383889-08:00" level=error msg="StartContainer for "ea93a5e0745f93c9bcf41e5f0be32c90 64c68e9b2626d46affd2296779a9da3a" failed" error="failed to create containerd task: OCI runtime create failed: rpc error: code = Internal desc = Could not run process: container_linux.go:348: starting container process caused "exec: \"--cpu\": executable file not found in $PATH": unknown"
35526 Jan 03 22:48:56 ubuntu containerd[1019]: time="2019-01-03T22:48:56.312998153-08:00" level=info msg="PullImage "docker.io/progrium/stress:latest" with aut h config nil"
ps -ef | grep b204b4
root 38013 1 0 Jan03 ? 00:00:00 containerd-shim -namespace k8s.io -workdir /var/lib/containerd/io.containerd.runtime.v1.linux/k8s.io/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 -address /run/containerd/containerd.sock -containerd-binary /usr/bin/containerd
root 38034 38013 0 Jan03 ? 00:00:04 /usr/bin/qemu-lite-system-x86_64 -name sandbox-b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 -uuid e0d9581a-eb80-4f84-9880-29fc9d71d944 -machine pc,accel=kvm,kernel_irqchip,nvdimm -cpu host,pmu=off -qmp unix:/run/vc/vm/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/qmp.sock,server,nowait -m 2048M,slots=10,maxmem=4002M -device pci-bridge,bus=pci.0,id=pci-bridge-0,chassis_nr=1,shpc=on,addr=2,romfile= -device virtio-serial-pci,disable-modern=true,id=serial0,romfile= -device virtconsole,chardev=charconsole0,id=console0 -chardev socket,id=charconsole0,path=/run/vc/vm/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/console.sock,server,nowait -device nvdimm,id=nv0,memdev=mem0 -object memory-backend-file,id=mem0,mem-path=/usr/share/kata-containers/kata-containers-image_clearlinux_1.4.1_agent_3cf32a0a6b0.img,size=536870912 -device virtio-scsi-pci,id=scsi0,disable-modern=true,romfile= -object rng-random,id=rng0,filename=/dev/urandom -device virtio-rng,rng=rng0,romfile= -device virtserialport,chardev=charch0,id=channel0,name=agent.channel.0 -chardev socket,id=charch0,path=/run/vc/vm/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/kata.sock,server,nowait -device virtio-9p-pci,disable-modern=true,fsdev=extra-9p-kataShared,mount_tag=kataShared,romfile= -fsdev local,id=extra-9p-kataShared,path=/run/kata-containers/shared/sandboxes/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77,security_model=none -netdev tap,id=network-0,vhost=on,vhostfds=3,fds=4 -device driver=virtio-net-pci,netdev=network-0,mac=9a:06:e4:89:98:2d,disable-modern=true,mq=on,vectors=4,romfile= -global kvm-pit.lost_tick_policy=discard -vga none -no-user-config -nodefaults -nographic -daemonize -kernel /usr/share/kata-containers/vmlinuz-4.14.67.19-4.container -append tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 quiet systemd.show_status=false panic=1 nr_cpus=3 init=/usr/lib/systemd/systemd systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket -smp 1,cores=1,threads=1,sockets=1,maxcpus=3
root 38041 38013 0 Jan03 ? 00:00:03 /usr/libexec/kata-containers/kata-proxy -listen-socket unix:///run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/proxy.sock -mux-socket /run/vc/vm/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/kata.sock -sandbox b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77
root 38204 38013 0 Jan03 ? 00:00:00 /usr/libexec/kata-containers/kata-shim -agent unix:///run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/proxy.sock -container b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 -exec-id b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77
root 48163 38013 0 Jan03 ? 00:00:00 /usr/bin/kata-runtime --root /run/containerd/runc/k8s.io --log /run/containerd/io.containerd.runtime.v1.linux/k8s.io/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/log.json --log-format json state b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77
further more the kata-runtime never free the file lock
peter@ubuntu:~/k8s$ sudo ls -l /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
-rw-r--r-- 1 root root 0 Jan 3 22:47 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
peter@ubuntu:~/k8s$ sudo flock --shared /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock ls
^C
the flock will never return as the file was locked by the kata-runtime process
sudo lsof | grep /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40291 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40292 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40293 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40294 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40295 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40296 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40297 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40299 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40300 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 40290 40301 root 7rW REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48164 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48165 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48166 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48167 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48168 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48169 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
kata-runt 48163 48170 root 6r REG 0,23 0 1279 /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/lock
peter@ubuntu:~/k8s$ ps -ef | grep 40290
root 40290 40281 0 Jan03 ? 00:00:00 /usr/bin/kata-runtime --root /run/containerd/runc/k8s.io --log /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020/log.json --log-format json create --bundle /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020 --pid-file /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020/init.pid 17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020
- more inportantly, the kubelet now became NotReady, due to the hung of containerd/kata-runtime.
(replace this text with the output of the kata-collect-data.sh script, after
you have reviewed its content to ensure it does not contain any private
information).
peter@ubuntu:~/k8s$ sudo kata-collect-data.sh
Meta details
Running kata-collect-data.sh version 1.4.1 (commit 45ea48e) at 2019-01-04.03:24:20.486242806-0800.
Runtime is /usr/bin/kata-runtime.
kata-env
Output of "/usr/bin/kata-runtime kata-env":
[Meta]
Version = "1.0.19"
[Runtime]
Debug = false
DisableNewNetNs = false
Path = "/usr/bin/kata-runtime"
[Runtime.Version]
Semver = "1.4.1"
Commit = "45ea48e"
OCI = "1.0.1-dev"
[Runtime.Config]
Path = "/usr/share/defaults/kata-containers/configuration.toml"
[Hypervisor]
MachineType = "pc"
Version = "QEMU emulator version 2.11.0\nCopyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers"
Path = "/usr/bin/qemu-lite-system-x86_64"
BlockDeviceDriver = "virtio-scsi"
EntropySource = "/dev/urandom"
Msize9p = 8192
MemorySlots = 10
Debug = false
UseVSock = false
[Image]
Path = "/usr/share/kata-containers/kata-containers-image_clearlinux_1.4.1_agent_3cf32a0a6b0.img"
[Kernel]
Path = "/usr/share/kata-containers/vmlinuz-4.14.67.19-4.container"
Parameters = ""
[Initrd]
Path = ""
[Proxy]
Type = "kataProxy"
Version = "kata-proxy version 1.4.1-6553b83"
Path = "/usr/libexec/kata-containers/kata-proxy"
Debug = false
[Shim]
Type = "kataShim"
Version = "kata-shim version 1.4.1-6346110"
Path = "/usr/libexec/kata-containers/kata-shim"
Debug = false
[Agent]
Type = "kata"
[Host]
Kernel = "4.15.0-43-generic"
Architecture = "amd64"
VMContainerCapable = true
SupportVSocks = true
[Host.Distro]
Name = "Ubuntu"
Version = "18.04"
[Host.CPU]
Vendor = "GenuineIntel"
Model = "Intel(R) Core(TM) i7-4770HQ CPU @ 2.20GHz"
[Netmon]
Version = "kata-netmon version 1.4.1"
Path = "/usr/libexec/kata-containers/kata-netmon"
Debug = false
Enable = false
Runtime config files
Runtime default config files
/etc/kata-containers/configuration.toml
/usr/share/defaults/kata-containers/configuration.toml
Runtime config file contents
Config file /etc/kata-containers/configuration.toml not found
Output of "cat "/usr/share/defaults/kata-containers/configuration.toml"":
# Copyright (c) 2017-2018 Intel Corporation
#
# SPDX-License-Identifier: Apache-2.0
#
# XXX: WARNING: this file is auto-generated.
# XXX:
# XXX: Source file: "cli/config/configuration.toml.in"
# XXX: Project:
# XXX: Name: Kata Containers
# XXX: Type: kata
[hypervisor.qemu]
path = "/usr/bin/qemu-lite-system-x86_64"
kernel = "/usr/share/kata-containers/vmlinuz.container"
image = "/usr/share/kata-containers/kata-containers.img"
machine_type = "pc"
# Optional space-separated list of options to pass to the guest kernel.
# For example, use `kernel_params = "vsyscall=emulate"` if you are having
# trouble running pre-2.15 glibc.
#
# WARNING: - any parameter specified here will take priority over the default
# parameter value of the same name used to start the virtual machine.
# Do not set values here unless you understand the impact of doing so as you
# may stop the virtual machine from booting.
# To see the list of default parameters, enable hypervisor debug, create a
# container and look for 'default-kernel-parameters' log entries.
kernel_params = ""
# 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
# Disable block device from being used for a container's rootfs.
# In case of a storage driver like devicemapper where a container's
# root file system is backed by a block device, the block device is passed
# directly to the hypervisor for performance reasons.
# This flag prevents the block device from being passed to the hypervisor,
# 9pfs is used instead to pass the rootfs.
disable_block_device_use = false
# Block storage driver to be used for the hypervisor in case the container
# rootfs is backed by a block device. This is either virtio-scsi or
# virtio-blk.
block_device_driver = "virtio-scsi"
# Enable iothreads (data-plane) to be used. This causes IO to be
# handled in a separate IO thread. This is currently only implemented
# for SCSI.
#
enable_iothreads = false
# Enable pre allocation of VM RAM, default false
# Enabling this will result in lower container density
# as all of the memory will be allocated and locked
# This is useful when you want to reserve all the memory
# upfront or in the cases where you want memory latencies
# to be very predictable
# Default false
#enable_mem_prealloc = true
# Enable huge pages for VM RAM, default false
# Enabling this will result in the VM memory
# being allocated using huge pages.
# This is useful when you want to use vhost-user network
# stacks within the container. This will automatically
# result in memory pre allocation
#enable_hugepages = true
# Enable swap of vm memory. Default false.
# The behaviour is undefined if mem_prealloc is also set to true
#enable_swap = true
# This option changes the default hypervisor and kernel parameters
# to enable debug output where available. This extra output is added
# to the proxy logs, but only when proxy debug is also enabled.
#
# Default false
#enable_debug = true
# Disable the customizations done in the runtime when it detects
# that it is running on top a VMM. This will result in the runtime
# behaving as it would when running on bare metal.
#
#disable_nesting_checks = true
# This is the msize used for 9p shares. It is the number of bytes
# used for 9p packet payload.
#msize_9p = 8192
# If true and vsocks are supported, use vsocks to communicate directly
# with the agent and no proxy is started, otherwise use unix
# sockets and start a proxy to communicate with the agent.
# Default false
#use_vsock = true
# VFIO devices are hotplugged on a bridge by default.
# Enable hotplugging on root bus. This may be required for devices with
# a large PCI bar, as this is a current limitation with hotplugging on
# a bridge. This value is valid for "pc" machine type.
# Default false
#hotplug_vfio_on_root_bus = true
# If host doesn't support vhost_net, set to true. Thus we won't create vhost fds for nics.
# Default false
#disable_vhost_net = true
#
# Default entropy source.
# The path to a host source of entropy (including a real hardware RNG)
# /dev/urandom and /dev/random are two main options.
# Be aware that /dev/random is a blocking source of entropy. If the host
# runs out of entropy, the VMs boot time will increase leading to get startup
# timeouts.
# The source of entropy /dev/urandom is non-blocking and provides a
# generally acceptable source of entropy. It should work well for pretty much
# all practical purposes.
#entropy_source= "/dev/urandom"
# Path to OCI hook binaries in the *guest rootfs*.
# This does not affect host-side hooks which must instead be added to
# the OCI spec passed to the runtime.
#
# You can create a rootfs with hooks by customizing the osbuilder scripts:
# https://github.com/kata-containers/osbuilder
#
# Hooks must be stored in a subdirectory of guest_hook_path according to their
# hook type, i.e. "guest_hook_path/{prestart,postart,poststop}".
# The agent will scan these directories for executable files and add them, in
# lexicographical order, to the lifecycle of the guest container.
# Hooks are executed in the runtime namespace of the guest. See the official documentation:
# https://github.com/opencontainers/runtime-spec/blob/v1.0.1/config.md#posix-platform-hooks
# Warnings will be logged if any error is encountered will scanning for hooks,
# but it will not abort container execution.
#guest_hook_path = "/usr/share/oci/hooks"
[factory]
# VM templating support. Once enabled, new VMs are created from template
# using vm cloning. They will share the same initial kernel, initramfs and
# agent memory by mapping it readonly. It helps speeding up new container
# creation and saves a lot of memory if there are many kata containers running
# on the same host.
#
# When disabled, new VMs are created from scratch.
#
# Default false
#enable_template = true
[proxy.kata]
path = "/usr/libexec/kata-containers/kata-proxy"
# If enabled, proxy messages will be sent to the system log
# (default: disabled)
#enable_debug = true
[shim.kata]
path = "/usr/libexec/kata-containers/kata-shim"
# If enabled, shim messages will be sent to the system log
# (default: disabled)
#enable_debug = true
[agent.kata]
# There is no field for this section. The goal is only to be able to
# specify which type of agent the user wants to use.
[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:
#
# - bridged
# Uses a linux bridge to interconnect the container interface to
# the VM. Works for most cases except macvlan and ipvlan.
#
# - macvtap
# Used when the Container network interface can be bridged using
# macvtap.
#
# - none
# Used when customize network. Only creates a tap device. No veth pair.
#
# - tcfilter
# Uses tc filter rules to redirect traffic from the network interface
# provided by plugin to a tap interface connected to the VM.
#
internetworking_model="macvtap"
# If enabled, the runtime will create opentracing.io traces and spans.
# (See https://www.jaegertracing.io/docs/getting-started).
# (default: disabled)
#enable_tracing = true
# If enabled, the runtime will not create a network namespace for shim and hypervisor processes.
# This option may have some potential impacts to your host. It should only be used when you know what you're doing.
# `disable_new_netns` conflicts with `enable_netmon`
# `disable_new_netns` conflicts with `internetworking_model=bridged` and `internetworking_model=macvtap`. It works only
# with `internetworking_model=none`. The tap device will be in the host network namespace and can connect to a bridge
# (like OVS) directly.
# If you are using docker, `disable_new_netns` only works with `docker run --net=none`
# (default: false)
#disable_new_netns = true
KSM throttler
version
Output of "/usr/libexec/kata-ksm-throttler/kata-ksm-throttler --version":
kata-ksm-throttler version 1.5.0-rc1-83ecff0
systemd service
Image details
---
osbuilder:
url: "https://github.com/kata-containers/osbuilder"
version: "unknown"
rootfs-creation-time: "2018-12-11T01:27:16.046924344+0000Z"
description: "osbuilder rootfs"
file-format-version: "0.0.2"
architecture: "x86_64"
base-distro:
name: "Clear"
version: "26730"
packages:
default:
- "iptables-bin"
- "libudev0-shim"
- "systemd"
extra:
agent:
url: "https://github.com/kata-containers/agent"
name: "kata-agent"
version: "1.4.1-3cf32a0a6b03b3b64c1ffbda3b7bb91876f7f2aa"
agent-is-init-daemon: "no"
Initrd details
No initrd
Logfiles
Runtime logs
Recent runtime problems found in system journal:
time="2019-01-03T07:43:15.130425375-08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3 error="open /run/vc/sbs/dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3/devices.json: no such file or directory" name=kata-runtime pid=61097 sandbox=dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3 sandboxid=dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3 source=virtcontainers subsystem=sandbox
time="2019-01-03T08:24:17.322110615-08:00" level=error msg="open /var/lib/vc/sbs: permission denied" arch=amd64 command=list name=kata-runtime pid=86352 source=runtime
time="2019-01-03T18:52:08.793575866-08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd error="open /run/vc/sbs/e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd/devices.json: no such file or directory" name=kata-runtime pid=15009 sandbox=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd sandboxid=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd source=virtcontainers subsystem=sandbox
time="2019-01-03T18:52:10.956422277-08:00" level=warning msg="unsupported address" address="fe80::f80c:78ff:fe3e:eb84/64" arch=amd64 command=create container=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd name=kata-runtime pid=15009 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-01-03T18:52:10.956924821-08:00" level=warning msg="unsupported route" arch=amd64 command=create container=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd destination="fe80::/64" name=kata-runtime pid=15009 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-01-03T18:59:50.010565743-08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 error="open /run/vc/sbs/7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26/devices.json: no such file or directory" name=kata-runtime pid=23311 sandbox=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 sandboxid=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 source=virtcontainers subsystem=sandbox
time="2019-01-03T18:59:54.066277225-08:00" level=warning msg="unsupported address" address="fe80::98f8:98ff:fefa:af86/64" arch=amd64 command=create container=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 name=kata-runtime pid=23311 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-01-03T18:59:54.06642583-08:00" level=warning msg="unsupported route" arch=amd64 command=create container=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 destination="fe80::/64" name=kata-runtime pid=23311 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-01-03T19:17:05.10098675-08:00" level=error msg="open /var/lib/vc/sbs: permission denied" arch=amd64 command=list name=kata-runtime pid=40772 source=runtime
time="2019-01-03T22:29:58.587163322-08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591 error="open /run/vc/sbs/062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591/devices.json: no such file or directory" name=kata-runtime pid=127682 sandbox=062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591 sandboxid=062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591 source=virtcontainers subsystem=sandbox
time="2019-01-03T22:30:01.160753044-08:00" level=warning msg="unsupported address" address="fe80::6c14:4bff:fe71:d663/64" arch=amd64 command=create container=062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591 name=kata-runtime pid=127682 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-01-03T22:30:01.160917982-08:00" level=warning msg="unsupported route" arch=amd64 command=create container=062e90c2ad88ce1fa0b5cd3033bcc3f10ee1fb8d3ab02845e927693281329591 destination="fe80::/64" name=kata-runtime pid=127682 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-01-03T22:47:25.037365638-08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 error="open /run/vc/sbs/b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77/devices.json: no such file or directory" name=kata-runtime pid=38022 sandbox=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 sandboxid=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 source=virtcontainers subsystem=sandbox
time="2019-01-03T22:47:28.264644201-08:00" level=warning msg="unsupported address" address="fe80::9806:e4ff:fe89:982d/64" arch=amd64 command=create container=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 name=kata-runtime pid=38022 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-01-03T22:47:28.265268812-08:00" level=warning msg="unsupported route" arch=amd64 command=create container=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 destination="fe80::/64" name=kata-runtime pid=38022 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-01-03T22:48:55.244124347-08:00" level=error msg="rpc error: code = Internal desc = Could not run process: container_linux.go:348: starting container process caused \"exec: \\\"--cpu\\\": executable file not found in $PATH\"" arch=amd64 command=create container=ea93a5e0745f93c9bcf41e5f0be32c9064c68e9b2626d46affd2296779a9da3a name=kata-runtime pid=40050 sandbox=b204b427bdd182951ebce4118225c50cafa3847622ccae98e13b2215b5876d77 source=runtime
time="2019-01-03T23:06:08.587695914-08:00" level=error msg="open /var/lib/vc/sbs: permission denied" arch=amd64 command=list name=kata-runtime pid=49404 source=runtime
time="2019-01-03T23:30:09.182161269-08:00" level=error msg="Container ID (07d2e63abbef02e34fe9bcddbb7fa178972e6827f5fea51c39438b54e7468655) does not exist" arch=amd64 command=delete container=07d2e63abbef02e34fe9bcddbb7fa178972e6827f5fea51c39438b54e7468655 name=kata-runtime pid=51487 source=runtime
time="2019-01-03T23:30:11.286663424-08:00" level=error msg="Container ID (3a6d50eec0cd84f1858529affd836e925ba8a6b69dbda757302931f902180b60) does not exist" arch=amd64 command=delete container=3a6d50eec0cd84f1858529affd836e925ba8a6b69dbda757302931f902180b60 name=kata-runtime pid=51530 source=runtime
Proxy logs
Recent proxy problems found in system journal:
time="2019-01-03T07:44:00.157307679-08:00" level=fatal msg="channel error" error="accept unix /run/vc/sbs/dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3/proxy.sock: use of closed network connection" name=kata-proxy pid=61217 sandbox=dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3 source=proxy
time="2019-01-03T07:44:00.1576867-08:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3/kata.sock: use of closed network connection" name=kata-proxy pid=61217 sandbox=dca461e3976fd01c7a87a9b4de8b2369bccdf5b1fc64d7bc5d323080df7a3bf3 source=proxy
time="2019-01-03T22:29:59.042769868-08:00" level=fatal msg="channel error" error="accept unix /run/vc/sbs/7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26/proxy.sock: use of closed network connection" name=kata-proxy pid=23330 sandbox=7a89251d1ab4120fbcc7ba2a9af7d242cc385c511b7a33e4d48489eeea358b26 source=proxy
time="2019-01-03T22:47:58.163312292-08:00" level=fatal msg="channel error" error="accept unix /run/vc/sbs/e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd/proxy.sock: use of closed network connection" name=kata-proxy pid=15041 sandbox=e70d8f665d8da2079cc9e03506d3f0733801fdf5622abfee7749ab5ae7c076bd source=proxy
Shim logs
No recent shim problems found in system journal.
Throttler logs
No recent throttler problems found in system journal.
Container manager details
Have docker
Docker
Output of "docker version":
Client:
Version: 18.09.0
API version: 1.39
Go version: go1.10.4
Git commit: 4d60db4
Built: Wed Nov 7 00:49:01 2018
OS/Arch: linux/amd64
Experimental: false
Server: Docker Engine - Community
Engine:
Version: 18.09.0
API version: 1.39 (minimum version 1.12)
Go version: go1.10.4
Git commit: 4d60db4
Built: Wed Nov 7 00:16:44 2018
OS/Arch: linux/amd64
Experimental: false
Output of "docker info":
Containers: 0
Running: 0
Paused: 0
Stopped: 0
Images: 12
Server Version: 18.09.0
Storage Driver: overlay2
Backing Filesystem: extfs
Supports d_type: true
Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
Volume: local
Network: bridge host macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: kata-runtime runc
Default Runtime: runc
Init Binary: docker-init
containerd version: c4446665cb9c30056f4998ed953e6d4ff22c7c39
runc version: 4fc53a81fb7c994640722ac585fa9ca548971871
init version: fec3683
Security Options:
apparmor
seccomp
Profile: default
Kernel Version: 4.15.0-43-generic
Operating System: Ubuntu 18.04.1 LTS
OSType: linux
Architecture: x86_64
CPUs: 3
Total Memory: 2.908GiB
Name: ubuntu
ID: QL43:4ZYI:46HP:SP35:ZGYY:GBAW:W54Z:2GQL:S25Y:EWOW:H4EA:JWZ3
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
File Descriptors: 22
Goroutines: 37
System Time: 2019-01-04T03:24:21.930782066-08:00
EventsListeners: 0
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
127.0.0.0/8
Registry Mirrors:
https://rflxlgcf.mirror.aliyuncs.com/
Live Restore Enabled: false
Product License: Community Engine
WARNING: No swap limit support
Output of "systemctl show docker":
Type=notify
Restart=always
NotifyAccess=main
RestartUSec=2s
TimeoutStartUSec=infinity
TimeoutStopUSec=infinity
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestamp=Thu 2019-01-03 22:59:09 PST
WatchdogTimestampMonotonic=15899556125
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=48325
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestamp=Thu 2019-01-03 22:59:08 PST
ExecMainStartTimestampMonotonic=15898961214
ExecMainExitTimestampMonotonic=0
ExecMainPID=48325
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/dockerd ; argv[]=/usr/bin/dockerd -D --add-runtime kata-runtime=/usr/bin/kata-runtime --default-runtime=runc ; ignore_errors=no ; start_time=[Thu 2019-01-03 22:59:08 PST] ; stop_time=[n/a] ; pid=48325 ; 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=[not set]
CPUUsageNSec=[not set]
TasksCurrent=15
IPIngressBytes=18446744073709551615
IPIngressPackets=18446744073709551615
IPEgressBytes=18446744073709551615
IPEgressPackets=18446744073709551615
Delegate=yes
DelegateControllers=cpu cpuacct io blkio memory devices pids
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=no
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=infinity
IPAccounting=no
UMask=0022
LimitCPU=infinity
LimitCPUSoft=infinity
LimitFSIZE=infinity
LimitFSIZESoft=infinity
LimitDATA=infinity
LimitDATASoft=infinity
LimitSTACK=infinity
LimitSTACKSoft=8388608
LimitCORE=infinity
LimitCORESoft=infinity
LimitRSS=infinity
LimitRSSSoft=infinity
LimitNOFILE=infinity
LimitNOFILESoft=infinity
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=infinity
LimitNPROCSoft=infinity
LimitMEMLOCK=16777216
LimitMEMLOCKSoft=16777216
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=11661
LimitSIGPENDINGSoft=11661
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=0
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
KillMode=process
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=docker.service
Names=docker.service
Requires=sysinit.target system.slice
Wants=network-online.target
BindsTo=containerd.service
WantedBy=multi-user.target
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=network-online.target firewalld.service systemd-journald.socket sysinit.target basic.target system.slice
Documentation=https://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/docker.service
DropInPaths=/etc/systemd/system/docker.service.d/kata-containers.conf
UnitFileState=enabled
UnitFilePreset=enabled
StateChangeTimestamp=Thu 2019-01-03 22:59:09 PST
StateChangeTimestampMonotonic=15899556128
InactiveExitTimestamp=Thu 2019-01-03 22:59:08 PST
InactiveExitTimestampMonotonic=15898961273
ActiveEnterTimestamp=Thu 2019-01-03 22:59:09 PST
ActiveEnterTimestampMonotonic=15899556128
ActiveExitTimestamp=Thu 2019-01-03 22:59:08 PST
ActiveExitTimestampMonotonic=15898886139
InactiveEnterTimestamp=Thu 2019-01-03 22:59:08 PST
InactiveEnterTimestampMonotonic=15898957893
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Thu 2019-01-03 22:59:08 PST
ConditionTimestampMonotonic=15898959057
AssertTimestamp=Thu 2019-01-03 22:59:08 PST
AssertTimestampMonotonic=15898959057
Transient=no
Perpetual=no
StartLimitIntervalUSec=1min
StartLimitBurst=3
StartLimitAction=none
FailureAction=none
SuccessAction=none
InvocationID=f196f5b3ad604b6a84776918ab3d6266
CollectMode=inactive
Have kubectl
Kubernetes
Output of "kubectl version":
Client Version: version.Info{Major:"1", Minor:"13", GitVersion:"v1.13.1", GitCommit:"eec55b9ba98609a46fee712359c7b5b365bdd920", GitTreeState:"clean", BuildDate:"2018-12-13T10:39:04Z", GoVersion:"go1.11.2", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"13", GitVersion:"v1.13.1", GitCommit:"eec55b9ba98609a46fee712359c7b5b365bdd920", GitTreeState:"clean", BuildDate:"2018-12-13T10:31:33Z", GoVersion:"go1.11.2", Compiler:"gc", Platform:"linux/amd64"}
Output of "kubectl config view":
apiVersion: v1
clusters:
- cluster:
certificate-authority-data: DATA+OMITTED
server: https://172.16.166.157:6443
name: kubernetes
contexts:
- context:
cluster: kubernetes
user: kubernetes-admin
name: kubernetes-admin@kubernetes
current-context: kubernetes-admin@kubernetes
kind: Config
preferences: {}
users:
- name: kubernetes-admin
user:
client-certificate-data: REDACTED
client-key-data: REDACTED
Output of "systemctl show kubelet":
Type=simple
Restart=always
NotifyAccess=none
RestartUSec=10s
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestamp=Thu 2019-01-03 22:57:47 PST
WatchdogTimestampMonotonic=15817750901
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=47978
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestamp=Thu 2019-01-03 22:57:47 PST
ExecMainStartTimestampMonotonic=15817750796
ExecMainExitTimestampMonotonic=0
ExecMainPID=47978
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/kubelet ; argv[]=/usr/bin/kubelet $KUBELET_KUBECONFIG_ARGS $KUBELET_CONFIG_ARGS $KUBELET_KUBEADM_ARGS $KUBELET_EXTRA_ARGS ; ignore_errors=no ; start_time=[Thu 2019-01-03 22:57:47 PST] ; stop_time=[n/a] ; pid=47978 ; code=(null) ; status=0/0 }
Slice=system.slice
ControlGroup=/system.slice/kubelet.service
MemoryCurrent=[not set]
CPUUsageNSec=[not set]
TasksCurrent=19
IPIngressBytes=18446744073709551615
IPIngressPackets=18446744073709551615
IPEgressBytes=18446744073709551615
IPEgressPackets=18446744073709551615
Delegate=no
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=no
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=3498
IPAccounting=no
Environment=[unprintable] KUBELET_CONFIG_ARGS=--config=/var/lib/kubelet/config.yaml [unprintable]
EnvironmentFile=/var/lib/kubelet/kubeadm-flags.env (ignore_errors=yes)
UMask=0022
LimitCPU=infinity
LimitCPUSoft=infinity
LimitFSIZE=infinity
LimitFSIZESoft=infinity
LimitDATA=infinity
LimitDATASoft=infinity
LimitSTACK=infinity
LimitSTACKSoft=8388608
LimitCORE=infinity
LimitCORESoft=0
LimitRSS=infinity
LimitRSSSoft=infinity
LimitNOFILE=4096
LimitNOFILESoft=1024
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=11661
LimitNPROCSoft=11661
LimitMEMLOCK=16777216
LimitMEMLOCKSoft=16777216
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=11661
LimitSIGPENDINGSoft=11661
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=0
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
KillMode=control-group
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=kubelet.service
Names=kubelet.service
Requires=sysinit.target system.slice
WantedBy=multi-user.target
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=sysinit.target basic.target systemd-journald.socket system.slice
Documentation=https://kubernetes.io/docs/home/
Description=kubelet: The Kubernetes Node Agent
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/kubelet.service
DropInPaths=/etc/systemd/system/kubelet.service.d/10-kubeadm.conf
UnitFileState=enabled
UnitFilePreset=enabled
StateChangeTimestamp=Thu 2019-01-03 22:57:47 PST
StateChangeTimestampMonotonic=15817750905
InactiveExitTimestamp=Thu 2019-01-03 22:57:47 PST
InactiveExitTimestampMonotonic=15817750905
ActiveEnterTimestamp=Thu 2019-01-03 22:57:47 PST
ActiveEnterTimestampMonotonic=15817750905
ActiveExitTimestamp=Thu 2019-01-03 22:57:47 PST
ActiveExitTimestampMonotonic=15817693519
InactiveEnterTimestamp=Thu 2019-01-03 22:57:47 PST
InactiveEnterTimestampMonotonic=15817744786
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=yes
AssertResult=yes
ConditionTimestamp=Thu 2019-01-03 22:57:47 PST
ConditionTimestampMonotonic=15817746892
AssertTimestamp=Thu 2019-01-03 22:57:47 PST
AssertTimestampMonotonic=15817746892
Transient=no
Perpetual=no
StartLimitIntervalUSec=0
StartLimitBurst=5
StartLimitAction=none
FailureAction=none
SuccessAction=none
InvocationID=5cc7bc157992488daa2108b72fb718d6
CollectMode=inactive
No crio
Packages
Have dpkg
Output of "dpkg -l|egrep "(cc-oci-runtimecc-runtimerunv|kata-proxy|kata-runtime|kata-shim|kata-ksm-throttler|kata-containers-image|linux-container|qemu-)"":
ii ipxe-qemu-256k-compat-efi-roms 1.0.0+git-20150424.a25a16d-0ubuntu2 all PXE boot firmware - Compat EFI ROM images for qemu
ii kata-containers-image 1.4.1-4 amd64 Kata containers image
ii kata-ksm-throttler 1.4.1.git+83ecff0-4 amd64
ii kata-linux-container 4.14.67.19-4 amd64 linux kernel optimised for container-like workloads.
ii kata-proxy 1.4.1+git.6553b83-4 amd64
ii kata-runtime 1.4.1+git.45ea48e-4 amd64
ii kata-shim 1.4.1+git.6346110-4 amd64
ii qemu-block-extra:amd64 1:2.11+dfsg-1ubuntu7.9 amd64 extra block backend modules for qemu-system and qemu-utils
ii qemu-kvm 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU Full virtualization on x86 hardware
ii qemu-lite 2.11.0+git.87517afd72-4 amd64 linux kernel optimised for container-like workloads.
ii qemu-slof 20170724+dfsg-1ubuntu1 all Slimline Open Firmware -- QEMU PowerPC version
ii qemu-system 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries
ii qemu-system-arm 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (arm)
ii qemu-system-common 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (common files)
ii qemu-system-mips 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (mips)
ii qemu-system-misc 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (miscellaneous)
ii qemu-system-ppc 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (ppc)
ii qemu-system-s390x 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (s390x)
ii qemu-system-sparc 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (sparc)
ii qemu-system-x86 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU full system emulation binaries (x86)
ii qemu-user 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU user mode emulation binaries
ii qemu-user-binfmt 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU user mode binfmt registration for qemu-user
ii qemu-utils 1:2.11+dfsg-1ubuntu7.9 amd64 QEMU utilities
ii qemu-vanilla 2.11.2+git.0982a56a55-4 amd64 linux kernel optimised for container-like workloads.
No rpm
bug
peter-wangxu
All 14 comments
I somehow got the reason why both kata-runtime and kubelet hung, will provide more information later
peter-wangxu
on 4 Jan 2019
👍2
@peter-wangxu - thanks for the initial level of detail -- I'm interested in your further assessment here.
@sboeuf - heads up.
egernst
on 4 Jan 2019
@bergwolf - heads up.
egernst
on 4 Jan 2019
I experience this too.
ccollicutt
on 4 Jan 2019
Based on the lock on the socket it looks like kata-proxy is not being cleaned up by the runtime.
raravena80
on 4 Jan 2019
Not able to find the root cause: but find a reliable way to reproduce in K8S cluster:
apiVersion: v1
kind: Pod
metadata:
name: kata-stress
labels:
app: myapp
runtime: kata
annotations:
io.kubernetes.cri.untrusted-workload: "true"
spec:
containers:
- name: myapp-container
image: docker.io/progrium/stress:latest
imagePullPolicy: IfNotPresent
command: ["stress"]
args: ["--cpu","2","--io","1","--vm","2","--vm-bytes","128M","--timeout","10s"]
resources:
limits:
cpu: 1
memory: 300M
requests:
cpu: 500m
memory: 100M
create pod in k8s
kubectl apply -f kata.yaml
after 10 seconds, the pod completed with 0, the kubelet will try to delete the old container and start a new one, but unfortunately, the kata-runtime create will hang when creating new container sandbox:
root 40290 40281 0 Jan03 ? 00:00:00 /usr/bin/kata-runtime --root /run/containerd/runc/k8s.io --log /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020/log.json --log-format json create --bundle /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020 --pid-file /run/containerd/io.containerd.runtime.v1.linux/k8s.io/17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020/init.pid 17a15cb99d2b29a724f1669b616c5d799947782034f123f4dc4868f81340b020
the kubelet hung because it's trying to fetch the containers status via kata-runtime state via containerd, which was also blocked by the sbs lock file
Thanks
Peter
peter-wangxu
on 5 Jan 2019
I got the trace by using kill -ABRT
Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.871874846-08:00" level=error msg="--- contention:" arch=amd64 name=kata-runtime pid=4 0290 source=runtime
384 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.871980969-08:00" level=error msg="cycles/second=2194961408" arch=amd64 name=kata-runtime pid=40290 source=runtime
385 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872007845-08:00" level=error msg="goroutine 4 [running]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
386 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872030984-08:00" level=error msg="runtime/pprof.writeGoroutineStacks(0x5555a4a6a3e0, 0xc42033ad20, 0xc4203fa000, 0x1000)" arch=amd64 name=kata-runtime pid=40290 source=runtime
387 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872149701-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:650 +0xa9" arch=amd64 name=kata-runtime pid=40290 source=runtime
388 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872191919-08:00" level=error msg="runtime/pprof.writeGoroutine(0x5555a4a6a3e0, 0xc42033ad20, 0x2, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
389 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872330363-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:639 +0x46" arch=amd64 name=kata-runtime pid=40290 source=runtime
390 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872360573-08:00" level=error msg="runtime/pprof.(*Profile).WriteTo(0x5555a4e457a0, 0x5555a4a6a3e0, 0xc42033ad20, 0x2, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
391 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872378637-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:310 +0x3e6" arch=amd64 name=kata-runtime pid=40290 source=runtime
392 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87239525-08:00" level=error msg="github.com/kata-containers/runtime/pkg/signals.Backtrace()" arch=amd64 name=kata-runtime pid=40290 source=runtime
393 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872422833-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/pkg/signals/signals.go:73 +0xb7" arch=amd64 name=kata-runtime pid=40290 source=runtime
394 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872640489-08:00" level=error msg="github.com/kata-containers/runtime/pkg/signals.Die(0xc42000c040)" arch=amd64 name=kata-runtime pid=40290 source=runtime
394 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872640489-08:00" level=error msg="github.com/kata-containers/runtime/pkg/signals.Die(0xc42000c040)" arch=amd64 name=kata-runtime pid=40290 source=runtime
395 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872688216-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/pkg/signals/signals.go:119 +0x32" arch=amd64 name=kata-runtime pid=40290 source=runtime
396 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872729794-08:00" level=error msg="main.setupSignalHandler.func2(0xc42009c420, 0xc42000c040)" arch=amd64 name=kata-runtime pid=40290 source=runtime
397 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872760648-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:212 +0x251" arch=amd64 name=kata-runtime pid=40290 source=runtime
398 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872793036-08:00" level=error msg="created by main.setupSignalHandler" arch=amd64 name=kata-runtime pid=40290 source=runtime
399 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872830528-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:199 +0x152" arch=amd64 name=kata-runtime pid=40290 source=runtime
400 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872851798-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
401 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87290111-08:00" level=error msg="goroutine 1 [select, locked to thread]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
402 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872927065-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).executeCommandWithResponse(0xc420201f40, 0x5555a4a754a0, 0xc4202a06f0, 0x5555a453d869, 0xa, 0xc4203a2840, 0x0, 0x0, 0x0, 0xc4203a 2870, ...)" aamd64 name=kata-runtime pid=40290 source=runtime
403 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872950948-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:599 +0x2c5" arch=amd64 name=kata-runtime pid=40290 source=runtime
404 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.872969598-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).executeCommand(0xc420201f40, 0x5555a4a754a0, 0xc4202a06f0, 0x5555a453d869, 0xa, 0xc4203a2840, 0xc4203a2870, 0x5555a4eb1dc8, 0x555 5a4a26860)" aamd64 name=kata-runtime pid=40290 source=runtime
405 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873003145-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:613 +0x93" arch=amd64 name=kata-runtime pid=40290 source=runtime
406 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873081826-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).ExecuteDeviceDel(0xc420201f40, 0x5555a4a754a0, 0xc4202a06f0, 0xc42032e760, 0x5, 0x5555a4eb1dc8, 0x5555a4a79480)" arch=amd64 name= kata-runtime 40290 source=runtime
407 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873130558-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:960 +0x19f" arch=amd64 name=kata-runtime pid=40290 source=runtime
408 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873158662-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*qemu).hotplugRemoveCPUs(0xc4202cc400, 0x1, 0x0, 0xc4202ab9d0, 0x5555a4446700)" arch=amd64 name=kata-runtime pid=40290 source=runtime
409 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873194895-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/qemu.go:1060 +0xce" arch=amd64 name=kata-runtime pid=40290 source=runtime
410 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873363445-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*qemu).hotplugCPUs(0xc4202cc400, 0x555500000001, 0x1, 0x5555a4eb1dc8, 0x5555a4a79480, 0x5555a4eb1dc8)" arch=amd64 name=kata-runtime pid=40290 source=runtim
411 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873417426-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/qemu.go:986 +0xac" arch=amd64 name=kata-runtime pid=40290 source=runtime
412 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873442504-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*qemu).hotplugDevice(0xc4202cc400, 0x5555a4921800, 0xc4200a7354, 0xa, 0x1, 0x5555a4a754a0, 0xc4203a2810, 0x7ffd41633ec2, 0x40)" arch=amd64 name=kata-runtim d=40290 source=runtime
413 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873461105-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/qemu.go:932 +0x2a7" arch=amd64 name=kata-runtime pid=40290 source=runtime
414 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.8734769-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*qemu).hotplugRemoveDevice(0xc4202cc400, 0x5555a4921800, 0xc4200a7354, 0xa, 0x0, 0x0, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
415 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873532185-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/qemu.go:963 +0xce" arch=amd64 name=kata-runtime pid=40290 source=runtime
416 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87357688-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*Container).removeResources(0xc4201eaf00, 0x3, 0xc420040570)" arch=amd64 name=kata-runtime pid=40290 source=runtime
417 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873660354-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/container.go:1256 +0x296" arch=amd64 name=kata-runtime pid=40290 source=runtime
418 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873697362-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*Container).rollbackFailingContainerCreation(0xc4201eaf00)" arch=amd64 name=kata-runtime pid=40290 source=runtime
419 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873905784-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/container.go:661 +0x42" arch=amd64 name=kata-runtime pid=40290 source=runtime
420 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.873958802-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.createContainer.func1(0xc4202ac340, 0xc4202ac338)" arch=amd64 name=kata-runtime pid=40290 source=runtime
421 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874006958-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/container.go:705 +0x47" arch=amd64 name=kata-runtime pid=40290 source=runtime
422 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87405282-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.createContainer(0xc420001980, 0x7ffd41633ec2, 0x40, 0xc420202780, 0x7d, 0x0, 0xc42023eea0, 0xa, 0xd, 0xc420222400, ...)" arch=amd64 name=kata-runtime pid=402 90 source=run
423 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874090485-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/container.go:721 +0x896" arch=amd64 name=kata-runtime pid=40290 source=runtime
424 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874123696-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*Sandbox).CreateContainer(0xc420001980, 0x7ffd41633ec2, 0x40, 0xc420202780, 0x7d, 0x0, 0xc42023eea0, 0xa, 0xd, 0xc420222400, ...)" arch=amd64 name=kata-run pid=40290 source=runtime
425 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874164788-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:1276 +0x72" arch=amd64 name=kata-runtime pid=40290 source=runtime
426 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874202116-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.CreateContainer(0x5555a4a754a0, 0xc420263e90, 0xc42020c4c0, 0x40, 0x7ffd41633ec2, 0x40, 0xc420202780, 0x7d, 0x0, 0xc42023eea0, ...)" arch=amd64 name=kata-ru e pid=40290 source=runtime
427 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874237197-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/api.go:398 +0x1df" arch=amd64 name=kata-runtime pid=40290 source=runtime
428 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874268619-08:00" level=error msg="github.com/kata-containers/runtime/virtcontainers.(*VCImpl).CreateContainer(0x5555a4e92820, 0x5555a4a754a0, 0xc4201e7e60, 0xc42020c4c0, 0x40, 0x7ffd41633ec2, 0x40, 0xc420202780, 0x7d, 0x0, ...)" arch=amd64 name=kata-runtime pid=40290 source=runtime
429 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874300707-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/virtcontainers/implementation.go:91 +0x99" arch=amd64 name=kata-runtime pid=40290 source=runtime
430 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874342977-08:00" level=error msg="main.createContainer(0x5555a4a754a0, 0xc4201e7e60, 0xc4200349e0, 0x9, 0x0, 0xc42000d7a0, 0x0, 0x0, 0xc420055800, 0xb, ...)" arch=amd64 name=kata-runtime pid=40290 source=runtime
431 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874465668-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/create.go:340 +0x45d" arch=amd64 name=kata-runtime pid=40290 source=runtime
432 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874507078-08:00" level=error msg="main.create(0x5555a4a754a0, 0xc4201e7560, 0x7ffd41633ec2, 0x40, 0xc420202580, 0x76, 0x0, 0x0, 0x7ffd41633e42, 0x7f, ...)" arch=amd64 name=kata-runtime pid=40290 source=runtime
433 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874555871-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/create.go:172 +0x590" arch=amd64 name=kata-runtime pid=40290 source=runtime
434 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874586682-08:00" level=error msg="main.glob..func1(0xc4201fe580, 0x100, 0xc4201fe580)" arch=amd64 name=kata-runtime pid=40290 source=runtime
435 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874615911-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/create.go:79 +0x405" arch=amd64 name=kata-runtime pid=40290 source=runtime
436 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874718555-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/urfave/cli.HandleAction(0x5555a4935e00, 0x5555a4a65d68, 0xc4201fe580, 0xc420032400, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
437 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.874932861-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/app.go:490 +0xca" arch=amd64 name=kata-runtime pid=40290 source=runtime
438 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87498331-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/urfave/cli.Command.Run(0x5555a45392cc, 0x6, 0x0, 0x0, 0x0, 0x0, 0x0, 0x5555a4543ba6, 0x12, 0x0, ...)" arch=amd64 name=kata-runtime pid=40290 source=runtim e
439 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87512003-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/command.go:210 +0xa38" arch=amd64 name=kata-runtime pid=40290 source=runtime
440 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875180959-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/urfave/cli.(*App).Run(0xc4201e2000, 0xc4200a00d0, 0xd, 0xd, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
441 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875211209-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/app.go:255 +0x6a2" arch=amd64 name=kata-runtime pid=40290 source=runtime
442 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875257939-08:00" level=error msg="main.createRuntimeApp(0x5555a4a75420, 0xc4200a6010, 0xc4200a00d0, 0xd, 0xd, 0xc420073f78, 0xc420073f48)" arch=amd64 name=kata-runtime pid=40290 source=runtime
443 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875291677-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:479 +0x271" arch=amd64 name=kata-runtime pid=40290 source=runtime
444 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875410592-08:00" level=error msg="main.createRuntime(0x5555a4a75420, 0xc4200a6010)" arch=amd64 name=kata-runtime pid=40290 source=runtime
445 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875451133-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:522 +0x7c" arch=amd64 name=kata-runtime pid=40290 source=runtime
446 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875573506-08:00" level=error msg="main.main()" arch=amd64 name=kata-runtime pid=40290 source=runtime
447 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.8756008-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:554 +0x95" arch=amd64 name=kata-runtime pid=40290 source=runtime
448 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875617369-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
449 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87564533-08:00" level=error msg="goroutine 19 [syscall]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
450 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875671599-08:00" level=error msg="os/signal.signal_recv(0x5555a4a70ba0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
451 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875687036-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/sigqueue.go:139 +0xa8" arch=amd64 name=kata-runtime pid=40290 source=runtime
452 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875705436-08:00" level=error msg="os/signal.loop()" arch=amd64 name=kata-runtime pid=40290 source=runtime
453 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875724525-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/os/signal/signal_unix.go:22 +0x24" arch=amd64 name=kata-runtime pid=40290 source=runtime
454 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875739945-08:00" level=error msg="created by os/signal.init.0" arch=amd64 name=kata-runtime pid=40290 source=runtime
455 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875753832-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/os/signal/signal_unix.go:28 +0x43" arch=amd64 name=kata-runtime pid=40290 source=runtime
456 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875861182-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
457 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875875782-08:00" level=error msg="goroutine 20 [select, locked to thread]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
458 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875890221-08:00" level=error msg="runtime.gopark(0x5555a4a66638, 0x0, 0x5555a4539ad0, 0x6, 0x18, 0x1)" arch=amd64 name=kata-runtime pid=40290 source=runtime
459 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875905313-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/proc.go:291 +0x120" arch=amd64 name=kata-runtime pid=40290 source=runtime
460 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87591965-08:00" level=error msg="runtime.selectgo(0xc42004d750, 0xc42008a480)" arch=amd64 name=kata-runtime pid=40290 source=runtime
461 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875937017-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/select.go:392 +0xe56" arch=amd64 name=kata-runtime pid=40290 source=runtime
462 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875952576-08:00" level=error msg="runtime.ensureSigM.func1()" arch=amd64 name=kata-runtime pid=40290 source=runtime
463 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875966467-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/signal_unix.go:549 +0x1f6" arch=amd64 name=kata-runtime pid=40290 source=runtime
464 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875981067-08:00" level=error msg="runtime.goexit()" arch=amd64 name=kata-runtime pid=40290 source=runtime
465 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.875997599-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/asm_amd64.s:2361 +0x1" arch=amd64 name=kata-runtime pid=40290 source=runtime
466 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876012193-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
467 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876032696-08:00" level=error msg="goroutine 5 [select]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
468 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876047846-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).mainLoop(0xc420201f40)" arch=amd64 name=kata-runtime pid=40290 source=runtime
469 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876065984-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:535 +0x49d" arch=amd64 name=kata-runtime pid=40290 source=runtime
470 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876095078-08:00" level=error msg="created by github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.startQMPLoop" arch=amd64 name=kata-runtime pid=40290 source=runtime
471 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876122755-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:573 +0xfe" arch=amd64 name=kata-runtime pid=40290 source=runtime
472 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876209284-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
473 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87622366-08:00" level=error msg="goroutine 21 [IO wait]:" arch=amd64 name=kata-runtime pid=40290 source=runtime
474 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876238421-08:00" level=error msg="internal/poll.runtime_pollWait(0x7fa6c150ce30, 0x72, 0xc42005fc90)" arch=amd64 name=kata-runtime pid=40290 source=runtime
475 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876253596-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/runtime/netpoll.go:173 +0x59" arch=amd64 name=kata-runtime pid=40290 source=runtime
476 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876272881-08:00" level=error msg="internal/poll.(*pollDesc).wait(0xc420217318, 0x72, 0xffffffffffffff00, 0x5555a4a6c8c0, 0x5555a4e58ae8)" arch=amd64 name=kata-runtime pid=40290 source=runtime
477 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876288713-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/internal/poll/fd_poll_runtime.go:85 +0x9d" arch=amd64 name=kata-runtime pid=40290 source=runtime
478 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87630375-08:00" level=error msg="internal/poll.(*pollDesc).waitRead(0xc420217318, 0xc4201bb400, 0xb30, 0xb30)" arch=amd64 name=kata-runtime pid=40290 source=runtime
479 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876318935-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x3f" arch=amd64 name=kata-runtime pid=40290 source=runtime
480 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876339289-08:00" level=error msg="internal/poll.(*FD).Read(0xc420217300, 0xc4201bb4d0, 0xb30, 0xb30, 0x0, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
481 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876488455-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/internal/poll/fd_unix.go:157 +0x17f" arch=amd64 name=kata-runtime pid=40290 source=runtime
482 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876505123-08:00" level=error msg="net.(*netFD).Read(0xc420217300, 0xc4201bb4d0, 0xb30, 0xb30, 0x400, 0xc4200a73a0, 0xe)" arch=amd64 name=kata-runtime pid=40290 source=runtime
483 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876581818-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/net/fd_unix.go:202 +0x51" arch=amd64 name=kata-runtime pid=40290 source=runtime
484 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876661231-08:00" level=error msg="net.(*conn).Read(0xc42000f080, 0xc4201bb4d0, 0xb30, 0xb30, 0x0, 0x0, 0x0)" arch=amd64 name=kata-runtime pid=40290 source=runtime
485 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876678374-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/net/net.go:176 +0x6c" arch=amd64 name=kata-runtime pid=40290 source=runtime
486 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876702503-08:00" level=error msg="bufio.(*Scanner).Scan(0xc42005ff40, 0xc42005ff28)" arch=amd64 name=kata-runtime pid=40290 source=runtime
487 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876726626-08:00" level=error msg="\t/usr/src/packages/BUILD/local/go/src/bufio/scan.go:208 +0xc1" arch=amd64 name=kata-runtime pid=40290 source=runtime
488 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876747259-08:00" level=error msg="github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).readLoop(0xc420201f40, 0xc42008a540)" arch=amd64 name=kata-runtime pid=40290 source=runtime
489 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876819649-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:245 +0xf1" arch=amd64 name=kata-runtime pid=40290 source=runtime
490 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876845764-08:00" level=error msg="created by github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu.(*QMP).mainLoop" arch=amd64 name=kata-runtime pid=40290 source=runtime
491 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.876862254-08:00" level=error msg="\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/vendor/github.com/intel/govmm/qemu/qmp.go:495 +0xbc" arch=amd64 name=kata-runtime pid=40290 source=runtime
492 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877054668-08:00" level=error msg="heap profile: 1: 1048576 [1: 1048576] @ heap/1048576" arch=amd64 name=kata-runtime pid=40290 source=runtime
493 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877076458-08:00" level=error msg="1: 1048576 [1: 1048576] @ 0x5555a44b5b15 0x5555a44b5a46 0x5555a44b25e6 0x5555a44bbf47 0x5555a44bc252 0x5555a45315f1 0x5555a3e920f1" arch=amd64 name=kata-runtime pid=40290 source=runtime
494 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877099991-08:00" level=error msg="#\t0x5555a44b5b14\truntime/pprof.writeGoroutineStacks+0x44\t\t\t\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:648" arch=amd64 name=kata-runtime pid=40290 source=runtime
495 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877121107-08:00" level=error msg="#\t0x5555a44b5a45\truntime/pprof.writeGoroutine+0x45\t\t\t\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:639" arch=amd64 name=kata-runtime pid=40290 source=runtime
496 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877137106-08:00" level=error msg="#\t0x5555a44b25e5\truntime/pprof.(*Profile).WriteTo+0x3e5\t\t\t\t/usr/src/packages/BUILD/local/go/src/runtime/pprof/pprof.go:310" arch=amd64 name=kata-runtime pid=40290 source=runtime
497 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877247872-08:00" level=error msg="#\t0x5555a44bbf46\tgithub.com/kata-containers/runtime/pkg/signals.Backtrace+0xb6\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/pkg/signals/signals.go:73" arch=amd64 name=kata-runtime pi d=40290rce=runtime
498 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877271545-08:00" level=error msg="#\t0x5555a44bc251\tgithub.com/kata-containers/runtime/pkg/signals.Die+0x31\t\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/pkg/signals/signals.go:119" arch=amd64 name=kata-runtime pid=4 0290 so=runtime
499 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877298172-08:00" level=error msg="#\t0x5555a45315f0\tmain.setupSignalHandler.func2+0x250\t\t\t\t/usr/src/packages/BUILD/go/src/github.com/kata-containers/runtime/cli/main.go:212" arch=amd64 name=kata-runtime pid=40290 source=runtime
500 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877329744-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
501 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877345404-08:00" level=error arch=amd64 name=kata-runtime pid=40290 source=runtime
502 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877360138-08:00" level=error msg="# runtime.MemStats" arch=amd64 name=kata-runtime pid=40290 source=runtime
503 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877374272-08:00" level=error msg="# Alloc = 2035376" arch=amd64 name=kata-runtime pid=40290 source=runtime
504 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877389874-08:00" level=error msg="# TotalAlloc = 3469808" arch=amd64 name=kata-runtime pid=40290 source=runtime
505 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877456393-08:00" level=error msg="# Sys = 8919288" arch=amd64 name=kata-runtime pid=40290 source=runtime
506 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877478722-08:00" level=error msg="# Lookups = 140" arch=amd64 name=kata-runtime pid=40290 source=runtime
507 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877492895-08:00" level=error msg="# Mallocs = 21020" arch=amd64 name=kata-runtime pid=40290 source=runtime
508 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877506405-08:00" level=error msg="# Frees = 9602" arch=amd64 name=kata-runtime pid=40290 source=runtime
509 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877594495-08:00" level=error msg="# HeapAlloc = 2035376" arch=amd64 name=kata-runtime pid=40290 source=runtime
510 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.87761425-08:00" level=error msg="# HeapSys = 5734400" arch=amd64 name=kata-runtime pid=40290 source=runtime
511 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877682692-08:00" level=error msg="# HeapIdle = 2433024" arch=amd64 name=kata-runtime pid=40290 source=runtime
512 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877709103-08:00" level=error msg="# HeapInuse = 3301376" arch=amd64 name=kata-runtime pid=40290 source=runtime
513 Jan 04 04:49:57 ubuntu kata-runtime[40290]: time="2019-01-04T04:49:57.877722764-08:00" level=error msg="# HeapReleased = 0" arch=amd64 name=kata-runtime pid=40290 source=runtime
/cc @devimc - can you take a look?
egernst
on 7 Jan 2019
egernst
on 7 Jan 2019
I can take a look
devimc
on 7 Jan 2019
@peter-wangxu I can't reproduce it
$ kata-runtime --version
kata-runtime : 1.5.0-rc2
commit : a8e158c9e3830554a95751fd416b7f56029afbd6
OCI specs: 1.0.1-dev
$ ./kata-agent --version
kata-agent version 1.5.0-rc2-91a87bc7176750eee2f032aa564e8b28f4ad0e73
$ kubectl get pods
NAME READY STATUS RESTARTS AGE
kata-stress 1/1 Running 3 2m19s
$ sudo kata-runtime list
ID PID STATUS BUNDLE CREATED OWNER
8294c5c89d5cf11e3f293e2ab1d98ed83d7f78300daf3852187dc1dd6b3d136b 3113 running /run/containers/storage/overlay-containers/8294c5c89d5cf11e3f293e2ab1d98ed83d7f78300daf3852187dc1dd6b3d136b/userdata 2019-01-07T18:00:57.748434185Z #0
da45c492e806d651bc0221a9e665db72c584ccd689e433ad80d517a19f7d258d 3157 running /run/containers/storage/overlay-containers/da45c492e806d651bc0221a9e665db72c584ccd689e433ad80d517a19f7d258d/userdata 2019-01-07T18:00:58.425220655Z #0
5c7c1796552f8ce8c78bdc58ce8a1f26e94cf2f84b6c97d327e27807e5f4680e 3204 running /run/containers/storage/overlay-containers/5c7c1796552f8ce8c78bdc58ce8a1f26e94cf2f84b6c97d327e27807e5f4680e/userdata 2019-01-07T18:00:59.379912218Z #0
1d6dd664e87c7d92a2a789b7e9a2ca41665b193fd82670671a3698289db152fe 3250 running /run/containers/storage/overlay-containers/1d6dd664e87c7d92a2a789b7e9a2ca41665b193fd82670671a3698289db152fe/userdata 2019-01-07T18:00:59.77104282Z #0
f68de771e12bb98011494d7ff10c762b3da96f222e36ae5f85ab50aef07361ae 6003 running /run/containers/storage/overlay-containers/f68de771e12bb98011494d7ff10c762b3da96f222e36ae5f85ab50aef07361ae/userdata 2019-01-07T18:04:36.425354385Z #0
5d3e1c3eb20f255b7ce8bd3b437013c7cff7d0540900f1fcbd43d2a3dfec1ac3 7361 stopped /run/containers/storage/overlay-containers/5d3e1c3eb20f255b7ce8bd3b437013c7cff7d0540900f1fcbd43d2a3dfec1ac3/userdata 2019-01-07T18:06:13.845279431Z #0
f041333bee0ff986a50594aba99aa3ddda672a64e67c8069003c52f6bf0131da 7774 running /run/containers/storage/overlay-containers/f041333bee0ff986a50594aba99aa3ddda672a64e67c8069003c52f6bf0131da/userdata 2019-01-07T18:06:47.811317602Z #0
...........
$ kubectl get pods
NAME READY STATUS RESTARTS AGE
kata-stress 0/1 Completed 7 13m
$ sudo kata-runtime list
ID PID STATUS BUNDLE CREATED OWNER
8294c5c89d5cf11e3f293e2ab1d98ed83d7f78300daf3852187dc1dd6b3d136b 3113 running /run/containers/storage/overlay-containers/8294c5c89d5cf11e3f293e2ab1d98ed83d7f78300daf3852187dc1dd6b3d136b/userdata 2019-01-07T18:00:57.748434185Z #0
da45c492e806d651bc0221a9e665db72c584ccd689e433ad80d517a19f7d258d 3157 running /run/containers/storage/overlay-containers/da45c492e806d651bc0221a9e665db72c584ccd689e433ad80d517a19f7d258d/userdata 2019-01-07T18:00:58.425220655Z #0
5c7c1796552f8ce8c78bdc58ce8a1f26e94cf2f84b6c97d327e27807e5f4680e 3204 running /run/containers/storage/overlay-containers/5c7c1796552f8ce8c78bdc58ce8a1f26e94cf2f84b6c97d327e27807e5f4680e/userdata 2019-01-07T18:00:59.379912218Z #0
1d6dd664e87c7d92a2a789b7e9a2ca41665b193fd82670671a3698289db152fe 3250 running /run/containers/storage/overlay-containers/1d6dd664e87c7d92a2a789b7e9a2ca41665b193fd82670671a3698289db152fe/userdata 2019-01-07T18:00:59.77104282Z #0
f68de771e12bb98011494d7ff10c762b3da96f222e36ae5f85ab50aef07361ae 6003 running /run/containers/storage/overlay-containers/f68de771e12bb98011494d7ff10c762b3da96f222e36ae5f85ab50aef07361ae/userdata 2019-01-07T18:04:36.425354385Z #0
4363609145f0192b8925a7d8d116703d943564e3155feb6d644afdd5e96ab1d4 13336 stopped /run/containers/storage/overlay-containers/4363609145f0192b8925a7d8d116703d943564e3155feb6d644afdd5e96ab1d4/userdata 2019-01-07T18:17:29.808114439Z #0
might be something is broken in your environment? can you try with last release?
devimc
on 7 Jan 2019
ohh wait, I was using crio not containerd as runtime, now I can reproduce it :sweat_smile:
devimc
on 7 Jan 2019
to reproduce this issue I had to change between runtimes (crio and containerd),
- run
kata-stresspod with crio - delete
kata-stresspod - stop crio
- configure kubelet to use containerd
- restart kubelet and containerd
- run again
kata-stresspod
I don't know if these are the right steps to reproduce this issue, but I wrote a patch to fix it
diff --git a/virtcontainers/container.go b/virtcontainers/container.go
index 545700b..d73a6e4 100644
--- a/virtcontainers/container.go
+++ b/virtcontainers/container.go
@@ -927,19 +927,29 @@ func (c *Container) stop() error {
// get failed if the process hasn't exited.
c.sandbox.agent.waitProcess(c, c.id)
- if err := c.sandbox.agent.stopContainer(c.sandbox, *c); err != nil {
+ var err error
+ defer func() {
+ if e := c.setContainerState(types.StateStopped); e != nil {
+ c.Logger().WithError(e).Errorf("Could not change container state to stopped")
+ if err == nil {
+ err = e
+ }
+ }
+ }()
+
+ if err = c.sandbox.agent.stopContainer(c.sandbox, *c); err != nil {
return err
}
- if err := c.detachDevices(); err != nil {
+ if err = c.detachDevices(); err != nil {
return err
}
- if err := c.removeDrive(); err != nil {
+ if err = c.removeDrive(); err != nil {
return err
}
- return c.setContainerState(types.StateStopped)
+ return err
}
func (c *Container) enter(cmd types.Cmd) (*Process, error) {
diff --git a/virtcontainers/kata_agent.go b/virtcontainers/kata_agent.go
index 64b40a7..f7ec6cd 100644
--- a/virtcontainers/kata_agent.go
+++ b/virtcontainers/kata_agent.go
@@ -1568,6 +1568,17 @@ func (k *kataAgent) sendReq(request interface{}) (interface{}, error) {
span.SetTag("request", request)
defer span.Finish()
+ if k.state.ProxyPid > 0 {
+ proxyProcess, err := os.FindProcess(k.state.ProxyPid)
+ if err != nil {
+ return nil, fmt.Errorf("Could not find a proxy with process id %d: %v", k.state.ProxyPid, err)
+ }
+
+ if err = proxyProcess.Signal(syscall.Signal(0)); err != nil {
+ return nil, fmt.Errorf("Proxy is not running: %v", err)
+ }
+ }
+
if err := k.connect(); err != nil {
return nil, err
}
@peter-wangxu @ccollicutt can you confirm if above patch works for you?
devimc
on 8 Jan 2019
@peter-wangxu @ccollicutt (nudge) :smile:
devimc
on 11 Jan 2019
Was this page helpful?
0 / 5 - 0 ratings
Related issues
AkihiroSuda
路
4Comments
jcvenegas
路
7Comments
cespo
路
11Comments
teawater
路
5Comments
egernst
路
11Comments
Most helpful comment
I somehow got the reason why both kata-runtime and kubelet hung, will provide more information later