search

kata-containers / runtime

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

Kata support image booting via systemd #1355

Closed free2k closed 3 years ago

free2k commented 5 years ago

Description of problem

The image started by systemd cannot be run. Will report an error

v1 docker run --runtime kata-runtime --name kata-test --cpus 2 --memory 2G -itd crawler:v2 1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458 /usr/bin/docker-current: Error response from daemon: oci runtime error: hook error.

https://github.com/projectatomic/oci-systemd-hook/blob/master/src/systemdhook.c line 373 Location tracking found that the mount --move operation fails. I don't know where the problem is.

Expected result

Run successfully

Actual result

/usr/bin/docker-current: Error response from daemon: oci runtime error: hook error.

Meta details

Running kata-collect-data.sh version 1.3.0 (commit a786643) at 2019-03-12.16:18:22.458075176+0800.

Runtime is /usr/bin/kata-runtime.

kata-env

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

[Meta]
  Version = "1.0.18"

[Runtime]
  Debug = true
  Path = "/usr/bin/kata-runtime"
  [Runtime.Version]
    Semver = "1.3.0"
    Commit = "a786643"
    OCI = "1.0.1"
  [Runtime.Config]
    Path = "/usr/share/defaults/kata-containers/configuration.toml"

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

[Image]
  Path = "/usr/share/kata-containers/kata-containers-image_clearlinux_1.3.0_agent_042c3ebd71c.img"

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

[Initrd]
  Path = ""

[Proxy]
  Type = "kataProxy"
  Version = "kata-proxy version 1.3.0-6ddb006"
  Path = "/usr/libexec/kata-containers/kata-proxy"
  Debug = true

[Shim]
  Type = "kataShim"
  Version = "kata-shim version 1.3.0-5fbf1f0"
  Path = "/usr/libexec/kata-containers/kata-shim"
  Debug = true

[Agent]
  Type = "kata"

[Host]
  Kernel = "3.10.0-693.mt20180601.62.el7.x86_64"
  Architecture = "amd64"
  VMContainerCapable = true
  SupportVSocks = false
  [Host.Distro]
    Name = "CentOS Linux"
    Version = "7"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz"

[Netmon]
  Version = "kata-netmon version 1.3.0"
  Path = "/usr/libexec/kata-containers/kata-netmon"
  Debug = true
  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 = " agent.log=debug initcall_debug agent.log=debug initcall_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

# 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"

[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.
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

KSM throttler

version

Output of "/usr/libexec/kata-ksm-throttler/kata-ksm-throttler --version":

kata-ksm-throttler version 1.3.0-6e903fb

Output of "/usr/lib/systemd/system/kata-ksm-throttler.service --version":

/usr/bin/kata-collect-data.sh:行168: /usr/lib/systemd/system/kata-ksm-throttler.service: 权限不够

systemd service

Image details

---
osbuilder:
  url: "https://github.com/kata-containers/osbuilder"
  version: "unknown"
rootfs-creation-time: "2018-09-27T09:46:58.640358658+0000Z"
description: "osbuilder rootfs"
file-format-version: "0.0.2"
architecture: "x86_64"
base-distro:
  name: "Clear"
  version: "25180"
  packages:
    default:
      - "iptables-bin"
      - "libudev0-shim"
      - "systemd"
    extra:

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.3.0-042c3ebd71c2ca425aa0c70fadcbf6370116659b"
  agent-is-init-daemon: "no"

Initrd details

No initrd

Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2019-03-11T20:10:49.566532625+08:00" level=error msg="Container ID (cd78a4b0a9f93a626c63fe97804d0a28fc8750c6111c223580d408856c816e23) does not exist" arch=amd64 command=delete container=cd78a4b0a9f93a626c63fe97804d0a28fc8750c6111c223580d408856c816e23 name=kata-runtime pid=23457 source=runtime
time="2019-03-11T20:13:43.800436821+08:00" level=error msg="hook error" arch=amd64 command=create container=4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053 error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=23980 source=runtime subsystem=hook
time="2019-03-11T20:13:43.800502798+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053 name=kata-runtime pid=23980 source=runtime
time="2019-03-11T20:13:43.804379153+08:00" level=error msg="Container ID (4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053) does not exist" arch=amd64 command=delete container=4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053 name=kata-runtime pid=24017 source=runtime
time="2019-03-11T20:13:43.830492467+08:00" level=error msg="Container ID (4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053) does not exist" arch=amd64 command=delete container=4fb293cb9cf375797b9c96b4814b4b328b60c6537de4ec0453492787aa34b053 name=kata-runtime pid=24026 source=runtime
time="2019-03-11T20:24:27.455748896+08:00" level=error msg="hook error" arch=amd64 command=create container=2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663 error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=24819 source=runtime subsystem=hook
time="2019-03-11T20:24:27.455813571+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663 name=kata-runtime pid=24819 source=runtime
time="2019-03-11T20:24:27.459685363+08:00" level=error msg="Container ID (2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663) does not exist" arch=amd64 command=delete container=2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663 name=kata-runtime pid=24851 source=runtime
time="2019-03-11T20:24:27.479864264+08:00" level=error msg="Container ID (2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663) does not exist" arch=amd64 command=delete container=2adf1c00627c9b4df05325e43c9fa149753eddf9b45ec6617aeeeac60dba4663 name=kata-runtime pid=24859 source=runtime
time="2019-03-11T20:25:39.960107115+08:00" level=error msg="hook error" arch=amd64 command=create container=c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=25105 source=runtime subsystem=hook
time="2019-03-11T20:25:39.960168541+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d name=kata-runtime pid=25105 source=runtime
time="2019-03-11T20:25:39.963940646+08:00" level=error msg="Container ID (c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d) does not exist" arch=amd64 command=delete container=c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d name=kata-runtime pid=25139 source=runtime
time="2019-03-11T20:25:39.996206468+08:00" level=error msg="Container ID (c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d) does not exist" arch=amd64 command=delete container=c0dba32812c0d516f9d3ff8e70fc4d6f4f3b0eadf1d9d10b834e2eb9021e270d name=kata-runtime pid=25147 source=runtime
time="2019-03-11T20:33:32.75632896+08:00" level=error msg="hook error" arch=amd64 command=create container=cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465 error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=26044 source=runtime subsystem=hook
time="2019-03-11T20:33:32.756395622+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465 name=kata-runtime pid=26044 source=runtime
time="2019-03-11T20:33:32.760330548+08:00" level=error msg="Container ID (cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465) does not exist" arch=amd64 command=delete container=cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465 name=kata-runtime pid=26077 source=runtime
time="2019-03-11T20:33:32.79040244+08:00" level=error msg="Container ID (cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465) does not exist" arch=amd64 command=delete container=cf1bc6f0b26b3c40b2f09c90355b8809cabf386d099d2f4789856ae9df981465 name=kata-runtime pid=26085 source=runtime
time="2019-03-11T20:35:14.09020861+08:00" level=error msg="hook error" arch=amd64 command=create container=9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=26318 source=runtime subsystem=hook
time="2019-03-11T20:35:14.090273377+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c name=kata-runtime pid=26318 source=runtime
time="2019-03-11T20:35:14.094110996+08:00" level=error msg="Container ID (9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c) does not exist" arch=amd64 command=delete container=9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c name=kata-runtime pid=26350 source=runtime
time="2019-03-11T20:35:14.121338099+08:00" level=error msg="Container ID (9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c) does not exist" arch=amd64 command=delete container=9524c7d979f43d35a1f832f4b45ce50d53a0940d620437091d94054018ffae3c name=kata-runtime pid=26358 source=runtime
time="2019-03-11T20:38:26.701623858+08:00" level=error msg="hook error" arch=amd64 command=create container=be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=26950 source=runtime subsystem=hook
time="2019-03-11T20:38:26.701694405+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b name=kata-runtime pid=26950 source=runtime
time="2019-03-11T20:38:26.705632483+08:00" level=error msg="Container ID (be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b) does not exist" arch=amd64 command=delete container=be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b name=kata-runtime pid=26986 source=runtime
time="2019-03-11T20:38:26.730494096+08:00" level=error msg="Container ID (be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b) does not exist" arch=amd64 command=delete container=be8e5c4c71b29578d430bd899f492a2c591e7c89c2e86b79a1d8507f78c1ad2b name=kata-runtime pid=26995 source=runtime
time="2019-03-12T15:42:07.221261643+08:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9178 source=virtcontainers subsystem=kata_agent
time="2019-03-12T15:42:07.221292442+08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 error="open /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/devices.json: no such file or directory" name=kata-runtime pid=9178 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 sandboxid=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=virtcontainers subsystem=sandbox
time="2019-03-12T15:42:07.223502289+08:00" level=debug arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=9178 source=virtcontainers subsystem=qemu
time="2019-03-12T15:42:08.039131311+08:00" level=warning msg="unsupported address" address="fe80::42:acff:fe11:2/64" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9178 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-03-12T15:42:08.039199936+08:00" level=warning msg="unsupported route" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 destination="fe80::/64" name=kata-runtime pid=9178 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-03-12T15:42:08.717834725+08:00" level=error msg="Container not ready, running or paused, impossible to signal the container" arch=amd64 command=kill container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9276 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=runtime
time="2019-03-12T15:42:08.773190064+08:00" level=error msg="Container ID (23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028) does not exist" arch=amd64 command=delete container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9324 source=runtime
time="2019-03-12T15:42:33.06899318+08:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9425 source=virtcontainers subsystem=kata_agent
time="2019-03-12T15:42:33.069024454+08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 error="open /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/devices.json: no such file or directory" name=kata-runtime pid=9425 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 sandboxid=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=virtcontainers subsystem=sandbox
time="2019-03-12T15:42:33.071311235+08:00" level=debug arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=9425 source=virtcontainers subsystem=qemu
time="2019-03-12T15:42:33.744974003+08:00" level=warning msg="unsupported address" address="fe80::42:acff:fe11:2/64" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9425 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-03-12T15:42:33.745064956+08:00" level=warning msg="unsupported route" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 destination="fe80::/64" name=kata-runtime pid=9425 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-03-12T15:42:34.397975974+08:00" level=error msg="Container not ready, running or paused, impossible to signal the container" arch=amd64 command=kill container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9517 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=runtime
time="2019-03-12T15:42:34.451011729+08:00" level=error msg="Container ID (23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028) does not exist" arch=amd64 command=delete container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9561 source=runtime
time="2019-03-12T15:42:50.578752016+08:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9610 source=virtcontainers subsystem=kata_agent
time="2019-03-12T15:42:50.578781556+08:00" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 error="open /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/devices.json: no such file or directory" name=kata-runtime pid=9610 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 sandboxid=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=virtcontainers subsystem=sandbox
time="2019-03-12T15:42:50.581026715+08:00" level=debug arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=9610 source=virtcontainers subsystem=qemu
time="2019-03-12T15:42:51.248326571+08:00" level=warning msg="unsupported address" address="fe80::42:acff:fe11:2/64" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9610 source=virtcontainers subsystem=network unsupported-address-type=ipv6
time="2019-03-12T15:42:51.248421948+08:00" level=warning msg="unsupported route" arch=amd64 command=create container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 destination="fe80::/64" name=kata-runtime pid=9610 source=virtcontainers subsystem=network unsupported-route-type=ipv6
time="2019-03-12T15:42:51.912788545+08:00" level=error msg="Container not ready, running or paused, impossible to signal the container" arch=amd64 command=kill container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9715 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=runtime
time="2019-03-12T15:42:51.96698162+08:00" level=error msg="Container ID (23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028) does not exist" arch=amd64 command=delete container=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 name=kata-runtime pid=9759 source=runtime
time="2019-03-12T15:52:08.093671584+08:00" level=error msg="hook error" arch=amd64 command=create container=1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458 error="exit status 1: stdout: , stderr: " hook-type=pre-start name=kata-runtime pid=10487 source=runtime subsystem=hook
time="2019-03-12T15:52:08.093737127+08:00" level=error msg="exit status 1: stdout: , stderr: " arch=amd64 command=create container=1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458 name=kata-runtime pid=10487 source=runtime
time="2019-03-12T15:52:08.09751351+08:00" level=error msg="Container ID (1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458) does not exist" arch=amd64 command=delete container=1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458 name=kata-runtime pid=10523 source=runtime
time="2019-03-12T15:52:08.11983427+08:00" level=error msg="Container ID (1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458) does not exist" arch=amd64 command=delete container=1c057dc5a3016c0c488d75443297b81146b1dadc271bff6f7a508f2afd5cb458 name=kata-runtime pid=10531 source=runtime

Proxy logs

Recent proxy problems found in system journal:

time="2019-03-12T15:42:08.17179156+08:00" level=info msg="[    0.499982] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.172313858+08:00" level=info msg="[    0.500493] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.17275761+08:00" level=info msg="[    0.500970] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.173251738+08:00" level=info msg="[    0.501440] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.173751455+08:00" level=info msg="[    0.501912] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.174228509+08:00" level=info msg="[    0.502439] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.174692241+08:00" level=info msg="[    0.502881] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.175189246+08:00" level=info msg="[    0.503370] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.175625368+08:00" level=info msg="[    0.503835] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.17609181+08:00" level=info msg="[    0.504285] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.192448708+08:00" level=info msg="[    0.504768] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.192578616+08:00" level=info msg="[    0.505269] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:08.330593145+08:00" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/proxy.sock->@: read: connection reset by peer" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:08.730344083+08:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/kata.sock: use of closed network connection" name=kata-proxy pid=9219 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:33.581023218+08:00" level=info msg="[    0.212789] EXT4-fs (pmem0p1): DAX enabled. Warning: EXPERIMENTAL, use at your own risk\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.581287138+08:00" level=info msg="[    0.213033] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: dax,data=ordered,errors=remount-ro\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.599043706+08:00" level=info msg="[    0.230760] systemd-gpt-auto-generator[67]: Failed to chase block device '/', ignoring: No such file or directory\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.637279446+08:00" level=info msg="[    0.269045] systemd[84]: tmp.mount: Failed to execute command: No such file or directory\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.639505552+08:00" level=info msg="[    0.271251] systemd-journald[76]: Failed to open configuration file '/etc/systemd/journald.conf': No such file or directory\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.653306314+08:00" level=info msg="[\x1b[0;1;31mFAILED\x1b[0m] Failed to mount Temporary Directory (/tmp).\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.653924281+08:00" level=info msg="[\x1b[0;1;33mDEPEND\x1b[0m] Dependency failed for Network Time Synchronization.\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.755261098+08:00" level=info msg="time=\"2019-03-12T07:42:33.720200251Z\" level=debug msg=\"request end\" duration=5.5204ms name=kata-agent pid=109 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{}\" sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.767040677+08:00" level=info msg="time=\"2019-03-12T07:42:33.731983505Z\" level=debug msg=\"request end\" duration=\"1.013µs\" name=kata-agent pid=109 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{}\" sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.845994962+08:00" level=info msg="[    0.477765] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.846623748+08:00" level=info msg="[    0.478355] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.8471987+08:00" level=info msg="[    0.478982] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.850710239+08:00" level=info msg="[    0.481698] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.869238617+08:00" level=info msg="[    0.501019] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.937244751+08:00" level=info msg="[    0.569030] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.93771499+08:00" level=info msg="[    0.569481] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.93818601+08:00" level=info msg="[    0.569939] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.938647747+08:00" level=info msg="[    0.570402] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.939100054+08:00" level=info msg="[    0.570853] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.939552865+08:00" level=info msg="[    0.571308] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.939992781+08:00" level=info msg="[    0.571774] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.940463942+08:00" level=info msg="[    0.572216] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.941333361+08:00" level=info msg="[    0.572650] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.942359969+08:00" level=info msg="[    0.573094] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.94253602+08:00" level=info msg="[    0.573740] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.942713458+08:00" level=info msg="[    0.574166] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.942901516+08:00" level=info msg="[    0.574544] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.943107633+08:00" level=info msg="[    0.574881] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.943483864+08:00" level=info msg="[    0.575261] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.943847356+08:00" level=info msg="[    0.575639] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:33.949069773+08:00" level=info msg="[    0.576019] run queue from wrong CPU 1, hctx active\n" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=agent
time="2019-03-12T15:42:34.061690574+08:00" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/proxy.sock->@: read: connection reset by peer" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:34.410353667+08:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/kata.sock: use of closed network connection" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:34.410385397+08:00" level=fatal msg="channel error" error="accept unix /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/proxy.sock: use of closed network connection" name=kata-proxy pid=9468 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:51.578862167+08:00" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/proxy.sock->@: read: connection reset by peer" name=kata-proxy pid=9651 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy
time="2019-03-12T15:42:51.925386747+08:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028/kata.sock: use of closed network connection" name=kata-proxy pid=9651 sandbox=23194d320330f268c1c9927bccf5065186199dd5765cad7662087fda3c425028 source=proxy

Shim logs

Recent shim problems found in system journal:

time="2019-03-07T17:28:36.663128453+08:00" level=info msg="copy stdout failed" container=c3d6d0c8ba3c5750ba890342e2456a38c4da34d101d04d676a56c1e244c7a33d error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f8f866dc-ee7f-46b8-b97f-2f5afa67d899 name=kata-shim pid=11 source=shim
time="2019-03-07T17:44:25.074943428+08:00" level=info msg="copy stdout failed" container=cea06cc5f93a00486008def51edb5d3e6507fb2a20adf52566a52d10105f7e15 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=311e5458-bb54-484d-b756-7f7324a4dfc7 name=kata-shim pid=11 source=shim
time="2019-03-07T17:52:53.347436355+08:00" level=info msg="copy stdout failed" container=8d5f6cea794ff63e2b583974f922d86fd61d2a6b2e9976b9b1115f010e7c0c06 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=b6617fd3-89bf-4f65-9780-f9a0d0aa8c50 name=kata-shim pid=11 source=shim
time="2019-03-07T17:59:44.398780296+08:00" level=info msg="copy stdout failed" container=eb8e81d486f3b80d7c147dc2b78633709c43563e8c51a46ec0f2fbe59db92846 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6a5ba2bc-226e-4227-8066-e224484c88de name=kata-shim pid=11 source=shim
time="2019-03-07T18:00:44.739603387+08:00" level=info msg="copy stdout failed" container=7327b6ad494f053d4c2e589a43240c1dbba85adce640ad59705395becb32b21a error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=7327b6ad494f053d4c2e589a43240c1dbba85adce640ad59705395becb32b21a name=kata-shim pid=1 source=shim
time="2019-03-07T19:13:17.900259357+08:00" level=info msg="copy stdout failed" container=5b95ed917f1d9f5e36f2431bb528185e9496055d61a8f00a51e0937b53509f15 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=18bbe9c8-959f-4749-8269-109c735e21ed name=kata-shim pid=12 source=shim
time="2019-03-07T20:15:03.348398656+08:00" level=info msg="copy stdout failed" container=721d95d21d97fa254735dac40c0db86c5e93b538344c12397f50abbfb2060207 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=93879a3a-f5dc-4772-b097-afcee1bb0256 name=kata-shim pid=21 source=shim
time="2019-03-07T20:41:00.952367111+08:00" level=info msg="copy stdout failed" container=c4c96fe27df8d27ad342fa5d6ed4201fc91ad7338573471971e770b9d0841842 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=03bba5f6-c2af-4c25-99e4-dff39d477b94 name=kata-shim pid=12 source=shim
time="2019-03-07T20:51:59.403201028+08:00" level=info msg="copy stdout failed" container=eb199cfb1510c25ca43c013a2a099d12e738c7aaf0e3186db96ab9ba13559a61 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=70efc524-a2d5-4e8f-98c8-3f618b311c6c name=kata-shim pid=11 source=shim
time="2019-03-07T20:52:08.296189125+08:00" level=info msg="copy stdout failed" container=eb199cfb1510c25ca43c013a2a099d12e738c7aaf0e3186db96ab9ba13559a61 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f37ffe0d-a0b8-4401-a595-3845816db9eb name=kata-shim pid=21 source=shim
time="2019-03-07T20:52:30.394535283+08:00" level=info msg="copy stdout failed" container=eb199cfb1510c25ca43c013a2a099d12e738c7aaf0e3186db96ab9ba13559a61 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=8e1e7087-be58-4335-9ce3-7e8c91e18b41 name=kata-shim pid=31 source=shim
time="2019-03-08T15:29:48.27331984+08:00" level=info msg="copy stdout failed" container=440fb71e6b627809866a01e0df77da05c512ec8c275de11b4c0e897c3cfb9168 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=b39ca589-c964-4547-965b-ace4a636ea0e name=kata-shim pid=11 source=shim

Throttler logs

No recent throttler problems found in system journal.

Container manager details

Have docker

Docker

Output of "docker version":

Client:
 Version:         1.13.1
 API version:     1.26
 Package version: docker-1.13.1-88.git07f3374.el7.centos.x86_64
 Go version:      go1.9.4
 Git commit:      07f3374/1.13.1
 Built:           Fri Dec  7 16:13:51 2018
 OS/Arch:         linux/amd64

Server:
 Version:         1.13.1
 API version:     1.26 (minimum version 1.12)
 Package version: docker-1.13.1-88.git07f3374.el7.centos.x86_64
 Go version:      go1.9.4
 Git commit:      07f3374/1.13.1
 Built:           Fri Dec  7 16:13:51 2018
 OS/Arch:         linux/amd64
 Experimental:    false

Output of "docker info":

Containers: 10
 Running: 1
 Paused: 0
 Stopped: 9
Images: 19
Server Version: 1.13.1
Storage Driver: devicemapper
 Pool Name: docker-8:2-1444585-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 10.74 GB
 Backing Filesystem: xfs
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 8.721 GB
 Data Space Total: 107.4 GB
 Data Space Available: 63.15 GB
 Metadata Space Used: 11.6 MB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.136 GB
 Thin Pool Minimum Free Space: 10.74 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: true
 Deferred Deletion Enabled: true
 Deferred Deleted Device Count: 0
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 WARNING: Usage of loopback devices is strongly discouraged for production use. Use `--storage-opt dm.thinpooldev` to specify a custom block storage device.
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.146-RHEL7 (2018-01-22)
Logging Driver: json-file
Cgroup Driver: systemd
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: kata-runtime runc
Default Runtime: runc
Init Binary: /usr/libexec/docker/docker-init-current
containerd version:  (expected: aa8187dbd3b7ad67d8e5e3a15115d3eef43a7ed1)
runc version: N/A (expected: 9df8b306d01f59d3a8029be411de015b7304dd8f)
init version: fec3683b971d9c3ef73f284f176672c44b448662 (expected: 949e6facb77383876aeff8a6944dde66b3089574)
Security Options:
 seccomp
  WARNING: You're not using the default seccomp profile
  Profile: /etc/docker/seccomp.json
Kernel Version: 3.10.0-693.mt20180601.62.el7.x86_64
Operating System: CentOS Linux 7 (Core)
OSType: linux
Architecture: x86_64
Number of Docker Hooks: 4
CPUs: 8
Total Memory: 15.42 GiB
Name: localhost.localdomain
ID: CM5C:F347:A7JF:LJHE:HWGU:WFDM:GP2H:DN4B:VA4C:IXQG:BS4C:BTKK
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false
Registries: docker.io (secure)

Output of "systemctl show docker":

Type=notify
Restart=on-abnormal
NotifyAccess=main
RestartUSec=100ms
TimeoutStartUSec=0
TimeoutStopUSec=1min 30s
WatchdogUSec=0
WatchdogTimestamp=一 2019-03-11 16:27:20 CST
WatchdogTimestampMonotonic=444089872118
StartLimitInterval=10000000
StartLimitBurst=5
StartLimitAction=none
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=17306
ControlPID=0
FileDescriptorStoreMax=0
StatusErrno=0
Result=success
ExecMainStartTimestamp=一 2019-03-11 16:27:18 CST
ExecMainStartTimestampMonotonic=444087909284
ExecMainExitTimestampMonotonic=0
ExecMainPID=17306
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/dockerd-current ; argv[]=/usr/bin/dockerd-current --exec-opt native.cgroupdriver=systemd --userland-proxy-path=/usr/libexec/docker/docker-proxy-current --init-path=/usr/libexec/docker/docker-init-current --seccomp-profile=/etc/docker/seccomp.json $OPTIONS $DOCKER_STORAGE_OPTIONS $DOCKER_NETWORK_OPTIONS $ADD_REGISTRY $BLOCK_REGISTRY $INSECURE_REGISTRY $REGISTRIES ; ignore_errors=no ; start_time=[一 2019-03-11 16:27:18 CST] ; stop_time=[n/a] ; pid=17306 ; 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=550817792
TasksCurrent=50
Delegate=no
CPUAccounting=no
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=no
TasksMax=18446744073709551615
Environment=GOTRACEBACK=crash DOCKER_HTTP_HOST_COMPAT=1 PATH=/usr/libexec/docker:/usr/bin:/usr/sbin
EnvironmentFile=/run/containers/registries.conf (ignore_errors=yes)
EnvironmentFile=/etc/sysconfig/docker (ignore_errors=yes)
EnvironmentFile=/etc/sysconfig/docker-storage (ignore_errors=yes)
EnvironmentFile=/etc/sysconfig/docker-network (ignore_errors=yes)
UMask=0022
LimitCPU=18446744073709551615
LimitFSIZE=18446744073709551615
LimitDATA=18446744073709551615
LimitSTACK=18446744073709551615
LimitCORE=18446744073709551615
LimitRSS=18446744073709551615
LimitNOFILE=1048576
LimitAS=18446744073709551615
LimitNPROC=1048576
LimitMEMLOCK=65536
LimitLOCKS=18446744073709551615
LimitSIGPENDING=63048
LimitMSGQUEUE=819200
LimitNICE=0
LimitRTPRIO=0
LimitRTTIME=18446744073709551615
OOMScoreAdjust=0
Nice=0
IOScheduling=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
SecureBits=0
CapabilityBoundingSet=18446744073709551615
AmbientCapabilities=0
MountFlags=0
PrivateTmp=no
PrivateNetwork=no
PrivateDevices=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
KillMode=process
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=docker.service
Names=docker.service
Requires=docker-cleanup.timer basic.target
Wants=system.slice docker-storage-setup.service
RequiredBy=docker-cleanup.service
Conflicts=shutdown.target
Before=shutdown.target
After=basic.target network.target systemd-journald.socket docker-storage-setup.service system.slice
Documentation=http://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/usr/lib/systemd/system/docker.service
UnitFileState=disabled
UnitFilePreset=disabled
InactiveExitTimestamp=一 2019-03-11 16:27:18 CST
InactiveExitTimestampMonotonic=444087909307
ActiveEnterTimestamp=一 2019-03-11 16:27:20 CST
ActiveEnterTimestampMonotonic=444089872139
ActiveExitTimestamp=一 2019-03-11 16:26:27 CST
ActiveExitTimestampMonotonic=444036809847
InactiveEnterTimestamp=一 2019-03-11 16:26:28 CST
InactiveEnterTimestampMonotonic=444037945499
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
IgnoreOnSnapshot=no
NeedDaemonReload=no
JobTimeoutUSec=0
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=一 2019-03-11 16:27:18 CST
ConditionTimestampMonotonic=444087908835
AssertTimestamp=一 2019-03-11 16:27:18 CST
AssertTimestampMonotonic=444087908835
Transient=no

No kubectl

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-)"":

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-)"":

kata-shim-bin-1.3.0+git.5fbf1f0-8.1.x86_64
qemu-img-1.5.3-156.el7_5.2.x86_64
qemu-vanilla-2.11.2+git.0982a56a55-12.1.x86_64
qemu-kvm-1.5.3-156.el7_5.2.x86_64
ipxe-roms-qemu-20170123-1.git4e85b27.el7.noarch
qemu-lite-bin-2.11.0+git.f886228056-12.1.x86_64
qemu-kvm-common-1.5.3-156.el7_5.2.x86_64
qemu-vanilla-bin-2.11.2+git.0982a56a55-12.1.x86_64
kata-proxy-1.3.0+git.6ddb006-9.1.x86_64
qemu-lite-data-2.11.0+git.f886228056-12.1.x86_64
kata-shim-1.3.0+git.5fbf1f0-8.1.x86_64
kata-linux-container-4.14.67.12-10.1.x86_64
qemu-lite-2.11.0+git.f886228056-12.1.x86_64
kata-proxy-bin-1.3.0+git.6ddb006-9.1.x86_64
qemu-vanilla-data-2.11.2+git.0982a56a55-12.1.x86_64
qemu-guest-agent-2.8.0-2.el7.x86_64
kata-runtime-1.3.0+git.a786643-14.1.x86_64
libvirt-daemon-driver-qemu-3.9.0-14.el7_5.5.x86_64
kata-ksm-throttler-1.3.0.git+6e903fb-11.1.x86_64
kata-containers-image-1.3.0-9.1.x86_64
free2k commented 5 years ago

FROM centos:7 ENV container docker MAINTAINER The CentOS Project cloud-ops@centos.org COPY rpm/ /root/rpm/ RUN (cd /lib/systemd/system/sysinit.target.wants/; for i in ; do [ $i == systemd-tmpfiles-setup.service ] || rm -f $i; done); \ rm -f /lib/systemd/system/multi-user.target.wants/; \ yum install -y rp-pppoe vim net-tools less wget crontabs traceroute openssh-server openssh-clients javapackages-tools java-1.8.0-openjdk-devel.x86_64; \ sed -i 's/#UseDNS yes/UseDNS no/g' /etc/ssh/sshd_config; \ systemctl enable sshd; \ rpm -qa | grep java | grep -v javapackages | xargs rpm -e --nodeps; \ rpm -ivh /root/rpm/*; \ yum clean all; \ rm -f /usr/lib/systemd/system/sysinit.target.wants/systemd-udev-trigger.service; \ rm -f /usr/lib/systemd/system/sysinit.target.wants/systemd-udevd.service; \ echo root:cg1uOq#bYsmn|chpasswd VOLUME ["/sys/fs/cgroup"] CMD ["/usr/sbin/init"] " This is the dockerfile

jodh-intel commented 5 years ago

Hi @free2k - thanks for reporting. I wonder if the issue relates to the fact that Kata containers already have systemd running inside them. We'll have to investigate...

free2k commented 5 years ago

sh-4.2# systemctl Failed to get D-Bus connection: Operation not permitted

I have solved the problem of mount failure and also successfully started kata. However, if you fail to start systemd, you will get a "Failed to get D-Bus connection: Operation not permitted" error. @jodh-intel