Skip to content
This repository has been archived by the owner on May 12, 2021. It is now read-only.

docker start fails with Kata and ACRN hypervisor #2026

Closed
vijaydhanraj opened this issue Sep 3, 2019 · 8 comments · Fixed by #2118
Closed

docker start fails with Kata and ACRN hypervisor #2026

vijaydhanraj opened this issue Sep 3, 2019 · 8 comments · Fixed by #2118

Comments

@vijaydhanraj
Copy link
Contributor

Description of problem

docker start fails with Kata and ACRN hypervisor. Followed the steps below,

  1. Run a docker container, sudo docker run --name CL_bash -ti --runtime=kata-runtime busybox sh
  2. Stop docker container, sudo docker stop CL_bash
  3. Start docker container, sudo docker start CL_bash

Debug Status:
Based on initial debug found that docker stop was failing with
Sep 03 15:27:53 ACRNSOS kata-runtime[2304]: time="2019-09-03T15:27:53.844312685-07:00" level=error msg="deleteSandbox failed with err:StopSandbox failed with err:failed to Statfs "/var/run/netns/cni-49777597-ff42-8d5c-4fd7-801f95190c7e": no such file or directory" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=runtime.

Found out that since the state of the sandbox was not properly saved, delete OCI command was trying to remove already deleted file (kill OCI command deletes this file). The expectation is that sandbox state will be stopped, but in this case, it was empty "".

Root caused the reason for sandbox state being empty to GetAndSetSandboxBlockIndex(), which overwrites the sandbox state from stopped to empty. ACRN calls this function to increase the block device index (rootfs for the container). Since this logic is very specific to ACRN, the issue is not reproducible with other hypervisors such as QEMU or Firecracker.

Any reason why the GetAndSetSandboxBlockIndex() should store the sandbox state? If this needed, can a check be added to ensure the state being stored is a valid state instead of simply overwriting the existing state?

Please find the stack trace below,
/usr/local/go/src/runtime/debug/stack.go:24 +0x9f\ngithub.com/kata-containers/runtime/virtcontainers/store.
(*filesystem).store(0xc0000b0640, 0xc0002bd301, 0x557019ce6da0, 0xc0000b1080, 0x0, 0x0)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/store/filesystem_backend.go:234 +0x52f\ngithub.com/kata-containers/runtime/virtcontainers/store.
(*Store).Store(0xc000512f00, 0x557019ce6d01, 0x557019ce6da0, 0xc0000b1080, 0x0, 0x0)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/store/manager.go:241 +0x2ed\ngithub.com/kata-containers/runtime/virtcontainers/store.
(*VCStore).Store(0xc0004edbb0, 0xc0000f2d01, 0x557019ce6da0, 0xc0000b1080, 0x2, 0x3)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/store/vc.go:90 +0x52\ngithub.com/kata-containers/runtime/virtcontainers.
(*Sandbox).getAndSetSandboxBlockIndex(0xc0000f2c60, 0xc00053f100, 0x40, 0xc0000f2c60)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:1626 +0xa7\ngithub.com/kata-containers/runtime/virtcontainers.
(*Sandbox).GetAndSetSandboxBlockIndex(...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:1779\ngithub.com/kata-containers/runtime/virtcontainers.
(*acrn).appendImage(0xc000199340, 0xc0000b1040, 0x3, 0x4, 0xc0000d8c80, 0x4b, 0xc0000b1040, 0x3, 0x4, 0x3, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/acrn.go:173 +0x177\ngithub.com/kata-containers/runtime/virtcontainers.
(*acrn).buildDevices(0xc000199340, 0xc0000d8c80, 0x4b, 0xc0000d8c80, 0x4b, 0x0, 0x0, 0xc0002bd788)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/acrn.go:204 +0x290\ngithub.com/kata-containers/runtime/virtcontainers.
(*acrn).createSandbox(0xc000199340, 0x557019d90740, 0xc00024ab70, 0xc00053f100, 0x40, 0xc00053f140, 0x37, 0x0, 0x0,0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/acrn.go:325 +0x299\ngithub.com/kata-containers/runtime/virtcontainers.
newSandbox(0x557019d90740, 0xc00024ab70, 0xc00053f100, 0x40, 0xc00051ff80, 0xc, 0xc00051ff78, 0x4, 0x100000001, 0x100000800, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:583 +0xb84\ngithub.com/kata-containers/runtime/virtcontainers.
createSandbox(0x557019d90740, 0xc00024a900, 0xc00053f100, 0x40, 0xc00051ff80, 0xc, 0xc00051ff78, 0x4, 0x100000001, 0x100000800, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:462 +0x16f\ngithub.com/kata-containers/runtime/virtcontainers.
fetchSandbox(0x557019d90740, 0xc0005436b0, 0xc0002e611d, 0x40, 0xc0002e611d, 0x40, 0xc000038ff0)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/sandbox.go:697 +0x2a4\ngithub.com/kata-co ntainers/runtime/virtcontainers.StatusContainer(0x557019d90740, 0xc0005436b0, 0xc0002e611d, 0x40, 0x7ffee76b6eab, 0x40, 0x0, 0x0, 0x0, 0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/api.go:561 + 0x1f6\ngithub.com/kata-containers/runtime/virtcontainers.
(*VCImpl).StatusContainer(0x55701a56f130, 0x557019d90740, 0xc000543350, 0xc0002e611d, 0x40, 0x7ffee76b6eab, 0x40, 0x0, 0x0, 0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/virtcontainers/implementation.go:117 +0xb0\nmain.getContainerInfo(0x557019d90740, 0xc000543350, 0x7ffee76b6eab, 0x40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/oci.go:52 +0x201\nmain.
getExistingContainerInfo(0x557019d90740, 0xc000543350, 0x7ffee76b6eab, 0x40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/oci.go:61 +0x96\nmain.
state(0x557019d90740, 0xc000543350, 0x7ffee76b6eab, 0x40, 0x0, 0x0)/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/state.go:53 +0x29a\nmain.
glob..func16(0xc0000f29a0, 0x0, 0xc0000f29a0)/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/state.go:39 +0x234\ngithub.com/kata-containers/runtime/vendor/github.com/urfave/cli.
HandleAction(0x557019bef560, 0x557019d58ae8, 0xc0000f29a0, 0xc0000ae600, 0x0)\n\t/home/vdhanraj/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/app.go:490 +0xca\ngithub.com/kata-containers/runtime/vendor/github.com/urfave/cli.
Command.Run(0x55701960805c, 0x5, 0x0, 0x0, 0x0, 0x0, 0x0, 0x557019624914, 0x1f, 0x0, ...)/home/vdhanraj/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/command.go:210 +0x998\ngithub.com/kata-containers/runtime/vendor/github.com/urfave/cli.
(*App).Run(0xc00030e000, 0xc0000b2000, 0x9, 0x9, 0x0, 0x0)\n\t/home/vdhanraj/go/src/github.com/kata-containers/runtime/vendor/github.com/urfave/cli/app.go:255 +0x6b1\nmain.createRuntimeApp(0x557019d906c0, 0xc0000a8010, 0xc0000b2000, 0x9, 0x9, 0x0, 0xc0002bff58)\n\t/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/main.go:478 +0x22d
main.createRuntime(0x557019d906c0, 0xc0000a8010)\n\t/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/main.go:521 +0x7c\nmain.
main()\n\t/home/vdhanraj/go/src/github.com/kata-containers/runtime/cli/main.go:553 +0x9e\n"

Expected result

root@ACRNSOS~ # sudo docker start CL_bash
CL_bash

Actual result

root@ACRNSOS~ # sudo docker start CL_bash
Error response from daemon: id already in use
Error: failed to start containers: CL_bash

Show kata-collect-data.sh details

Meta details

Running kata-collect-data.sh version 1.8.0-alpha0 (commit 21c1e374c8ade0531eb862c0e0462f39d6331aca-dirty) at 2019-09-03.15:28:17.540225264-0700.

Runtime is /usr/local/bin/kata-runtime.

kata-env

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

[Meta]
  Version = "1.0.23"

[Runtime]
  Debug = true
  Trace = false
  DisableGuestSeccomp = true
  DisableNewNetNs = false
  Path = "/usr/local/bin/kata-runtime"
  [Runtime.Version]
    Semver = "1.9.0-alpha0"
    Commit = "92709ef520ec590fd2b19279cfb25281c548a853-dirty"
    OCI = "1.0.1-dev"
  [Runtime.Config]
    Path = "/etc/kata-containers/configuration.toml"

[Hypervisor]
  MachineType = ""
  Version = "DM version is: 1.2-unstable-3cc0eaba (daily tag:acrn-2019w33.5-140000p), build by vdhanraj@2019-08-20 17:12:54"
  Path = "/usr/bin/acrn-dm"
  BlockDeviceDriver = "virtio-blk"
  EntropySource = "/dev/urandom"
  Msize9p = 0
  MemorySlots = 10
  Debug = false
  UseVSock = false
  SharedFS = ""

[Image]
  Path = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/kata-containers.img"

[Kernel]
  Path = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/vmlinuz-4.19.28-41"
  Parameters = "systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket agent.log=debug"

[Initrd]
  Path = ""

[Proxy]
  Type = "kataProxy"
  Version = "kata-proxy version 1.8.0-alpha0-339152c1c9cc45283470a143cc53402e09ea64b3-dirty"
  Path = "/usr/libexec/kata-containers/kata-proxy"
  Debug = true

[Shim]
  Type = "kataShim"
  Version = "kata-shim version 1.8.0-alpha0-a677afa3f49b51b26ad7248702a354933884d2a2"
  Path = "/usr/libexec/kata-containers/kata-shim"
  Debug = true

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

[Host]
  Kernel = "4.19.59-PKT-190722T171340Z-dirty"
  Architecture = "amd64"
  VMContainerCapable = true
  SupportVSocks = false
  [Host.Distro]
    Name = "Clear Linux OS"
    Version = "30020"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz"

[Netmon]
  Version = "kata-netmon version 1.8.0-alpha0"
  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

Output of "cat "/etc/kata-containers/configuration.toml"":

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

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

[hypervisor.acrn]
path = "/usr/bin/acrn-dm"
ctlpath = "/usr/bin/acrnctl"
#kernel = "/usr/share/kata-containers/vmlinuz.container"
#image = "/usr/share/kata-containers/kata-containers.img"
kernel = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/vmlinuz.container"
image = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/kata-containers.img"
#kernel = "/home/vdhanraj/uos1/CL_UOS/kernel/default-iot-lts2018"
#image = "/home/vdhanraj/uos1/CL_UOS/cluos_kata-agent_console.img"

# 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 acrn uses the default firmware leave this option empty
firmware = ""

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

# Block storage driver to be used for the hypervisor in case the container
# rootfs is backed by a block device. ACRN only supports virtio-blk.
block_device_driver = "virtio-blk"

# 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

# 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

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

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

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

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

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

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

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

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

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

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

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

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

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

Output of "cat "/usr/share/defaults/kata-containers/configuration.toml"":

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

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

[hypervisor.acrn]
path = "/usr/bin/acrn-dm"
ctlpath = "/usr/bin/acrnctl"
#kernel = "/usr/share/kata-containers/vmlinuz.container"
#image = "/usr/share/kata-containers/kata-containers.img"
kernel = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/vmlinuz.container"
image = "/home/vdhanraj/uos1/kata/katabins/share/kata-containers/kata-containers.img"
#kernel = "/usr/lib/kernel/default-iot-lts2018"
#image = "/home/vdhanraj/uos1/check-GVT-g/clear-27230-kata-agent.img"
#kernel = "/home/vdhanraj/uos1/CL_UOS/kernel/default-iot-lts2018"
#image = "/home/vdhanraj/uos1/CL_UOS/cluos_kata-agent_console.img"

# 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 acrn uses the default firmware leave this option empty
firmware = ""

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

# Block storage driver to be used for the hypervisor in case the container
# rootfs is backed by a block device. ACRN only supports virtio-blk.
block_device_driver = "virtio-blk"

# 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

# 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

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

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

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

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

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

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

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

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

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

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

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

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

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

KSM throttler

version

Output of " --version":

/usr/local/bin/kata-collect-data.sh: line 178: --version: command not found

systemd service

Image details

---
osbuilder:
  url: "https://github.com/kata-containers/osbuilder"
  version: "unknown"
rootfs-creation-time: "2019-06-06T16:03:27.180906818+0000Z"
description: "osbuilder rootfs"
file-format-version: "0.0.2"
architecture: "x86_64"
base-distro:
  name: "Clear"
  version: "29800"
  packages:
    default:
      - "chrony"
      - "iptables-bin"
      - "libudev0-shim"
      - "systemd"
      - "util-linux-bin"
    extra:

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.8.0-alpha0-ccb3648c52b24409e8eae6d360180ff34e00cbfa"
  agent-is-init-daemon: "no"

Initrd details

No initrd

Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2019-09-03T15:21:04.604362901-07:00" level=info msg="##*##createSandbox: state=, err=open /run/vc/sbs/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/state.json: no such file or directory" arch=amd64 command=create container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1677 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:21:14.674061955-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1677 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=container
time="2019-09-03T15:21:14.674998885-07:00" level=debug msg="sending request" arch=amd64 command=create container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=grpc.CopyFileRequest pid=1677 req="path:\"/run/kata-containers/shared/containers/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542-ac295505ed8d6b18-resolv.conf\" file_size:635 file_mode:33188 dir_mode:2147484136 data:\"# This file is managed by man:systemd-resolved(8). Do not edit.\\n#\\n# This is a dynamic resolv.conf file for connecting local clients directly to\\n# all known uplink DNS servers. This file lists all configured search domains.\\n#\\n# Third party programs must not access this file directly, but only through the\\n# symlink at /etc/resolv.conf. To manage man:resolv.conf(5) in a different way,\\n# replace this symlink by a static file or a different symlink.\\n#\\n# See man:systemd-resolved.service(8) for details about the supported modes of\\n# operation for /etc/resolv.conf.\\n\\nnameserver 10.248.2.1\\nnameserver 10.22.224.196\\nnameserver 10.3.86.116\\n\" " source=virtcontainers subsystem=kata_agent
time="2019-09-03T15:21:14.67683934-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1677 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=container
time="2019-09-03T15:21:14.679868253-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1677 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=container
time="2019-09-03T15:21:14.818374999-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=state container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1772 source=virtcontainers
time="2019-09-03T15:21:14.868384493-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=start container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1780 source=virtcontainers
time="2019-09-03T15:21:14.881559213-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=start container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1780 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:21:14.953515298-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=state container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=1790 source=virtcontainers
time="2019-09-03T15:26:34.978614179-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=kill container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2039 source=virtcontainers
time="2019-09-03T15:26:34.98750929-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=kill container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2039 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:26:35.015850334-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=kill container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2039 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:26:35.047657271-07:00" level=warning msg="no such file or directory: /run/kata-containers/shared/sandboxes/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/rootfs"
time="2019-09-03T15:26:35.791460618-07:00" level=info msg="##kill: Error=%!s(<nil>)" arch=amd64 command=kill container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 container state=running name=kata-runtime pid=2039 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=runtime
time="2019-09-03T15:26:35.858298132-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=state container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2060 source=virtcontainers
time="2019-09-03T15:26:35.908521976-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=delete name=kata-runtime pid=2067 source=virtcontainers
time="2019-09-03T15:26:35.923018576-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:26:35.9340408-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:26:35.941576752-07:00" level=warning msg="Agent did not stop sandbox" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 error="rpc error: code = InvalidArgument desc = Invalid unix scheme: " name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 sandboxid=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:26:35.943285812-07:00" level=info msg="##*##Network Remove failed with err:failed to Statfs \"/var/run/netns/cni-2fb4feb5-8243-0d5c-5ddc-e6cc648540bb\": no such file or directory" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:26:35.943314783-07:00" level=info msg="***sandboxStop: s.removeNetwork function failed with er:failed to Statfs \"/var/run/netns/cni-2fb4feb5-8243-0d5c-5ddc-e6cc648540bb\": no such file or directory" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:26:35.943339603-07:00" level=info msg="api.StopSandbox: s.Stop function failed with err: failed to Statfs \"/var/run/netns/cni-2fb4feb5-8243-0d5c-5ddc-e6cc648540bb\": no such file or directory" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=virtcontainers
time="2019-09-03T15:26:35.943540281-07:00" level=error msg="deleteSandbox failed with err:StopSandbox failed with err:failed to Statfs \"/var/run/netns/cni-2fb4feb5-8243-0d5c-5ddc-e6cc648540bb\": no such file or directory" arch=amd64 command=delete container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2067 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=runtime
time="2019-09-03T15:26:36.121898383-07:00" level=info msg="fetch sandbox: Sandbox ID edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 not found" arch=amd64 command=state container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-runtime pid=2077 source=virtcontainers
time="2019-09-03T15:27:35.886571395-07:00" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2147 source=virtcontainers subsystem=kata_agent
time="2019-09-03T15:27:35.887281578-07:00" level=warning msg="load sandbox devices failed" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 error="open /run/vc/sbs/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/devices.json: no such file or directory" name=kata-runtime pid=2147 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 sandboxid=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:27:45.960518209-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2147 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=container
time="2019-09-03T15:27:45.961166935-07:00" level=debug msg="sending request" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=grpc.CopyFileRequest pid=2147 req="path:\"/run/kata-containers/shared/containers/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9-626de59055b06503-resolv.conf\" file_size:635 file_mode:33188 dir_mode:2147484136 data:\"# This file is managed by man:systemd-resolved(8). Do not edit.\\n#\\n# This is a dynamic resolv.conf file for connecting local clients directly to\\n# all known uplink DNS servers. This file lists all configured search domains.\\n#\\n# Third party programs must not access this file directly, but only through the\\n# symlink at /etc/resolv.conf. To manage man:resolv.conf(5) in a different way,\\n# replace this symlink by a static file or a different symlink.\\n#\\n# See man:systemd-resolved.service(8) for details about the supported modes of\\n# operation for /etc/resolv.conf.\\n\\nnameserver 10.248.2.1\\nnameserver 10.22.224.196\\nnameserver 10.3.86.116\\n\" " source=virtcontainers subsystem=kata_agent
time="2019-09-03T15:27:45.963611558-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2147 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=container
time="2019-09-03T15:27:45.968868911-07:00" level=debug msg="filesystem sharing is not supported, files will be copied" arch=amd64 command=create container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2147 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=container
time="2019-09-03T15:27:46.115735207-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=state container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2242 source=virtcontainers
time="2019-09-03T15:27:46.1752803-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=start container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2249 source=virtcontainers
time="2019-09-03T15:27:46.190287172-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=start container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2249 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:46.267099295-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=state container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2261 source=virtcontainers
time="2019-09-03T15:27:52.48655451-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=kill container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2276 source=virtcontainers
time="2019-09-03T15:27:52.498470632-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=kill container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2276 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:52.512485661-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=kill container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2276 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:52.943213035-07:00" level=warning msg="no such file or directory: /run/kata-containers/shared/sandboxes/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/rootfs"
time="2019-09-03T15:27:53.691239277-07:00" level=info msg="##kill: Error=%!s(<nil>)" arch=amd64 command=kill container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 container state=running name=kata-runtime pid=2276 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=runtime
time="2019-09-03T15:27:53.758511551-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=state container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2297 source=virtcontainers
time="2019-09-03T15:27:53.810779416-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=delete name=kata-runtime pid=2304 source=virtcontainers
time="2019-09-03T15:27:53.824540476-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:53.835915482-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:53.84330538-07:00" level=warning msg="Agent did not stop sandbox" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 error="rpc error: code = InvalidArgument desc = Invalid unix scheme: " name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 sandboxid=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:27:53.84406204-07:00" level=info msg="##*##Network Remove failed with err:failed to Statfs \"/var/run/netns/cni-49777597-ff42-8d5c-4fd7-801f95190c7e\": no such file or directory" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:27:53.844091639-07:00" level=info msg="***sandboxStop: s.removeNetwork function failed with er:failed to Statfs \"/var/run/netns/cni-49777597-ff42-8d5c-4fd7-801f95190c7e\": no such file or directory" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers subsystem=sandbox
time="2019-09-03T15:27:53.844116201-07:00" level=info msg="api.StopSandbox: s.Stop function failed with err: failed to Statfs \"/var/run/netns/cni-49777597-ff42-8d5c-4fd7-801f95190c7e\": no such file or directory" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=virtcontainers
time="2019-09-03T15:27:53.844312685-07:00" level=error msg="deleteSandbox failed with err:StopSandbox failed with err:failed to Statfs \"/var/run/netns/cni-49777597-ff42-8d5c-4fd7-801f95190c7e\": no such file or directory" arch=amd64 command=delete container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2304 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=runtime
time="2019-09-03T15:27:54.028519171-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=state container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2314 source=virtcontainers
time="2019-09-03T15:28:01.138185962-07:00" level=info msg="fetch sandbox: Sandbox ID a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 not found" arch=amd64 command=state container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-runtime pid=2340 source=virtcontainers

Proxy logs

Recent proxy problems found in system journal:

time="2019-09-03T15:20:52.221701494-07:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/kata.sock: use of closed network connection" name=kata-proxy pid=1551 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=proxy
time="2019-09-03T15:21:14.628672975-07:00" level=info msg="time=\"2019-09-03T22:21:13.623897886Z\" level=info msg=\"linkByHwAddr link\" debug_console=false link=\"&{{1 65536 1000 lo  up|loopback 65609 0 0 <nil>  0xc0001d60fc 0 0xc000039400 loopback <nil> unknown 0 0 0 []}}\" name=kata-agent pid=80 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.628850091-07:00" level=info msg="time=\"2019-09-03T22:21:13.624133432Z\" level=info msg=\"linkByHwAddr lAttrs\" debug_console=false lAttrs=\"&{1 65536 1000 lo  up|loopback 65609 0 0 <nil>  0xc0001d60fc 0 0xc000039400 loopback <nil> unknown 0 0 0 []}\" name=kata-agent pid=80 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.637842758-07:00" level=info msg="time=\"2019-09-03T22:21:13.633202345Z\" level=debug msg=\"request end\" debug_console=false duration=4.102423ms name=kata-agent pid=80 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.645087507-07:00" level=info msg="time=\"2019-09-03T22:21:13.640440808Z\" level=debug msg=\"request end\" debug_console=false duration=\"1.944µs\" name=kata-agent pid=80 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.675856944-07:00" level=info msg="time=\"2019-09-03T22:21:13.671201821Z\" level=debug msg=\"new request\" debug_console=false name=kata-agent pid=80 req=\"path:\\\"/run/kata-containers/shared/containers/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542-ac295505ed8d6b18-resolv.conf\\\" file_size:635 file_mode:33188 dir_mode:2147484136 data:\\\"# This file is managed by man:systemd-resolved(8). Do not edit.\\\\n#\\\\n# This is a dynamic resolv.conf file for connecting local clients directly to\\\\n# all known uplink DNS servers. This file lists all configured search domains.\\\\n#\\\\n# Third party programs must not access this file directly, but only through the\\\\n# symlink at /etc/resolv.conf. To manage man:resolv.conf(5) in a different way,\\\\n# replace this symlink by a static file or a different symlink.\\\\n#\\\\n# See man:systemd-resolved.service(8) for details about the supported modes of\\\\n# operation for /etc/resolv.conf.\\\\n\\\\nnameserver 10.248.2.1\\\\nnameserver 10.22.224.196\\\\nnameserver 10.3.86.116\\\\n\\\" \" request=/grpc.AgentService/CopyFile sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.676003318-07:00" level=info msg="time=\"2019-09-03T22:21:13.67137684Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=635 name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent tmp-file-size=635\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.676451663-07:00" level=info msg="time=\"2019-09-03T22:21:13.671565315Z\" level=debug msg=\"request end\" debug_console=false duration=\"250.069µs\" name=kata-agent pid=80 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.677427343-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/proxy.sock->@: use of closed network connection" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=proxy
time="2019-09-03T15:21:14.679102099-07:00" level=info msg="time=\"2019-09-03T22:21:13.674364768Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=13 name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent tmp-file-size=13\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.679501973-07:00" level=info msg="time=\"2019-09-03T22:21:13.674776521Z\" level=debug msg=\"request end\" debug_console=false duration=\"459.298µs\" name=kata-agent pid=80 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.680445213-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/proxy.sock->@: use of closed network connection" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=proxy
time="2019-09-03T15:21:14.682146647-07:00" level=info msg="time=\"2019-09-03T22:21:13.677410723Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=174 name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent tmp-file-size=174\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.682542955-07:00" level=info msg="time=\"2019-09-03T22:21:13.677833042Z\" level=debug msg=\"request end\" debug_console=false duration=\"465.42µs\" name=kata-agent pid=80 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.74301808-07:00" level=info msg="time=\"2019-09-03T22:21:13.738350813Z\" level=debug msg=\"request end\" debug_console=false duration=51.768024ms name=kata-agent pid=80 request=/grpc.AgentService/CreateContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.743550994-07:00" level=info msg="time=\"2019-09-03T22:21:13.738835817Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 signal=\"child exited\" source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.7448187-07:00" level=info msg="time=\"2019-09-03T22:21:13.739054224Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 signal=\"child exited\" source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:21:14.891766353-07:00" level=info msg="time=\"2019-09-03T22:21:13.88708709Z\" level=debug msg=\"request end\" debug_console=false duration=1.93396ms name=kata-agent pid=80 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.014980095-07:00" level=info msg="time=\"2019-09-03T22:26:34.010072027Z\" level=debug msg=\"request end\" debug_console=false duration=\"322.26µs\" name=kata-agent pid=80 request=/grpc.AgentService/SignalProcess resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.020512112-07:00" level=info msg="time=\"2019-09-03T22:26:34.014087595Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=80 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 signal=\"child exited\" source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.03623408-07:00" level=info msg="time=\"2019-09-03T22:26:34.031495418Z\" level=debug msg=\"request end\" debug_console=false duration=\"253.942µs\" name=kata-agent pid=80 request=/grpc.AgentService/SignalProcess resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.047151275-07:00" level=info msg="time=\"2019-09-03T22:26:34.04250186Z\" level=debug msg=\"request end\" debug_console=false duration=6.667197ms name=kata-agent pid=80 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.04964557-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/proxy.sock->@: use of closed network connection" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=proxy
time="2019-09-03T15:26:35.05207405-07:00" level=info msg="time=\"2019-09-03T22:26:34.047436233Z\" level=debug msg=\"request end\" debug_console=false duration=\"885.764µs\" name=kata-agent pid=80 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent\n" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=agent
time="2019-09-03T15:26:35.054940392-07:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542/kata.sock: use of closed network connection" name=kata-proxy pid=1745 sandbox=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 source=proxy
time="2019-09-03T15:27:45.914489111-07:00" level=info msg="time=\"2019-09-03T22:27:45.628054221Z\" level=info msg=\"linkByHwAddr link\" debug_console=false link=\"&{{1 65536 1000 lo  up|loopback 65609 0 0 <nil>  0xc0001d60fc 0 0xc000039400 loopback <nil> unknown 0 0 0 []}}\" name=kata-agent pid=79 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.914710281-07:00" level=info msg="time=\"2019-09-03T22:27:45.628274464Z\" level=info msg=\"linkByHwAddr lAttrs\" debug_console=false lAttrs=\"&{1 65536 1000 lo  up|loopback 65609 0 0 <nil>  0xc0001d60fc 0 0xc000039400 loopback <nil> unknown 0 0 0 []}\" name=kata-agent pid=79 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.92625779-07:00" level=info msg="time=\"2019-09-03T22:27:45.639928147Z\" level=debug msg=\"request end\" debug_console=false duration=4.087873ms name=kata-agent pid=79 request=/grpc.AgentService/CreateSandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.931044176-07:00" level=info msg="time=\"2019-09-03T22:27:45.644712973Z\" level=debug msg=\"request end\" debug_console=false duration=\"2.009µs\" name=kata-agent pid=79 request=/grpc.AgentService/OnlineCPUMem resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.962563989-07:00" level=info msg="time=\"2019-09-03T22:27:45.676207747Z\" level=debug msg=\"new request\" debug_console=false name=kata-agent pid=79 req=\"path:\\\"/run/kata-containers/shared/containers/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9-626de59055b06503-resolv.conf\\\" file_size:635 file_mode:33188 dir_mode:2147484136 data:\\\"# This file is managed by man:systemd-resolved(8). Do not edit.\\\\n#\\\\n# This is a dynamic resolv.conf file for connecting local clients directly to\\\\n# all known uplink DNS servers. This file lists all configured search domains.\\\\n#\\\\n# Third party programs must not access this file directly, but only through the\\\\n# symlink at /etc/resolv.conf. To manage man:resolv.conf(5) in a different way,\\\\n# replace this symlink by a static file or a different symlink.\\\\n#\\\\n# See man:systemd-resolved.service(8) for details about the supported modes of\\\\n# operation for /etc/resolv.conf.\\\\n\\\\nnameserver 10.248.2.1\\\\nnameserver 10.22.224.196\\\\nnameserver 10.3.86.116\\\\n\\\" \" request=/grpc.AgentService/CopyFile sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.962737489-07:00" level=info msg="time=\"2019-09-03T22:27:45.676386798Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=635 name=kata-agent pid=79 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent tmp-file-size=635\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.962942527-07:00" level=info msg="time=\"2019-09-03T22:27:45.676621327Z\" level=debug msg=\"request end\" debug_console=false duration=\"288.988µs\" name=kata-agent pid=79 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.964155294-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/proxy.sock->@: use of closed network connection" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=proxy
time="2019-09-03T15:27:45.968051375-07:00" level=info msg="time=\"2019-09-03T22:27:45.681611138Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=13 name=kata-agent pid=79 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent tmp-file-size=13\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.968462508-07:00" level=info msg="time=\"2019-09-03T22:27:45.682045272Z\" level=debug msg=\"request end\" debug_console=false duration=\"472.283µs\" name=kata-agent pid=79 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.970893715-07:00" level=info msg="time=\"2019-09-03T22:27:45.68444995Z\" level=debug msg=\"Checking temporary file size\" debug_console=false expected-size=174 name=kata-agent pid=79 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent tmp-file-size=174\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.971287657-07:00" level=info msg="time=\"2019-09-03T22:27:45.684884152Z\" level=debug msg=\"request end\" debug_console=false duration=\"471.256µs\" name=kata-agent pid=79 request=/grpc.AgentService/CopyFile resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:45.973369878-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/proxy.sock->@: write: broken pipe" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=proxy
time="2019-09-03T15:27:46.036857537-07:00" level=info msg="time=\"2019-09-03T22:27:45.750501069Z\" level=debug msg=\"request end\" debug_console=false duration=59.428428ms name=kata-agent pid=79 request=/grpc.AgentService/CreateContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:46.037404983-07:00" level=info msg="time=\"2019-09-03T22:27:45.750989183Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=79 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 signal=\"child exited\" source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:46.037881566-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/proxy.sock->@: use of closed network connection" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=proxy
time="2019-09-03T15:27:46.203546255-07:00" level=info msg="time=\"2019-09-03T22:27:45.917164705Z\" level=debug msg=\"request end\" debug_console=false duration=1.700051ms name=kata-agent pid=79 request=/grpc.AgentService/StartContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:46.30042564-07:00" level=info msg="time=\"2019-09-03T22:27:46.014020019Z\" level=debug msg=\"request end\" debug_console=false duration=\"31.277µs\" name=kata-agent pid=79 request=/grpc.AgentService/TtyWinResize resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.510898485-07:00" level=info msg="time=\"2019-09-03T22:27:52.224424913Z\" level=debug msg=\"request end\" debug_console=false duration=\"341.748µs\" name=kata-agent pid=79 request=/grpc.AgentService/SignalProcess resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.51203729-07:00" level=info msg="time=\"2019-09-03T22:27:52.225113768Z\" level=info msg=\"ignoring unexpected signal\" debug_console=false name=kata-agent pid=79 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 signal=\"child exited\" source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.925641793-07:00" level=info msg="time=\"2019-09-03T22:27:52.639204711Z\" level=debug msg=\"request end\" debug_console=false duration=\"256.221µs\" name=kata-agent pid=79 request=/grpc.AgentService/SignalProcess resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.942672519-07:00" level=info msg="time=\"2019-09-03T22:27:52.656312116Z\" level=debug msg=\"request end\" debug_console=false duration=12.067063ms name=kata-agent pid=79 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.944487086-07:00" level=debug msg="Copy stream error" error="write unix /run/vc/sbs/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/proxy.sock->@: write: broken pipe" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=proxy
time="2019-09-03T15:27:52.950680796-07:00" level=info msg="time=\"2019-09-03T22:27:52.664367655Z\" level=debug msg=\"request end\" debug_console=false duration=3.753651ms name=kata-agent pid=79 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{XXX_unrecognized:[],}\" sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent\n" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=agent
time="2019-09-03T15:27:52.954956546-07:00" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9/kata.sock: use of closed network connection" name=kata-proxy pid=2215 sandbox=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 source=proxy

Shim logs

Recent shim problems found in system journal:

time="2019-09-03T14:59:47.262667854-07:00" level=info msg="copy stdout failed" container=5bce77d886dd2fa646c596df4a83f7feb8595763736c2f956a60d30cc269cf2f error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=5bce77d886dd2fa646c596df4a83f7feb8595763736c2f956a60d30cc269cf2f name=kata-shim pid=1 source=shim
time="2019-09-03T15:14:16.658677396-07:00" level=info msg="copy stdout failed" container=297adb1bd30ea1e6f23bd1c5a26c532f847f35babbdfe39cd160e67515bc8660 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=297adb1bd30ea1e6f23bd1c5a26c532f847f35babbdfe39cd160e67515bc8660 name=kata-shim pid=1 source=shim
time="2019-09-03T15:20:52.095996281-07:00" level=info msg="copy stdout failed" container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-shim pid=1 source=shim
time="2019-09-03T15:26:35.016738697-07:00" level=info msg="copy stdout failed" container=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=edd9de76d087bd4c62a3e4b9e7c37566eb88a54300b17ede1e26c3c0a1148542 name=kata-shim pid=1 source=shim
time="2019-09-03T15:27:52.51966169-07:00" level=info msg="copy stdout failed" container=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=a3348e8ed06e360bfec62282abccb9e441419e7ae22a508966f2829263c6b1d9 name=kata-shim pid=1 source=shim

Throttler logs

No recent throttler problems found in system journal.

Container manager details

Have docker

Docker

Output of "docker version":

Client:
 Version:           18.06.3
 API version:       1.38
 Go version:        go1.12.5
 Git commit:        d7080c17a580919f5340a15a8e5e013133089680
 Built:             Mon Jun  3 17:41:01 2019
 OS/Arch:           linux/amd64
 Experimental:      false

Server:
 Engine:
  Version:          18.06.3
  API version:      1.38 (minimum version 1.12)
  Go version:       go1.12.5
  Git commit:       d7080c17a580919f5340a15a8e5e013133089680
  Built:            Mon Jun  3 17:41:13 2019
  OS/Arch:          linux/amd64
  Experimental:     false

Output of "docker info":

Containers: 3
 Running: 0
 Paused: 0
 Stopped: 3
Images: 1
Server Version: 18.06.3
Storage Driver: devicemapper
 Pool Name: docker-8:3-15205092-pool
 Pool Blocksize: 65.54kB
 Base Device Size: 10.74GB
 Backing Filesystem: ext4
 Udev Sync Supported: true
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Data Space Used: 2.196GB
 Data Space Total: 107.4GB
 Data Space Available: 105.2GB
 Metadata Space Used: 18.65MB
 Metadata Space Total: 2.147GB
 Metadata Space Available: 2.129GB
 Thin Pool Minimum Free Space: 10.74GB
 Deferred Removal Enabled: true
 Deferred Deletion Enabled: true
 Deferred Deleted Device Count: 0
 Library Version: 1.02.147 (2018-06-13)
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: kata-runtime runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 1.2.6 (expected: 468a545b9edcd5932818eb9de8e72413e616e86e)
runc version: N/A (expected: a592beb5bc4c4092b1b1bac971afed27687340c5)
init version: v0.18.0 (expected: fec3683b971d9c3ef73f284f176672c44b448662)
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.19.59-PKT-190722T171340Z-dirty
Operating System: Clear Linux OS
OSType: linux
Architecture: x86_64
CPUs: 1
Total Memory: 15.33GiB
Name: ACRNSOS
ID: IAHA:4VEI:JM6V:AIPY:OABO:SFEO:MOND:2VVF:OUNF:X7PT:2NOJ:RV2E
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 23
 Goroutines: 44
 System Time: 2019-09-03T15:28:35.901523798-07:00
 EventsListeners: 0
HTTPS Proxy: http://proxy-chain.intel.com:912/
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: devicemapper: usage of loopback devices is strongly discouraged for production use.
         Use `--storage-opt dm.thinpooldev` to specify a custom block storage device.

Output of "systemctl show docker":

Type=simple
Restart=on-failure
NotifyAccess=none
RestartUSec=100ms
TimeoutStartUSec=infinity
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=374
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
ReloadResult=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestamp=Tue 2019-09-03 14:52:16 PDT
ExecMainStartTimestampMonotonic=5746723
ExecMainExitTimestampMonotonic=0
ExecMainPID=374
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/dockerd ; argv[]=/usr/bin/dockerd -D --default-runtime runc --add-runtime kata-runtime=/usr/local/bin/kata-runtime ; ignore_errors=no ; start_time=[Tue 2019-09-03 14:52:16 PDT] ; stop_time=[n/a] ; pid=374 ; 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=322383872
CPUUsageNSec=[not set]
TasksCurrent=63
IPIngressBytes=[no data]
IPIngressPackets=[no data]
IPEgressBytes=[no data]
IPEgressPackets=[no data]
Delegate=yes
DelegateControllers=cpu cpuacct io blkio memory devices pids bpf-firewall bpf-devices
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
CPUQuotaPeriodUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=yes
MemoryMin=0
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=4915
IPAccounting=no
Environment=HTTPS_PROXY=http://proxy-chain.intel.com:912/
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=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=62608
LimitSIGPENDINGSoft=62608
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=0
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
LogRateLimitIntervalUSec=0
LogRateLimitBurst=0
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
PrivateMounts=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictSUIDSGID=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
ProtectHostname=no
KillMode=process
KillSignal=15
FinalKillSignal=9
SendSIGKILL=yes
SendSIGHUP=no
WatchdogSignal=6
Id=docker.service
Names=docker.service
Requires=system.slice sysinit.target
Wants=network-online.target
WantedBy=multi-user.target
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=sysinit.target firewalld.service systemd-journald.socket basic.target system.slice network-online.target
Documentation=https://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/usr/lib/systemd/system/docker.service
DropInPaths=/etc/systemd/system/docker.service.d/https-proxy.conf /etc/systemd/system/docker.service.d/kata-containers.conf
UnitFileState=enabled
UnitFilePreset=disabled
StateChangeTimestamp=Tue 2019-09-03 14:52:16 PDT
StateChangeTimestampMonotonic=5746913
InactiveExitTimestamp=Tue 2019-09-03 14:52:16 PDT
InactiveExitTimestampMonotonic=5746913
ActiveEnterTimestamp=Tue 2019-09-03 14:52:16 PDT
ActiveEnterTimestampMonotonic=5746913
ActiveExitTimestampMonotonic=0
InactiveEnterTimestampMonotonic=0
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Tue 2019-09-03 14:52:16 PDT
ConditionTimestampMonotonic=5745935
AssertTimestamp=Tue 2019-09-03 14:52:16 PDT
AssertTimestampMonotonic=5745936
Transient=no
Perpetual=no
StartLimitIntervalUSec=1min
StartLimitBurst=3
StartLimitAction=none
FailureAction=none
SuccessAction=none
InvocationID=74431ff039f94991bbfee806278592ea
CollectMode=inactive

No kubectl
Have crio

crio

Output of "crio --version":

crio version 1.14.4
commit: unknown

Output of "systemctl show crio":

Type=notify
Restart=on-failure
NotifyAccess=main
RestartUSec=10s
TimeoutStartUSec=infinity
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=0
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
ReloadResult=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestampMonotonic=0
ExecMainExitTimestampMonotonic=0
ExecMainPID=0
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/crio ; argv[]=/usr/bin/crio $CRIO_STORAGE_OPTIONS $CRIO_NETWORK_OPTIONS $CRIO_METRICS_OPTIONS ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
ExecReload={ path=/bin/kill ; argv[]=/bin/kill -s HUP $MAINPID ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
MemoryCurrent=[not set]
CPUUsageNSec=[not set]
TasksCurrent=[not set]
IPIngressBytes=[no data]
IPIngressPackets=[no data]
IPEgressBytes=[no data]
IPEgressPackets=[no data]
Delegate=no
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
CPUQuotaPeriodUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=yes
MemoryMin=0
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=infinity
IPAccounting=no
Environment=GOTRACEBACK=crash
EnvironmentFiles=/etc/sysconfig/crio (ignore_errors=yes)
UMask=0022
LimitCPU=infinity
LimitCPUSoft=infinity
LimitFSIZE=infinity
LimitFSIZESoft=infinity
LimitDATA=infinity
LimitDATASoft=infinity
LimitSTACK=infinity
LimitSTACKSoft=8388608
LimitCORE=infinity
LimitCORESoft=infinity
LimitRSS=infinity
LimitRSSSoft=infinity
LimitNOFILE=1048576
LimitNOFILESoft=1048576
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=1048576
LimitNPROCSoft=1048576
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=62608
LimitSIGPENDINGSoft=62608
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=-999
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
LogRateLimitIntervalUSec=0
LogRateLimitBurst=0
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
PrivateMounts=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictSUIDSGID=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
ProtectHostname=no
KillMode=control-group
KillSignal=15
FinalKillSignal=9
SendSIGKILL=yes
SendSIGHUP=no
WatchdogSignal=6
Id=crio.service
Names=crio.service
Requires=system.slice sysinit.target
Wants=network-online.target
Conflicts=shutdown.target
Before=shutdown.target
After=sysinit.target network-online.target basic.target systemd-journald.socket system.slice
Documentation=https://github.com/cri-o/cri-o
Description=Open Container Initiative Daemon
LoadState=loaded
ActiveState=inactive
SubState=dead
FragmentPath=/usr/lib/systemd/system/crio.service
UnitFileState=disabled
UnitFilePreset=disabled
StateChangeTimestampMonotonic=0
InactiveExitTimestampMonotonic=0
ActiveEnterTimestampMonotonic=0
ActiveExitTimestampMonotonic=0
InactiveEnterTimestampMonotonic=0
CanStart=yes
CanStop=yes
CanReload=yes
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=no
AssertResult=no
ConditionTimestampMonotonic=0
AssertTimestampMonotonic=0
Transient=no
Perpetual=no
StartLimitIntervalUSec=2min
StartLimitBurst=6
StartLimitAction=none
FailureAction=none
SuccessAction=none
CollectMode=inactive

Output of "cat /etc/crio/crio.conf":

cat: /etc/crio/crio.conf: No such file or directory

Have containerd

containerd

Output of "containerd --version":

containerd github.com/containerd/containerd 1.2.6 1.2.6

Output of "systemctl show containerd":

Type=simple
Restart=always
NotifyAccess=none
RestartUSec=5s
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=0
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
ReloadResult=success
UID=[not set]
GID=[not set]
NRestarts=0
ExecMainStartTimestampMonotonic=0
ExecMainExitTimestampMonotonic=0
ExecMainPID=0
ExecMainCode=0
ExecMainStatus=0
ExecStartPre={ path=/sbin/modprobe ; argv[]=/sbin/modprobe overlay ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
ExecStart={ path=/usr/bin/containerd ; argv[]=/usr/bin/containerd ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
MemoryCurrent=[not set]
CPUUsageNSec=[not set]
TasksCurrent=[not set]
IPIngressBytes=[no data]
IPIngressPackets=[no data]
IPEgressBytes=[no data]
IPEgressPackets=[no data]
Delegate=yes
DelegateControllers=cpu cpuacct io blkio memory devices pids bpf-firewall bpf-devices
CPUAccounting=no
CPUWeight=[not set]
StartupCPUWeight=[not set]
CPUShares=[not set]
StartupCPUShares=[not set]
CPUQuotaPerSecUSec=infinity
CPUQuotaPeriodUSec=infinity
IOAccounting=no
IOWeight=[not set]
StartupIOWeight=[not set]
BlockIOAccounting=no
BlockIOWeight=[not set]
StartupBlockIOWeight=[not set]
MemoryAccounting=yes
MemoryMin=0
MemoryLow=0
MemoryHigh=infinity
MemoryMax=infinity
MemorySwapMax=infinity
MemoryLimit=infinity
DevicePolicy=auto
TasksAccounting=yes
TasksMax=4915
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=1048576
LimitNOFILESoft=1048576
LimitAS=infinity
LimitASSoft=infinity
LimitNPROC=infinity
LimitNPROCSoft=infinity
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=infinity
LimitLOCKSSoft=infinity
LimitSIGPENDING=62608
LimitSIGPENDINGSoft=62608
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=infinity
LimitRTTIMESoft=infinity
OOMScoreAdjust=-999
Nice=0
IOSchedulingClass=0
IOSchedulingPriority=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardInputData=
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
LogLevelMax=-1
LogRateLimitIntervalUSec=0
LogRateLimitBurst=0
SecureBits=0
CapabilityBoundingSet=cap_chown cap_dac_override cap_dac_read_search cap_fowner cap_fsetid cap_kill cap_setgid cap_setuid cap_setpcap cap_linux_immutable cap_net_bind_service cap_net_broadcast cap_net_admin cap_net_raw cap_ipc_lock cap_ipc_owner cap_sys_module cap_sys_rawio cap_sys_chroot cap_sys_ptrace cap_sys_pacct cap_sys_admin cap_sys_boot cap_sys_nice cap_sys_resource cap_sys_time cap_sys_tty_config cap_mknod cap_lease cap_audit_write cap_audit_control cap_setfcap cap_mac_override cap_mac_admin cap_syslog cap_wake_alarm cap_block_suspend
AmbientCapabilities=
DynamicUser=no
RemoveIPC=no
MountFlags=
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
PrivateMounts=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
LockPersonality=no
RuntimeDirectoryPreserve=no
RuntimeDirectoryMode=0755
StateDirectoryMode=0755
CacheDirectoryMode=0755
LogsDirectoryMode=0755
ConfigurationDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictSUIDSGID=no
RestrictNamespaces=no
MountAPIVFS=no
KeyringMode=private
ProtectHostname=no
KillMode=process
KillSignal=15
FinalKillSignal=9
SendSIGKILL=yes
SendSIGHUP=no
WatchdogSignal=6
Id=containerd.service
Names=containerd.service
Requires=system.slice sysinit.target
Conflicts=shutdown.target
Before=shutdown.target
After=network.target systemd-journald.socket sysinit.target basic.target system.slice
Documentation=https://containerd.io
Description=containerd container runtime
LoadState=loaded
ActiveState=inactive
SubState=dead
FragmentPath=/usr/lib/systemd/system/containerd.service
UnitFileState=disabled
UnitFilePreset=disabled
StateChangeTimestampMonotonic=0
InactiveExitTimestampMonotonic=0
ActiveEnterTimestampMonotonic=0
ActiveExitTimestampMonotonic=0
InactiveEnterTimestampMonotonic=0
CanStart=yes
CanStop=yes
CanReload=no
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=no
AssertResult=no
ConditionTimestampMonotonic=0
AssertTimestampMonotonic=0
Transient=no
Perpetual=no
StartLimitIntervalUSec=10s
StartLimitBurst=5
StartLimitAction=none
FailureAction=none
SuccessAction=none
CollectMode=inactive

Output of "cat /etc/containerd/config.toml":

cat: /etc/containerd/config.toml: No such file or directory

Packages

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

@vijaydhanraj
Copy link
Contributor Author

vijaydhanraj commented Sep 4, 2019 •
edited
Loading

/cc @jodh-intel @amshinde @devimc @jcvenegas @WeiZhang555 @bergwolf any thoughts on the issue?

@jodh-intel
Copy link
Contributor

/cc @mcastelino.

@amshinde
Copy link
Member

@vijaydhanraj If the state is being over-written, then this is a bug.
cc @WeiZhang555

@vijaydhanraj
Copy link
Contributor Author

Any update on this issue? This is one of the gating issues.

@vijaydhanraj
Copy link
Contributor Author

vijaydhanraj commented Sep 24, 2019 •
edited
Loading

With the latest changes, not even able to run a simple docker container. The below change fixes the issue.
cc @WeiZhang555 , @amshinde , @jodh-intel @devimc @jcvenegas

func (s *Sandbox) getAndSetSandboxBlockIndex() (int, error) {
	currentIndex := s.state.BlockIndex
	// Increment so that container gets incremented block index
	s.state.BlockIndex++
	/*
		if !s.supportNewStore() {
			// experimental runtime use "persist.json" which doesn't need "state.json" anymore
			// update on-disk state
			if err := s.store.Store(store.State, s.state); err != nil {
				return -1, err
			}
		}
	*/
	return currentIndex, nil
}

@WeiZhang555
Copy link
Member

@vijaydhanraj Can you add one more line into the configuration file(might be "/opt/kata/share/defaults/kata-containers/configuration.toml" if you install from the release tar)

experimental=['newstore']

and have another try? This can make the s.supportNewStore() true.

I think your modification could impact other hypervisor implementations but not sure, please file a PR and let's check the Jenkins test result.

@vijaydhanraj
Copy link
Contributor Author

Hi @WeiZhang555 , I did try adding 'newstore' to the configuration.toml but my latest PR changes #2075 fail with newstore option. I am trying to create a global store which can be accessed by any kata-runtime process.

With newstore option, the kata-runtime doesn't seem to use the already created store (in my case the UUID store). Is this the expectation?

@vijaydhanraj
Copy link
Contributor Author

Since the SandboxState is not loaded, we see corruption of the sandbox state. The following logs show the same,

Oct 06 22:41:32 ACRNSOS kata-runtime[1620]: time="2019-10-06T22:41:32.03749759-07:00" level=info msg="Sandbox State before LOAD= {State: BlockIndex:0 GuestMemoryBlockSizeMB:0 GuestMemoryHotplugProbe:false CgroupPath: PersistVersion:0}" arch=amd64 command=state container=dcebcea58d6666a538a321726cc724f3ca42f84962eb2ab688f6bdabe32e3286 name=kata-runtime pid=1620 sandbox=dcebcea58d6666a538a321726cc724f3ca42f84962eb2ab688f6bdabe32e3286 source=virtcontainers subsystem=sandbox
Oct 06 22:41:32 ACRNSOS kata-runtime[1620]: time="2019-10-06T22:41:32.037564263-07:00" level=info msg="getAndSetSandboxBlockIndex: Sandbox State = {State:ready BlockIndex:2 GuestMemoryBlockSizeMB:128 GuestMemoryHotplugProbe:false CgroupPath: PersistVersion:0}" arch=amd64 command=state container=dcebcea58d6666a538a321726cc724f3ca42f84962eb2ab688f6bdabe32e3286 name=kata-runtime pid=1620 sandbox=dcebcea58d6666a538a321726cc724f3ca42f84962eb2ab688f6bdabe32e3286 source=virtcontainers subsystem=sandbox

With the below code changes, things seem to work fine.

diff --git a/virtcontainers/sandbox.go b/virtcontainers/sandbox.go
index 119e653..c50a456 100644
--- a/virtcontainers/sandbox.go
+++ b/virtcontainers/sandbox.go
@@ -1601,11 +1601,18 @@ func (s *Sandbox) resumeSetStates() error {
 // subsequent accesses. This index is used to maintain the index at which a
 // block device is assigned to a container in the sandbox.
 func (s *Sandbox) getAndSetSandboxBlockIndex() (int, error) {
+       if s.store != nil {
+               err := s.store.Load(store.State, &s.state)
+               if err == nil && s.state.State == "" {
+                       return -1, fmt.Errorf("getAndSetSandboxBlockIndex: Failed to load sandbox state: Empty State")
+               }
+       } else {
+               return -1, fmt.Errorf("getAndSetSandboxBlockIndex: Empty Store")
+       }
        currentIndex := s.state.BlockIndex
 
        // Increment so that container gets incremented block index
        s.state.BlockIndex++
-
        if !s.supportNewStore() {
                // experimental runtime use "persist.json" which doesn't need "state.json" anymore
                // update on-disk state
@@ -1613,13 +1620,20 @@ func (s *Sandbox) getAndSetSandboxBlockIndex() (int, error) {
                        return -1, err
                }
        }
-
        return currentIndex, nil
 }
 
 // decrementSandboxBlockIndex decrements the current sandbox block index.
 // This is used to recover from failure while adding a block device.
 func (s *Sandbox) decrementSandboxBlockIndex() error {
+       if s.store != nil {
+               err := s.store.Load(store.State, &s.state)
+               if err == nil && s.state.State == "" {
+                       return fmt.Errorf("decrementSandboxBlockIndex: Failed to load sandbox state: Empty State")
+               }
+       } else {
+               return fmt.Errorf("decrementSandboxBlockIndex:Empty Store")
+       }
        s.state.BlockIndex--
 
        if !s.supportNewStore() {
@@ -1629,7 +1643,6 @@ func (s *Sandbox) decrementSandboxBlockIndex() error {
                        return err
                }
        }
-
        return nil
 }

amshinde added a commit to amshinde/kata-runtime that referenced this issue Oct 8, 2019
@amshinde
state: Load the state from storage early on
e8018e6 
The hypervisor.createSandbox may need to access the state.
For eg, ACRN today needs to access the block index to assign
it to the root image of the VM. Hence load this early on.

Fixes kata-containers#2026

Signed-off-by: Archana Shinde <archana.m.shinde@intel.com>
amshinde added a commit to amshinde/kata-runtime that referenced this issue Oct 8, 2019
@amshinde
state: Load the state from storage early on
fa4acad 
The hypervisor.createSandbox may need to access the state.
For eg, ACRN today needs to access the block index to assign
it to the root image of the VM. Hence load this early on.

Fixes kata-containers#2026

Signed-off-by: Archana Shinde <archana.m.shinde@intel.com>
@amshinde amshinde mentioned this issue Oct 8, 2019
Merged
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Load state early so that hypervisor can store the correct state amshinde/kata-runtime
4 participants
@WeiZhang555 @amshinde @jodh-intel @vijaydhanraj