Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

metrics: fast footprint #766

Merged

Conversation

grahamwhaley
Copy link
Contributor

Add a system level footprint test, that should be faster to run than the
existing footprint_data.sh test. It should be faster as it:

  • launches containers in parallel, not just linearly
  • does not take measurements after each launch, just at the start and end

@grahamwhaley
Copy link
Contributor Author

Offering this up as a WIP/RFC right now, as it currently shows up a couple of interesting 'things'...

On a small machine (my 2-core (HT disabled) NUC, 32Gb RAM), running this test gets us what look to be VM launch timeouts:

..........docker: Error response from daemon: OCI runtime create failed: Failed to check if grpc server is working: rpc error: code = DeadlineExceeded desc = context deadline exceeded: unknown.

I believe launching 10 containers at a time, with a 10s sleep between each batch, is just too slow on my low core count machine. We should discuss if this is a real issue for us, and if we need to look at out grpc timeouts and consider bumping them up etc.

Secondly, if I run this on a bigger machine (88core Xeon, 384Gb RAM), then the test happily launches all 200 containers with no ti..........docker: Error response from daemon: OCI runtime create failed: Failed to check if grpc server is working: rpc error: code = DeadlineExceeded desc = context deadline exceeded: unknown.
meouts. Then it enters the KSM settle detection phase, and even with the mildly aggressive settings from over in the metrics library, it hits the 5minute timeout waiting for it to settle. I even bumped that to a 20minute timeout, and we still hit it. I guess 200 VMs is just a lot for KSM to merge.

Thus, with the defaults as they are we see anomalies running on both small machines and big machines (and I'm sure the KSM issue will be worse on the smaller machines anyway).

For the grpc timeouts, I think we should discuss, probably debug, and debate.
For the KSM - well, as we are just talking through settings on the throttler as well, maybe we can merge those two discussions.

@grahamwhaley
Copy link
Contributor Author

/me goes to add Fixes to commit

# Kata Containers density metrics tests

This directory contains a number of tests to help measure container
density. Some measures are based around the PSS of the runtime components,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd consider defining the term container density. Something like:

to help measure the number of containers that can be run simultaneously, known as container density.

Also how about a definition of PSS?

In fact, it might even be worth creating a doc specifically for abbreviations and acronymns like this that all test docs could refer to?

@@ -0,0 +1,46 @@
# Kata Containers density metrics tests
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: missing TOC.

and others look at the system level ('free' and '/proc/meminfo' for instance)
impact.

## docker_memory_usage
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Might be worth putting these test names in the titles in backticks?


This directory contains a number of tests to help measure container
density. Some measures are based around the PSS of the runtime components,
and others look at the system level ('free' and '/proc/meminfo' for instance)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd use backticks for these two.

## docker_memory_usage

This test measures the PSS footprint of the runtime components whilst
launching a number of small (busybox) containers.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.


# See if KSM is enabled.
# If so, ammend the test name to reflect that
# FIXME - needs refactoring - see https://github.com/kata-containers/tests/issues/519
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Issue closed so can this comment be dropped?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

heh, that is the one bit of ksm code that did not get pulled out into the lib afaict. Let me do that now then...

fi
}

# helper function to get USS of prcess in arg1
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: typo - process. Ditto below.


echo "Timed out waiting for containers to launch (${t}s)"
cleanup
die "Timed out waiting for containers to launch (${t}s)"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As we have this die, do we need the echo above with the same message?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I put the two in as the cleanup can take some time (depending on how many containers one has run). When running interactively I wanted some indication that we'd died/timed out on screen before the final death.

else
echo "Waiting for containers to launch (${numcontainers} at ${t}s)"
fi
sleep 3
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't this be sleep $step?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good spot

metrics_json_end_array "Results"
}


Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: extraneous blank line.

@jodh-intel
Copy link
Contributor

Ping @grahamwhaley - we gotta whip these wips! 😄

@grahamwhaley grahamwhaley changed the title [RFC] metrics: fast footprint metrics: fast footprint Sep 25, 2018
@grahamwhaley grahamwhaley removed the wip label Sep 25, 2018
@grahamwhaley
Copy link
Contributor Author

Updated. Found a couple of errors in the JSON generation (typos) whilst there. Tested once we got around the grpc timeout issue...

@grahamwhaley
Copy link
Contributor Author

/test

# kill_processes_before_start
}

# helper function to get USS of prcess in arg1
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

process

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

oops - missed one! thx, fixed, pushed.

@GabyCT
Copy link
Contributor

GabyCT commented Sep 27, 2018

@grahamwhaley , I ran the script fast-footprint.sh and while running after iteration 3, I am getting the following message docker: Error response from daemon: OCI runtime create failed: Failed to check if grpc server is working: rpc error: code = Unavailable desc = transport is closing: unknown, I do not know if this message is related with this PR or something else is happening, this is the configuration that I am using

# Meta details

Running `kata-collect-data.sh` version `1.3.0-rc1 (commit 0d99a4f49f60d936fa15e5a0842cfd4d03a24e8f)` at `2018-09-27.21:50:48.136563316+0000`.

---

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

# `kata-env`

Output of "`/usr/local/bin/kata-runtime kata-env`":
```toml
[Meta]
  Version = "1.0.18"

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

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

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

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

[Initrd]
  Path = ""

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

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

[Agent]
  Type = "kata"

[Host]
  Kernel = "4.15.0-1023-azure"
  Architecture = "amd64"
  VMContainerCapable = true
  SupportVSocks = false
  [Host.Distro]
    Name = "Ubuntu"
    Version = "16.04"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz"

[Netmon]
  Version = "kata-netmon version 1.3.0-rc1"
  Path = "/usr/libexec/kata-containers/kata-netmon"
  Debug = true
  Enable = false

Runtime config files

Runtime default config files

/etc/kata-containers/configuration.toml
/usr/share/defaults/kata-containers/configuration.toml

Runtime config file contents

Config file /etc/kata-containers/configuration.toml not found
Output of "cat "/usr/share/defaults/kata-containers/configuration.toml"":

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

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

[hypervisor.qemu]
path = "/usr/bin/qemu-lite-system-x86_64"
kernel = "/usr/share/kata-containers/vmlinuz.container"
image = "/usr/share/kata-containers/kata-containers.img"
machine_type = "pc"

# Optional space-separated list of options to pass to the guest kernel.
# For example, use `kernel_params = "vsyscall=emulate"` if you are having
# trouble running pre-2.15 glibc.
#
# WARNING: - any parameter specified here will take priority over the default
# parameter value of the same name used to start the virtual machine.
# Do not set values here unless you understand the impact of doing so as you
# may stop the virtual machine from booting.
# To see the list of default parameters, enable hypervisor debug, create a
# container and look for 'default-kernel-parameters' log entries.
kernel_params = " agent.log=debug"

# Path to the firmware.
# If you want that qemu uses the default firmware leave this option empty
firmware = ""

# Machine accelerators
# comma-separated list of machine accelerators to pass to the hypervisor.
# For example, `machine_accelerators = "nosmm,nosmbus,nosata,nopit,static-prt,nofw"`
machine_accelerators=""

# Default number of vCPUs per SB/VM:
# unspecified or 0                --> will be set to 1
# < 0                             --> will be set to the actual number of physical cores
# > 0 <= number of physical cores --> will be set to the specified number
# > number of physical cores      --> will be set to the actual number of physical cores
default_vcpus = 1

# Default maximum number of vCPUs per SB/VM:
# unspecified or == 0             --> will be set to the actual number of physical cores or to the maximum number
#                                     of vCPUs supported by KVM if that number is exceeded
# > 0 <= number of physical cores --> will be set to the specified number
# > number of physical cores      --> will be set to the actual number of physical cores or to the maximum number
#                                     of vCPUs supported by KVM if that number is exceeded
# WARNING: Depending of the architecture, the maximum number of vCPUs supported by KVM is used when
# the actual number of physical cores is greater than it.
# WARNING: Be aware that this value impacts the virtual machine's memory footprint and CPU
# the hotplug functionality. For example, `default_maxvcpus = 240` specifies that until 240 vCPUs
# can be added to a SB/VM, but the memory footprint will be big. Another example, with
# `default_maxvcpus = 8` the memory footprint will be small, but 8 will be the maximum number of
# vCPUs supported by the SB/VM. In general, we recommend that you do not edit this variable,
# unless you know what are you doing.
default_maxvcpus = 0

# Bridges can be used to hot plug devices.
# Limitations:
# * Currently only pci bridges are supported
# * Until 30 devices per bridge can be hot plugged.
# * Until 5 PCI bridges can be cold plugged per VM.
#   This limitation could be a bug in qemu or in the kernel
# Default number of bridges per SB/VM:
# unspecified or 0   --> will be set to 1
# > 1 <= 5           --> will be set to the specified number
# > 5                --> will be set to 5
default_bridges = 1

# Default memory size in MiB for SB/VM.
# If unspecified then it will be set 2048 MiB.
#default_memory = 2048
#
# Default memory slots per SB/VM.
# If unspecified then it will be set 10.
# This is will determine the times that memory will be hotadded to sandbox/VM.
#memory_slots = 10

# Disable block device from being used for a container's rootfs.
# In case of a storage driver like devicemapper where a container's
# root file system is backed by a block device, the block device is passed
# directly to the hypervisor for performance reasons.
# This flag prevents the block device from being passed to the hypervisor,
# 9pfs is used instead to pass the rootfs.
disable_block_device_use = false

# Block storage driver to be used for the hypervisor in case the container
# rootfs is backed by a block device. This is either virtio-scsi or
# virtio-blk.
block_device_driver = "virtio-scsi"

# Enable iothreads (data-plane) to be used. This causes IO to be
# handled in a separate IO thread. This is currently only implemented
# for SCSI.
#
enable_iothreads = false

# Enable pre allocation of VM RAM, default false
# Enabling this will result in lower container density
# as all of the memory will be allocated and locked
# This is useful when you want to reserve all the memory
# upfront or in the cases where you want memory latencies
# to be very predictable
# Default false
#enable_mem_prealloc = true

# Enable huge pages for VM RAM, default false
# Enabling this will result in the VM memory
# being allocated using huge pages.
# This is useful when you want to use vhost-user network
# stacks within the container. This will automatically
# result in memory pre allocation
#enable_hugepages = true

# Enable swap of vm memory. Default false.
# The behaviour is undefined if mem_prealloc is also set to true
#enable_swap = true

# This option changes the default hypervisor and kernel parameters
# to enable debug output where available. This extra output is added
# to the proxy logs, but only when proxy debug is also enabled.
#
# Default false
enable_debug = true

# Disable the customizations done in the runtime when it detects
# that it is running on top a VMM. This will result in the runtime
# behaving as it would when running on bare metal.
#
#disable_nesting_checks = true

# This is the msize used for 9p shares. It is the number of bytes
# used for 9p packet payload.
#msize_9p = 8192

# If true and vsocks are supported, use vsocks to communicate directly
# with the agent and no proxy is started, otherwise use unix
# sockets and start a proxy to communicate with the agent.
# Default false
#use_vsock = true

# VFIO devices are hotplugged on a bridge by default.
# Enable hotplugging on root bus. This may be required for devices with
# a large PCI bar, as this is a current limitation with hotplugging on
# a bridge. This value is valid for "pc" machine type.
# Default false
#hotplug_vfio_on_root_bus = true

# If host doesn't support vhost_net, set to true. Thus we won't create vhost fds for nics.
# Default false
#disable_vhost_net = true
#
# Default entropy source.
# The path to a host source of entropy (including a real hardware RNG)
# /dev/urandom and /dev/random are two main options.
# Be aware that /dev/random is a blocking source of entropy.  If the host
# runs out of entropy, the VMs boot time will increase leading to get startup
# timeouts.
# The source of entropy /dev/urandom is non-blocking and provides a
# generally acceptable source of entropy. It should work well for pretty much
# all practical purposes.
#entropy_source= "/dev/urandom"

[factory]
# VM templating support. Once enabled, new VMs are created from template
# using vm cloning. They will share the same initial kernel, initramfs and
# agent memory by mapping it readonly. It helps speeding up new container
# creation and saves a lot of memory if there are many kata containers running
# on the same host.
#
# When disabled, new VMs are created from scratch.
#
# Default false
#enable_template = true

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

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

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

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

[agent.kata]
# There is no field for this section. The goal is only to be able to
# specify which type of agent the user wants to use.

[netmon]
# If enabled, the network monitoring process gets started when the
# sandbox is created. This allows for the detection of some additional
# network being added to the existing network namespace, after the
# sandbox has been created.
# (default: disabled)
#enable_netmon = true

# Specify the path to the netmon binary.
path = "/usr/libexec/kata-containers/kata-netmon"

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

[runtime]
# If enabled, the runtime will log additional debug messages to the
# system log
# (default: disabled)
enable_debug = true
#
# Internetworking model
# Determines how the VM should be connected to the
# the container network interface
# Options:
#
#   - bridged
#     Uses a linux bridge to interconnect the container interface to
#     the VM. Works for most cases except macvlan and ipvlan.
#
#   - macvtap
#     Used when the Container network interface can be bridged using
#     macvtap.
internetworking_model="macvtap"

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

KSM throttler

version

Output of " --version":

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

systemd service

Image details

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

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.3.0-rc1-1ee972176ae437bcace0a37227818c506bb64ba9"
  agent-is-init-daemon: "no"

Initrd details

No initrd


Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2018-09-27T21:43:56.436261624Z" level=debug arch=amd64 command=create container=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=23682 source=virtcontainers subsystem=qemu
time="2018-09-27T21:44:13.738792245Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e name=kata-runtime pid=23992 source=virtcontainers subsystem=kata_agent
time="2018-09-27T21:44:13.738934745Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e error="open /run/vc/sbs/e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e/devices.json: no such file or directory" name=kata-runtime pid=23992 sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e sandboxid=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=virtcontainers subsystem=sandbox
time="2018-09-27T21:44:13.741966842Z" level=debug arch=amd64 command=create container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=23992 source=virtcontainers subsystem=qemu
time="2018-09-27T21:44:30.733468207Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 name=kata-runtime pid=24276 source=virtcontainers subsystem=kata_agent
time="2018-09-27T21:44:30.734019506Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 error="open /run/vc/sbs/fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735/devices.json: no such file or directory" name=kata-runtime pid=24276 sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 sandboxid=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=virtcontainers subsystem=sandbox
time="2018-09-27T21:44:30.738242003Z" level=debug arch=amd64 command=create container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=24276 source=virtcontainers subsystem=qemu
time="2018-09-27T21:44:48.406482773Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 name=kata-runtime pid=24591 source=virtcontainers subsystem=kata_agent
time="2018-09-27T21:44:48.406669672Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 error="open /run/vc/sbs/7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645/devices.json: no such file or directory" name=kata-runtime pid=24591 sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 sandboxid=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=virtcontainers subsystem=sandbox
time="2018-09-27T21:44:48.40959697Z" level=debug arch=amd64 command=create container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 default-kernel-parameters="tsc=reliable no_timer_check rcupdate.rcu_expedited=1 i8042.direct=1 i8042.dumbkbd=1 i8042.nopnp=1 i8042.noaux=1 noreplace-smp reboot=k console=hvc0 console=hvc1 iommu=off cryptomgr.notests net.ifnames=0 pci=lastbus=0 root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 debug systemd.show_status=true systemd.log_level=debug" name=kata-runtime pid=24591 source=virtcontainers subsystem=qemu
time="2018-09-27T21:45:06.912172909Z" level=error msg="Container c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 name=kata-runtime pid=25105 sandbox=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 source=runtime
time="2018-09-27T21:45:06.952965474Z" level=error msg="Container 64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 name=kata-runtime pid=25100 sandbox=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 source=runtime
time="2018-09-27T21:45:07.035099204Z" level=error msg="Container 8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 name=kata-runtime pid=25120 sandbox=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 source=runtime
time="2018-09-27T21:45:07.050898791Z" level=error msg="Container 6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 name=kata-runtime pid=25093 sandbox=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 source=runtime
time="2018-09-27T21:45:07.559438358Z" level=error msg="Container 829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a name=kata-runtime pid=25140 sandbox=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a source=runtime
time="2018-09-27T21:45:07.611763713Z" level=error msg="Container 8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea name=kata-runtime pid=25143 sandbox=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea source=runtime
time="2018-09-27T21:45:07.644341585Z" level=error msg="Container 4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 name=kata-runtime pid=25144 sandbox=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 source=runtime
time="2018-09-27T21:45:07.644849585Z" level=error msg="Container e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e name=kata-runtime pid=25177 sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=runtime
time="2018-09-27T21:45:07.669322864Z" level=error msg="Container 1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 name=kata-runtime pid=25178 sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=runtime
time="2018-09-27T21:45:07.743088001Z" level=error msg="Container bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 name=kata-runtime pid=25136 sandbox=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 source=runtime
time="2018-09-27T21:45:07.75586529Z" level=error msg="Container 592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 name=kata-runtime pid=25146 sandbox=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 source=runtime
time="2018-09-27T21:45:07.859885801Z" level=error msg="Container 2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 name=kata-runtime pid=25212 sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=runtime
time="2018-09-27T21:45:07.910580758Z" level=error msg="Container fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 name=kata-runtime pid=25207 sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=runtime
time="2018-09-27T21:45:07.982872797Z" level=error msg="Container 7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 name=kata-runtime pid=25253 sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=runtime
time="2018-09-27T21:45:08.028763957Z" level=error msg="Container 230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 name=kata-runtime pid=25295 sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=runtime
time="2018-09-27T21:45:08.03782695Z" level=error msg="Container 4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c name=kata-runtime pid=25297 sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=runtime
time="2018-09-27T21:45:08.03787015Z" level=error msg="Container 8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 name=kata-runtime pid=25262 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=runtime
time="2018-09-27T21:45:08.087192308Z" level=error msg="Container 1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb name=kata-runtime pid=25306 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=runtime
time="2018-09-27T21:45:08.129077772Z" level=error msg="Container 3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 name=kata-runtime pid=25352 sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=runtime
time="2018-09-27T21:45:08.137904464Z" level=error msg="Container 64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 name=kata-runtime pid=25368 sandbox=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 source=runtime
time="2018-09-27T21:45:08.15439955Z" level=error msg="Container 8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 name=kata-runtime pid=25336 sandbox=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 source=runtime
time="2018-09-27T21:45:08.161443944Z" level=error msg="Container c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 name=kata-runtime pid=25369 sandbox=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 source=runtime
time="2018-09-27T21:45:08.262818958Z" level=error msg="Container d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 name=kata-runtime pid=25377 sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=runtime
time="2018-09-27T21:45:08.263321457Z" level=error msg="Container 6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 name=kata-runtime pid=25411 sandbox=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 source=runtime
time="2018-09-27T21:45:08.569477397Z" level=error msg="Container 8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea name=kata-runtime pid=25559 sandbox=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea source=runtime
time="2018-09-27T21:45:08.599285671Z" level=error msg="Container e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e name=kata-runtime pid=25566 sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=runtime
time="2018-09-27T21:45:08.630520044Z" level=error msg="Container 829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a name=kata-runtime pid=25570 sandbox=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a source=runtime
time="2018-09-27T21:45:08.667716413Z" level=error msg="Container 1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 name=kata-runtime pid=25593 sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=runtime
time="2018-09-27T21:45:08.731232559Z" level=error msg="Container 4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 name=kata-runtime pid=25608 sandbox=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 source=runtime
time="2018-09-27T21:45:08.738489952Z" level=error msg="Container 592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 name=kata-runtime pid=25646 sandbox=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 source=runtime
time="2018-09-27T21:45:08.770971925Z" level=error msg="Container bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 name=kata-runtime pid=25643 sandbox=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 source=runtime
time="2018-09-27T21:45:08.806523094Z" level=error msg="Container fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 name=kata-runtime pid=25674 sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=runtime
time="2018-09-27T21:45:08.807630693Z" level=error msg="Container 2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 name=kata-runtime pid=25647 sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=runtime
time="2018-09-27T21:45:08.881036631Z" level=error msg="Container 7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 name=kata-runtime pid=25772 sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=runtime
time="2018-09-27T21:45:08.957591966Z" level=error msg="Container 1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb name=kata-runtime pid=25860 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=runtime
time="2018-09-27T21:45:08.962545361Z" level=error msg="Container 8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 name=kata-runtime pid=25844 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=runtime
time="2018-09-27T21:45:08.962903261Z" level=error msg="Container 230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 name=kata-runtime pid=25858 sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=runtime
time="2018-09-27T21:45:09.018906813Z" level=error msg="Container 4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c name=kata-runtime pid=25886 sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=runtime
time="2018-09-27T21:45:09.041835394Z" level=error msg="Container 3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 name=kata-runtime pid=25897 sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=runtime
time="2018-09-27T21:45:09.282390689Z" level=error msg="Container d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 not ready, running or paused, cannot send a signal" arch=amd64 command=kill container=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 name=kata-runtime pid=26002 sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=runtime

Proxy logs

Recent proxy problems found in system journal:

time="2018-09-27T21:45:06.422993226Z" level=info msg="time=\"2018-09-27T21:45:06.400739334Z\" level=debug msg=\"request end\" duration=53.941546ms name=kata-agent pid=102 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 source=agent\n" name=kata-proxy pid=21959 sandbox=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 source=agent
time="2018-09-27T21:45:06.425419624Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107/kata.sock: use of closed network connection" name=kata-proxy pid=21959 sandbox=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 source=proxy
time="2018-09-27T21:45:06.440943311Z" level=info msg="time=\"2018-09-27T21:45:06.310750305Z\" level=debug msg=\"request end\" duration=27.078789ms name=kata-agent pid=101 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=agent\n" name=kata-proxy pid=19241 sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=agent
time="2018-09-27T21:45:06.511385351Z" level=info msg="time=\"2018-09-27T21:45:06.493784409Z\" level=debug msg=\"request end\" duration=\"59.022µs\" error=\"rpc error: code = NotFound desc = Process 1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb not found (container 1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb)\" name=kata-agent pid=97 request=/grpc.AgentService/WaitProcess resp= sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent\n" name=kata-proxy pid=23439 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent
time="2018-09-27T21:45:06.515325947Z" level=info msg="time=\"2018-09-27T21:45:06.457620203Z\" level=debug msg=\"request end\" duration=\"33.053µs\" error=\"rpc error: code = NotFound desc = Process 8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 not found (container 8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3)\" name=kata-agent pid=113 request=/grpc.AgentService/WaitProcess resp= sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent\n" name=kata-proxy pid=22838 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent
time="2018-09-27T21:45:06.530581234Z" level=info msg="time=\"2018-09-27T21:45:06.503704289Z\" level=debug msg=\"request end\" duration=\"924.244µs\" name=kata-agent pid=106 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=agent\n" name=kata-proxy pid=23134 sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=agent
time="2018-09-27T21:45:06.541185825Z" level=info msg="time=\"2018-09-27T21:45:06.518744256Z\" level=debug msg=\"request end\" duration=7.23491ms name=kata-agent pid=113 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent\n" name=kata-proxy pid=22838 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent
time="2018-09-27T21:45:06.54713602Z" level=info msg="time=\"2018-09-27T21:45:06.523802688Z\" level=debug msg=\"request end\" duration=71.708151ms name=kata-agent pid=102 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 source=agent\n" name=kata-proxy pid=21020 sandbox=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 source=agent
time="2018-09-27T21:45:06.553993415Z" level=info msg="time=\"2018-09-27T21:45:06.529018244Z\" level=debug msg=\"request end\" duration=750.841785ms name=kata-agent pid=115 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 source=agent\n" name=kata-proxy pid=20433 sandbox=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 source=agent
time="2018-09-27T21:45:06.555585413Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45/kata.sock: use of closed network connection" name=kata-proxy pid=20433 sandbox=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 source=proxy
time="2018-09-27T21:45:06.604120572Z" level=info msg="time=\"2018-09-27T21:45:06.554228345Z\" level=debug msg=\"request end\" duration=\"728.89µs\" name=kata-agent pid=97 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent\n" name=kata-proxy pid=23439 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent
time="2018-09-27T21:45:06.698263892Z" level=info msg="time=\"2018-09-27T21:45:06.677764453Z\" level=debug msg=\"request end\" duration=388.433475ms name=kata-agent pid=106 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 source=agent\n" name=kata-proxy pid=21338 sandbox=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 source=agent
time="2018-09-27T21:45:06.708977082Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625/kata.sock: use of closed network connection" name=kata-proxy pid=21338 sandbox=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 source=proxy
time="2018-09-27T21:45:06.773656127Z" level=info msg="time=\"2018-09-27T21:45:06.659140221Z\" level=debug msg=\"request end\" duration=\"900.652µs\" name=kata-agent pid=109 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=agent\n" name=kata-proxy pid=18959 sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=agent
time="2018-09-27T21:45:06.787370516Z" level=fatal msg="channel error" error="accept unix /run/vc/sbs/8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813/proxy.sock: use of closed network connection" name=kata-proxy pid=21020 sandbox=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 source=proxy
time="2018-09-27T21:45:06.799508005Z" level=info msg="time=\"2018-09-27T21:45:06.773723889Z\" level=debug msg=\"request end\" duration=232.223967ms name=kata-agent pid=105 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 source=agent\n" name=kata-proxy pid=23740 sandbox=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 source=agent
time="2018-09-27T21:45:06.802768302Z" level=info msg="time=\"2018-09-27T21:45:06.783440253Z\" level=debug msg=\"request end\" duration=404.372478ms name=kata-agent pid=103 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=agent\n" name=kata-proxy pid=20144 sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=agent
time="2018-09-27T21:45:06.821042387Z" level=info msg="time=\"2018-09-27T21:45:06.794768662Z\" level=debug msg=\"request end\" duration=263.305282ms name=kata-agent pid=108 request=/grpc.AgentService/RemoveContainer resp=\"&Empty{}\" sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=agent\n" name=kata-proxy pid=19824 sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=agent
time="2018-09-27T21:45:07.105409245Z" level=info msg="time=\"2018-09-27T21:45:07.083276924Z\" level=debug msg=\"request end\" duration=560.593008ms name=kata-agent pid=101 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=agent\n" name=kata-proxy pid=24033 sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=agent
time="2018-09-27T21:45:07.109124341Z" level=info msg="time=\"2018-09-27T21:45:07.084610413Z\" level=debug msg=\"request end\" duration=311.639266ms name=kata-agent pid=110 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea source=agent\n" name=kata-proxy pid=20744 sandbox=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea source=agent
time="2018-09-27T21:45:07.118920233Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9/kata.sock: use of closed network connection" name=kata-proxy pid=23740 sandbox=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 source=proxy
time="2018-09-27T21:45:07.1580012Z" level=info msg="time=\"2018-09-27T21:45:07.13775698Z\" level=debug msg=\"request end\" duration=757.082957ms name=kata-agent pid=110 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a source=agent\n" name=kata-proxy pid=19553 sandbox=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a source=agent
time="2018-09-27T21:45:07.195412068Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a/kata.sock: use of closed network connection" name=kata-proxy pid=19553 sandbox=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a source=proxy
time="2018-09-27T21:45:07.197834266Z" level=info msg="time=\"2018-09-27T21:45:07.17653716Z\" level=debug msg=\"request end\" duration=483.708201ms name=kata-agent pid=108 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 source=agent\n" name=kata-proxy pid=21639 sandbox=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 source=agent
time="2018-09-27T21:45:07.219617547Z" level=fatal msg="channel error" error="accept unix /run/vc/sbs/8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea/proxy.sock: use of closed network connection" name=kata-proxy pid=20744 sandbox=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea source=proxy
time="2018-09-27T21:45:07.225048643Z" level=info msg="time=\"2018-09-27T21:45:07.205470189Z\" level=debug msg=\"request end\" duration=1.333942616s name=kata-agent pid=110 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 source=agent\n" name=kata-proxy pid=22255 sandbox=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 source=agent
time="2018-09-27T21:45:07.253223219Z" level=fatal msg="channel error" error="accept unix /run/vc/sbs/4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997/proxy.sock: use of closed network connection" name=kata-proxy pid=21639 sandbox=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 source=proxy
time="2018-09-27T21:45:07.270206004Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47/kata.sock: use of closed network connection" name=kata-proxy pid=22255 sandbox=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 source=proxy
time="2018-09-27T21:45:07.315428466Z" level=info msg="time=\"2018-09-27T21:45:07.290031643Z\" level=debug msg=\"request end\" duration=857.443067ms name=kata-agent pid=115 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=agent\n" name=kata-proxy pid=24631 sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=agent
time="2018-09-27T21:45:07.325855157Z" level=info msg="time=\"2018-09-27T21:45:07.306173122Z\" level=debug msg=\"request end\" duration=395.562008ms name=kata-agent pid=103 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=agent\n" name=kata-proxy pid=20144 sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=agent
time="2018-09-27T21:45:07.334750049Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e/kata.sock: use of closed network connection" name=kata-proxy pid=24033 sandbox=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e source=proxy
time="2018-09-27T21:45:07.365772423Z" level=fatal msg="channel error" error="accept unix /run/vc/sbs/1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2/proxy.sock: use of closed network connection" name=kata-proxy pid=20144 sandbox=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 source=proxy
time="2018-09-27T21:45:07.378511312Z" level=info msg="time=\"2018-09-27T21:45:07.299972406Z\" level=debug msg=\"request end\" duration=997.805027ms name=kata-agent pid=109 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=agent\n" name=kata-proxy pid=24335 sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=agent
time="2018-09-27T21:45:07.395004598Z" level=info msg="time=\"2018-09-27T21:45:07.324555597Z\" level=debug msg=\"request end\" duration=225.998353ms name=kata-agent pid=101 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=agent\n" name=kata-proxy pid=19241 sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=agent
time="2018-09-27T21:45:07.478386027Z" level=info msg="time=\"2018-09-27T21:45:07.344694348Z\" level=debug msg=\"request end\" duration=208.749291ms name=kata-agent pid=104 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=agent\n" name=kata-proxy pid=22565 sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=agent
time="2018-09-27T21:45:07.49789581Z" level=info msg="time=\"2018-09-27T21:45:07.470888382Z\" level=debug msg=\"request end\" duration=204.924576ms name=kata-agent pid=106 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=agent\n" name=kata-proxy pid=23134 sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=agent
time="2018-09-27T21:45:07.507141502Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735/kata.sock: use of closed network connection" name=kata-proxy pid=24335 sandbox=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 source=proxy
time="2018-09-27T21:45:07.516050794Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2/kata.sock: use of closed network connection" name=kata-proxy pid=19241 sandbox=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 source=proxy
time="2018-09-27T21:45:07.631635696Z" level=info msg="time=\"2018-09-27T21:45:07.608211789Z\" level=debug msg=\"request end\" duration=452.500687ms name=kata-agent pid=113 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent\n" name=kata-proxy pid=22838 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=agent
time="2018-09-27T21:45:07.657674374Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645/kata.sock: use of closed network connection" name=kata-proxy pid=24631 sandbox=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 source=proxy
time="2018-09-27T21:45:07.714522525Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3/kata.sock: use of closed network connection" name=kata-proxy pid=22838 sandbox=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 source=proxy
time="2018-09-27T21:45:07.746807498Z" level=info msg="time=\"2018-09-27T21:45:07.728811864Z\" level=debug msg=\"request end\" duration=483.873111ms name=kata-agent pid=97 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent\n" name=kata-proxy pid=23439 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=agent
time="2018-09-27T21:45:07.751407694Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3/kata.sock: use of closed network connection" name=kata-proxy pid=23134 sandbox=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 source=proxy
time="2018-09-27T21:45:07.762279285Z" level=debug msg="Copy stream error" error="read unix /run/vc/sbs/4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c/proxy.sock->@: use of closed network connection" name=kata-proxy pid=22565 sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=proxy
time="2018-09-27T21:45:07.762435384Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c/kata.sock: use of closed network connection" name=kata-proxy pid=22565 sandbox=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c source=proxy
time="2018-09-27T21:45:07.809024545Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb/kata.sock: use of closed network connection" name=kata-proxy pid=23439 sandbox=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb source=proxy
time="2018-09-27T21:45:07.888097977Z" level=info msg="time=\"2018-09-27T21:45:07.827148664Z\" level=debug msg=\"request end\" duration=537.600835ms name=kata-agent pid=109 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=agent\n" name=kata-proxy pid=18959 sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=agent
time="2018-09-27T21:45:07.904584663Z" level=fatal msg="channel error" error="accept unix /run/vc/sbs/3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299/proxy.sock: use of closed network connection" name=kata-proxy pid=18959 sandbox=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 source=proxy
time="2018-09-27T21:45:07.987599793Z" level=info msg="time=\"2018-09-27T21:45:07.961324397Z\" level=debug msg=\"request end\" duration=680.491281ms name=kata-agent pid=108 request=/grpc.AgentService/DestroySandbox resp=\"&Empty{}\" sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=agent\n" name=kata-proxy pid=19824 sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=agent
time="2018-09-27T21:45:07.989657691Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3/kata.sock: use of closed network connection" name=kata-proxy pid=19824 sandbox=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 source=proxy

Shim logs

Recent shim problems found in system journal:

time="2018-09-27T21:18:51.080030973Z" level=info msg="copy stdout failed" container=492542d0c39af602a7fac80e5b4ed60071c39d2f8c5b4666794df000775a992a error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=492542d0c39af602a7fac80e5b4ed60071c39d2f8c5b4666794df000775a992a name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.097826956Z" level=info msg="copy stdout failed" container=6510fbfebd598ad5b014c75308a8702b489cd0266afa1d0f4813ad993c1d53c4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6510fbfebd598ad5b014c75308a8702b489cd0266afa1d0f4813ad993c1d53c4 name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.099417755Z" level=info msg="copy stdout failed" container=81e3263a691b7198621cb72b233ff1bc3f6308bdf5545851be7bc3497e28eb19 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=81e3263a691b7198621cb72b233ff1bc3f6308bdf5545851be7bc3497e28eb19 name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.114030042Z" level=info msg="copy stdout failed" container=9dde0f22ba46522d724d4c1314a686ebe1a0666ac7561342a218f88230a9ae90 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=9dde0f22ba46522d724d4c1314a686ebe1a0666ac7561342a218f88230a9ae90 name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.117570039Z" level=info msg="copy stdout failed" container=cac37b17d720b3c277602f7d52137e02167e03c79d21b35ec8fe236c8906e055 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=cac37b17d720b3c277602f7d52137e02167e03c79d21b35ec8fe236c8906e055 name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.121524635Z" level=info msg="copy stdout failed" container=3605ba98d29c411a72f4e74c0a050a3e05deeb8d6adc144f8c03b069b2bebc3c error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=3605ba98d29c411a72f4e74c0a050a3e05deeb8d6adc144f8c03b069b2bebc3c name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.135521822Z" level=info msg="copy stdout failed" container=06fdb43ecdd53b12a295638114a4ccae66e3d88a2341d954a94173ebee9729fd error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=06fdb43ecdd53b12a295638114a4ccae66e3d88a2341d954a94173ebee9729fd name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.156561403Z" level=info msg="copy stdout failed" container=cbb9362cd288f079d273e1156d4b42252a0b2a3170c581d8b6720c3c0113f31e error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=cbb9362cd288f079d273e1156d4b42252a0b2a3170c581d8b6720c3c0113f31e name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.207041057Z" level=info msg="copy stdout failed" container=6462410509e6b4bf1ae9537ba149e0a3398e0876c7b39b4e0be652ff7d601636 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6462410509e6b4bf1ae9537ba149e0a3398e0876c7b39b4e0be652ff7d601636 name=kata-shim pid=1 source=shim
time="2018-09-27T21:18:51.221378045Z" level=info msg="copy stdout failed" container=171589ccf2fb5efa2e710eeaa27a3c271d8a28dbfaae94101c25ab2cc6773769 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=171589ccf2fb5efa2e710eeaa27a3c271d8a28dbfaae94101c25ab2cc6773769 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:31.956225703Z" level=info msg="copy stdout failed" container=d32409719c3dbdb135bae9944f4b8f41b84ee4558e654026e079d3d84256d7e4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=d32409719c3dbdb135bae9944f4b8f41b84ee4558e654026e079d3d84256d7e4 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.016074049Z" level=info msg="copy stdout failed" container=9d6a6aea99a5b6c3fc2a3b3c0545171fc083cb1ad31c46a0518b33acd56116e9 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=9d6a6aea99a5b6c3fc2a3b3c0545171fc083cb1ad31c46a0518b33acd56116e9 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.023618243Z" level=info msg="copy stdout failed" container=d9e91180e3398a6772d553774677c65d1b9c5adf9fec56aa48cd9f3b303bc3e7 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=d9e91180e3398a6772d553774677c65d1b9c5adf9fec56aa48cd9f3b303bc3e7 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.051746517Z" level=info msg="copy stdout failed" container=e9f3cea34a88404a0704470b9b3ea01b1ae3c4f58a4fa543ea2a955e2fc55496 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=e9f3cea34a88404a0704470b9b3ea01b1ae3c4f58a4fa543ea2a955e2fc55496 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.055793014Z" level=info msg="copy stdout failed" container=223517445fc7935f3b07f51f046d821bc13d80535534493dc42ce13038aefea4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=223517445fc7935f3b07f51f046d821bc13d80535534493dc42ce13038aefea4 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.058531011Z" level=info msg="copy stdout failed" container=16f987cc0a5d050646b34165c1647f2e2112bc1c5fbc548fe2f89f3faa91bd9d error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=16f987cc0a5d050646b34165c1647f2e2112bc1c5fbc548fe2f89f3faa91bd9d name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.063572707Z" level=info msg="copy stdout failed" container=eb7d422c03ab0d2349357b33b5cb1471b0eb3e419426ca6f558c6491dd4146f4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=eb7d422c03ab0d2349357b33b5cb1471b0eb3e419426ca6f558c6491dd4146f4 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.070214201Z" level=info msg="copy stdout failed" container=62b550e6900406c931f304f61decd61fd8773f2ec872cea8a91c586a09be3fe9 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=62b550e6900406c931f304f61decd61fd8773f2ec872cea8a91c586a09be3fe9 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.094263379Z" level=info msg="copy stdout failed" container=f9d72c4ee68e7c70d7f0bea776e738b017c62da4b7fcf7204b2caff5ad59f1a4 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=f9d72c4ee68e7c70d7f0bea776e738b017c62da4b7fcf7204b2caff5ad59f1a4 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.106807568Z" level=info msg="copy stdout failed" container=dbc63a048f70f6b538ad9a10cd3801fb648e01542de5f8475463fe28fb11ab34 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=dbc63a048f70f6b538ad9a10cd3801fb648e01542de5f8475463fe28fb11ab34 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.109899565Z" level=info msg="copy stdout failed" container=3d1015ea20a9d1bde779aa05cf9c60d63abec213b7041368927b3ce988554753 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=3d1015ea20a9d1bde779aa05cf9c60d63abec213b7041368927b3ce988554753 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.115196261Z" level=info msg="copy stdout failed" container=3cd4a4d7ec96a9874f9ae13162694356da44350cb7744ddd80c8405915629495 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=3cd4a4d7ec96a9874f9ae13162694356da44350cb7744ddd80c8405915629495 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.129029348Z" level=info msg="copy stdout failed" container=370b332664ffa8f7cdbb3611f24603aa5e434860065b448c52d6c3cf7c7eea4b error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=370b332664ffa8f7cdbb3611f24603aa5e434860065b448c52d6c3cf7c7eea4b name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.137629441Z" level=info msg="copy stdout failed" container=b1e89213318fecd412bece92e64dbebdd9551df1adfafa0a1a74d7249651084c error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=b1e89213318fecd412bece92e64dbebdd9551df1adfafa0a1a74d7249651084c name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.155975124Z" level=info msg="copy stdout failed" container=a967cc85ba4d0dc1c25194cca545cb19eb5bcf6664e33f11242898c2ff1d26e6 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=a967cc85ba4d0dc1c25194cca545cb19eb5bcf6664e33f11242898c2ff1d26e6 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.166799215Z" level=info msg="copy stdout failed" container=d237d65a4881cd27234ae62ce18da9863b21cbaa1ee65f49c7935abbed8a0ff8 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=d237d65a4881cd27234ae62ce18da9863b21cbaa1ee65f49c7935abbed8a0ff8 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.17250781Z" level=info msg="copy stdout failed" container=805c6f288a6204d3c1417627afe89c594b3e456f2d412ba9dd7613d81d97b361 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=805c6f288a6204d3c1417627afe89c594b3e456f2d412ba9dd7613d81d97b361 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.245460544Z" level=info msg="copy stdout failed" container=4d077ff5797de0cd377431c5ab11c19624757b93a061f25cf0806b8f1f7ac6bd error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=4d077ff5797de0cd377431c5ab11c19624757b93a061f25cf0806b8f1f7ac6bd name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.316571081Z" level=info msg="copy stdout failed" container=7b25071a9b6aad2912f64afb65c008e3a6cbe87d3675917d75d7ee61beb41502 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=7b25071a9b6aad2912f64afb65c008e3a6cbe87d3675917d75d7ee61beb41502 name=kata-shim pid=1 source=shim
time="2018-09-27T21:34:32.372884731Z" level=info msg="copy stdout failed" container=27fde921106c931d53c572358c24ec2a139ef27dbe6c76754eef21c7489f1385 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=27fde921106c931d53c572358c24ec2a139ef27dbe6c76754eef21c7489f1385 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.77563223Z" level=info msg="copy stdout failed" container=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=4c8bed307c51e953f0ef58ef462f11fe69c3b5482cee3b8c1e52cd7b5b4cd997 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.805771805Z" level=info msg="copy stdout failed" container=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=8db8f84cea168104bbd37021b925130a59c1d31eadb0c361b9a2ebb9c1ac3813 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.850226467Z" level=info msg="copy stdout failed" container=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=6f4125daf044ab2160fddfb1188759a36f9be3552318f7aaa54b7e7beb997107 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.854286263Z" level=info msg="copy stdout failed" container=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=64f57c9818dc7a0081b66dcf70af2e6c41cf24d99c36e64331a4f1a423645a45 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.909900216Z" level=info msg="copy stdout failed" container=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=bd69d426baa083da5305d6bdd4707130451ad9940dbe23ccb4d94271459acec9 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.93982609Z" level=info msg="copy stdout failed" container=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=8a9c764b13548ce6a093103ac31e296ef4f4e018dfd4f3ef812a798c176948ea name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.950123882Z" level=info msg="copy stdout failed" container=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=fa5c82c43fc6a2a1f1ce6a8ca861512e1a4e6fa3fee9f2d697ad134e9d567735 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:04.957958575Z" level=info msg="copy stdout failed" container=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=829a30d73a49d1602970f95d287d6eff337a894f9bc32c814e5e0f32e3f1183a name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.008607932Z" level=info msg="copy stdout failed" container=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=1124ecb41240180be896defcb9fe8504982f4c15baba78cfe41b0d596e43c7b2 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.038360506Z" level=info msg="copy stdout failed" container=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=2ad38d5e2f3d24ce2af75066213781bbef2e7a49858a06db8a965ab460114ef2 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.05693249Z" level=info msg="copy stdout failed" container=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=3fdc2c99f20c8f86ccaebdf2d0cd61fe772904417badc29767e3ceb1cda42299 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.060128188Z" level=info msg="copy stdout failed" container=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=c92b9d744056e15891a71cfbb7194c8a1d4da68dcf1919b34afce54f1e440625 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.06895548Z" level=info msg="copy stdout failed" container=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=7dbf4ae5cd68a581f6a1681cd00dea4c695562642dc3dd3bfb8efe2f0c032645 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.087871364Z" level=info msg="copy stdout failed" container=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=d1d846c3a08cece13a8917b7a30a6e3586d5bfba7e07e101ac73c516341d6ad3 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.100602153Z" level=info msg="copy stdout failed" container=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=592b7fd038bf45bc547bc29a844ba39e02b10a9c765245a55c6ee89ae7276b47 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.111379344Z" level=info msg="copy stdout failed" container=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=e54e2bf3b71e9ec2e89c31031524bd19914d5725372d0ed529e1cc13aa16b63e name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.122912234Z" level=info msg="copy stdout failed" container=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=4067bca0b4fa7f4f51eb177e04c49665beb2011ed1c9715c0abaa38020f2f47c name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.13959022Z" level=info msg="copy stdout failed" container=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=230081f78240d0cbce6b8495ebad289a83e4a5259f41c579d6108633943d5cb3 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.179495786Z" level=info msg="copy stdout failed" container=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=8f24626fa1bba03ec7f05d03a914032621300071e5287844994fe09c14e0ecf3 name=kata-shim pid=1 source=shim
time="2018-09-27T21:45:05.206264263Z" level=info msg="copy stdout failed" container=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb error="rpc error: code = Unknown desc = read /dev/ptmx: input/output error" exec-id=1f9ab5598f7b30d8ba478370c3ae76938ee87b3abb26ebd9cacfac3366c754eb 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.1-ce
 API version:       1.38
 Go version:        go1.10.3
 Git commit:        e68fc7a
 Built:             Tue Aug 21 17:24:56 2018
 OS/Arch:           linux/amd64
 Experimental:      false

Server:
 Engine:
  Version:          18.06.1-ce
  API version:      1.38 (minimum version 1.12)
  Go version:       go1.10.3
  Git commit:       e68fc7a
  Built:            Tue Aug 21 17:23:21 2018
  OS/Arch:          linux/amd64
  Experimental:     false

Output of "docker info":

Containers: 0
 Running: 0
 Paused: 0
 Stopped: 0
Images: 7
Server Version: 18.06.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: false
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: runc kata-runtime
Default Runtime: kata-runtime
Init Binary: docker-init
containerd version: 468a545b9edcd5932818eb9de8e72413e616e86e
runc version: 0d99a4f49f60d936fa15e5a0842cfd4d03a24e8f (expected: 69663f0bd4b60df09991c08812a60108003fa340)
init version: fec3683
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.15.0-1023-azure
Operating System: Ubuntu 16.04.5 LTS
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 7.791GiB
Name: gabypnp
ID: 5TIH:5YPR:375O:JVJ3:KXX7:TTJO:TDTA:AEI2:ZHZ5:DBIV:GTLY:Y7C4
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 35
 Goroutines: 44
 System Time: 2018-09-27T21:50:50.803700802Z
 EventsListeners: 0
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: No swap limit support

Output of "systemctl show docker":

Type=notify
Restart=on-failure
NotifyAccess=main
RestartUSec=100ms
TimeoutStartUSec=infinity
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestamp=Wed 2018-09-26 16:21:30 UTC
WatchdogTimestampMonotonic=3061530170
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=1198
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
ExecMainStartTimestamp=Wed 2018-09-26 16:21:14 UTC
ExecMainStartTimestampMonotonic=3045688776
ExecMainExitTimestampMonotonic=0
ExecMainPID=1198
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/bin/dockerd ; argv[]=/usr/bin/dockerd -D --add-runtime kata-runtime=/usr/local/bin/kata-runtime --default-runtime=kata-runtime --storage-driver=overlay2 ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
ExecReload={ path=/bin/kill ; argv[]=/bin/kill -s HUP $MAINPID ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
ControlGroup=/system.slice/docker.service
MemoryCurrent=214786048
CPUUsageNSec=2257312283532
TasksCurrent=194
Delegate=yes
CPUAccounting=no
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=no
TasksMax=18446744073709551615
UMask=0022
LimitCPU=18446744073709551615
LimitCPUSoft=18446744073709551615
LimitFSIZE=18446744073709551615
LimitFSIZESoft=18446744073709551615
LimitDATA=18446744073709551615
LimitDATASoft=18446744073709551615
LimitSTACK=18446744073709551615
LimitSTACKSoft=8388608
LimitCORE=18446744073709551615
LimitCORESoft=18446744073709551615
LimitRSS=18446744073709551615
LimitRSSSoft=18446744073709551615
LimitNOFILE=1048576
LimitNOFILESoft=1048576
LimitAS=18446744073709551615
LimitASSoft=18446744073709551615
LimitNPROC=18446744073709551615
LimitNPROCSoft=18446744073709551615
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=18446744073709551615
LimitLOCKSSoft=18446744073709551615
LimitSIGPENDING=31828
LimitSIGPENDINGSoft=31828
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=18446744073709551615
LimitRTTIMESoft=18446744073709551615
OOMScoreAdjust=0
Nice=0
IOScheduling=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
SecureBits=0
CapabilityBoundingSet=18446744073709551615
AmbientCapabilities=0
MountFlags=0
PrivateTmp=no
PrivateNetwork=no
PrivateDevices=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
KillMode=process
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=docker.service
Names=docker.service
Requires=docker.socket system.slice sysinit.target
Wants=network-online.target
WantedBy=multi-user.target
ConsistsOf=docker.socket
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=sysinit.target network-online.target system.slice docker.socket firewalld.service basic.target systemd-journald.socket
TriggeredBy=docker.socket
Documentation=https://docs.docker.com
Description=Docker Application Container Engine
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/docker.service
DropInPaths=/etc/systemd/system/docker.service.d/kata-containers.conf
UnitFileState=enabled
UnitFilePreset=enabled
StateChangeTimestamp=Wed 2018-09-26 16:21:30 UTC
StateChangeTimestampMonotonic=3061530172
InactiveExitTimestamp=Wed 2018-09-26 16:21:14 UTC
InactiveExitTimestampMonotonic=3045688830
ActiveEnterTimestamp=Wed 2018-09-26 16:21:30 UTC
ActiveEnterTimestampMonotonic=3061530172
ActiveExitTimestamp=Wed 2018-09-26 16:21:13 UTC
ActiveExitTimestampMonotonic=3044547194
InactiveEnterTimestamp=Wed 2018-09-26 16:21:14 UTC
InactiveEnterTimestampMonotonic=3045552660
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
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Wed 2018-09-26 16:21:14 UTC
ConditionTimestampMonotonic=3045687959
AssertTimestamp=Wed 2018-09-26 16:21:14 UTC
AssertTimestampMonotonic=3045687959
Transient=no
StartLimitInterval=60000000
StartLimitBurst=3
StartLimitAction=none

Have kubectl

Kubernetes

Output of "kubectl version":

Client Version: version.Info{Major:"1", Minor:"10", GitVersion:"v1.10.5", GitCommit:"32ac1c9073b132b8ba18aa830f46b77dcceb0723", GitTreeState:"clean", BuildDate:"2018-06-21T11:46:00Z", GoVersion:"go1.9.3", Compiler:"gc", Platform:"linux/amd64"}
The connection to the server localhost:8080 was refused - did you specify the right host or port?

Output of "kubectl config view":

apiVersion: v1
clusters: []
contexts: []
current-context: ""
kind: Config
preferences: {}
users: []

Output of "systemctl show kubelet":

Type=simple
Restart=always
NotifyAccess=none
RestartUSec=10s
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=0
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=exit-code
ExecMainStartTimestamp=Thu 2018-09-27 21:50:45 UTC
ExecMainStartTimestampMonotonic=109216485955
ExecMainExitTimestamp=Thu 2018-09-27 21:50:45 UTC
ExecMainExitTimestampMonotonic=109216611500
ExecMainPID=28204
ExecMainCode=1
ExecMainStatus=255
ExecStart={ path=/usr/bin/kubelet ; argv[]=/usr/bin/kubelet $KUBELET_KUBECONFIG_ARGS $KUBELET_SYSTEM_PODS_ARGS $KUBELET_NETWORK_ARGS $KUBELET_DNS_ARGS $KUBELET_AUTHZ_ARGS $KUBELET_CADVISOR_ARGS $KUBELET_CERTIFICATE_ARGS $KUBELET_EXTRA_ARGS ; ignore_errors=no ; start_time=[Thu 2018-09-27 21:50:45 UTC] ; stop_time=[Thu 2018-09-27 21:50:45 UTC] ; pid=28204 ; code=exited ; status=255 }
Slice=system.slice
MemoryCurrent=18446744073709551615
CPUUsageNSec=18446744073709551615
TasksCurrent=18446744073709551615
Delegate=no
CPUAccounting=no
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=no
TasksMax=18446744073709551615
Environment=KUBELET_KUBECONFIG_ARGS=--bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf\x20--kubeconfig=/etc/kubernetes/kubelet.conf KUBELET_SYSTEM_PODS_ARGS=--pod-manifest-path=/etc/kubernetes/manifests\x20--allow-privileged=true KUBELET_NETWORK_ARGS=--network-plugin=cni\x20--cni-conf-dir=/etc/cni/net.d\x20--cni-bin-dir=/opt/cni/bin KUBELET_DNS_ARGS=--cluster-dns=10.96.0.10\x20--cluster-domain=cluster.local KUBELET_AUTHZ_ARGS=--authorization-mode=Webhook\x20--client-ca-file=/etc/kubernetes/pki/ca.crt KUBELET_EXTRA_ARGS=--container-runtime=remote\x20--container-runtime-endpoint=unix:///var/run/crio/crio.sock\x20--runtime-request-timeout=30m KUBELET_CADVISOR_ARGS=--cadvisor-port=0 KUBELET_CERTIFICATE_ARGS=--rotate-certificates=true\x20--cert-dir=/var/lib/kubelet/pki
UMask=0022
LimitCPU=18446744073709551615
LimitCPUSoft=18446744073709551615
LimitFSIZE=18446744073709551615
LimitFSIZESoft=18446744073709551615
LimitDATA=18446744073709551615
LimitDATASoft=18446744073709551615
LimitSTACK=18446744073709551615
LimitSTACKSoft=8388608
LimitCORE=18446744073709551615
LimitCORESoft=0
LimitRSS=18446744073709551615
LimitRSSSoft=18446744073709551615
LimitNOFILE=4096
LimitNOFILESoft=1024
LimitAS=18446744073709551615
LimitASSoft=18446744073709551615
LimitNPROC=31828
LimitNPROCSoft=31828
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=18446744073709551615
LimitLOCKSSoft=18446744073709551615
LimitSIGPENDING=31828
LimitSIGPENDINGSoft=31828
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=18446744073709551615
LimitRTTIMESoft=18446744073709551615
OOMScoreAdjust=0
Nice=0
IOScheduling=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
SecureBits=0
CapabilityBoundingSet=18446744073709551615
AmbientCapabilities=0
MountFlags=0
PrivateTmp=no
PrivateNetwork=no
PrivateDevices=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
KillMode=control-group
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=kubelet.service
Names=kubelet.service
Requires=system.slice sysinit.target
WantedBy=multi-user.target
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=sysinit.target systemd-journald.socket basic.target system.slice
Documentation=http://kubernetes.io/docs/
Description=kubelet: The Kubernetes Node Agent
LoadState=loaded
ActiveState=activating
SubState=auto-restart
FragmentPath=/lib/systemd/system/kubelet.service
DropInPaths=/etc/systemd/system/kubelet.service.d/10-kubeadm.conf
UnitFileState=enabled
UnitFilePreset=enabled
StateChangeTimestamp=Thu 2018-09-27 21:50:45 UTC
StateChangeTimestampMonotonic=109216612420
InactiveExitTimestamp=Thu 2018-09-27 21:50:45 UTC
InactiveExitTimestampMonotonic=109216612420
ActiveEnterTimestamp=Thu 2018-09-27 21:50:45 UTC
ActiveEnterTimestampMonotonic=109216486011
ActiveExitTimestamp=Thu 2018-09-27 21:50:45 UTC
ActiveExitTimestampMonotonic=109216611801
InactiveEnterTimestamp=Thu 2018-09-27 21:50:45 UTC
InactiveEnterTimestampMonotonic=109216611801
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
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Thu 2018-09-27 21:50:45 UTC
ConditionTimestampMonotonic=109216485048
AssertTimestamp=Thu 2018-09-27 21:50:45 UTC
AssertTimestampMonotonic=109216485048
Transient=no
StartLimitInterval=0
StartLimitBurst=5
StartLimitAction=none

Have crio
Output of "crio --version":

crio version 1.10.7-dev
commit: "6273bea4c9ed788aeb3d051ebf2d030060c05b6c"

Output of "systemctl show crio":

Type=simple
Restart=on-failure
NotifyAccess=none
RestartUSec=5s
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestampMonotonic=0
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=0
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
ExecMainStartTimestampMonotonic=0
ExecMainExitTimestampMonotonic=0
ExecMainPID=0
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/local/bin/crio ; argv[]=/usr/local/bin/crio --log-level debug ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
MemoryCurrent=18446744073709551615
CPUUsageNSec=18446744073709551615
TasksCurrent=18446744073709551615
Delegate=no
CPUAccounting=no
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=no
TasksMax=18446744073709551615
UMask=0022
LimitCPU=18446744073709551615
LimitCPUSoft=18446744073709551615
LimitFSIZE=18446744073709551615
LimitFSIZESoft=18446744073709551615
LimitDATA=18446744073709551615
LimitDATASoft=18446744073709551615
LimitSTACK=18446744073709551615
LimitSTACKSoft=8388608
LimitCORE=18446744073709551615
LimitCORESoft=0
LimitRSS=18446744073709551615
LimitRSSSoft=18446744073709551615
LimitNOFILE=4096
LimitNOFILESoft=1024
LimitAS=18446744073709551615
LimitASSoft=18446744073709551615
LimitNPROC=31828
LimitNPROCSoft=31828
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=18446744073709551615
LimitLOCKSSoft=18446744073709551615
LimitSIGPENDING=31828
LimitSIGPENDINGSoft=31828
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=18446744073709551615
LimitRTTIMESoft=18446744073709551615
OOMScoreAdjust=0
Nice=0
IOScheduling=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
SecureBits=0
CapabilityBoundingSet=18446744073709551615
AmbientCapabilities=0
MountFlags=0
PrivateTmp=no
PrivateNetwork=no
PrivateDevices=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
KillMode=control-group
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=crio.service
Names=crio.service
Requires=system.slice sysinit.target
Conflicts=shutdown.target
Before=shutdown.target
After=sysinit.target systemd-journald.socket basic.target system.slice
Documentation=https://github.com/kubernetes-incubator/cri-o
Description=CRI-O daemon
LoadState=loaded
ActiveState=inactive
SubState=dead
FragmentPath=/etc/systemd/system/crio.service
UnitFileState=disabled
UnitFilePreset=enabled
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
JobTimeoutAction=none
ConditionResult=no
AssertResult=no
ConditionTimestampMonotonic=0
AssertTimestampMonotonic=0
Transient=no
StartLimitInterval=10000000
StartLimitBurst=5
StartLimitAction=none

Packages

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

ii  kata-containers-image               1.3.0~rc1-34                               amd64        Kata containers image
ii  qemu-lite                           2.11.0+git.f886228056-50                   amd64        linux kernel optimised for container-like workloads.

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


I ran the footprint_data.sh script and I did not see the previous error, I even check the json and everything is looking fine.

@grahamwhaley
Copy link
Contributor Author

Hi @GabyCT . I suspect the error is eeked out by this test as it is a bit 'harder' than the normal footprint test. This test launches containers in parallel - by default 10 at a time, which can eek out some issues or push some boundaries - for instance, my best guess is that you may be suffering some form of the 'entropy depletion' issue. That was fixed v.recently over at kata-containers/runtime#781 - could you update all your components to the HEAD and see if the issue persists? If it does, we'll have to go debug it. I'm fairly certain it's not a problem with the test itself, but the test may be exposing an issue.

@grahamwhaley
Copy link
Contributor Author

Oh, hold on - sigh, a rebase went wonky and added an extra commit in there not from the series. sigh. Let me figure out how to fix that!

The KSM settling detection code was living inside the
docker memory test. We want to make use of that detection
code in other tests as well, so move it out to the common
lib to live with the other KSM related functions.

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
@grahamwhaley
Copy link
Contributor Author

Fixed with a rebase - normal service has resumed....

@GabyCT
Copy link
Contributor

GabyCT commented Sep 28, 2018

@grahamwhaley , I'll do a re-test thanks

@GabyCT
Copy link
Contributor

GabyCT commented Sep 28, 2018

/test

@GabyCT
Copy link
Contributor

GabyCT commented Sep 28, 2018

lgtm

Approved with PullApprove Approved with PullApprove

@GabyCT
Copy link
Contributor

GabyCT commented Sep 28, 2018

@intelkevinputnam or @klynnrif could you please check this? thanks

Copy link

@intelkevinputnam intelkevinputnam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall looks really good. I think the readability of fast_footprint would be improved by adding a bulleted list for the configurable options.

containers in parallel and optionally waiting for KSM to settle its memory
compaction cycles.

The script is quite configurable via environment variables on which container

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Try a bulleted list for the options in this paragraph.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think I see what you mean @intelkevinputnam - have broken into a list and worded as such. ptal.

@GabyCT
Copy link
Contributor

GabyCT commented Oct 3, 2018

@intelkevinputnam ptal

Copy link

@intelkevinputnam intelkevinputnam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@grahamwhaley
Copy link
Contributor Author

I believe all is ship shape here - looking for another review from @kata-containers/tests


docker kill $(docker ps -qa)

# kill_processes_before_start
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

remove this commented line?

function grab_stats() {
# If configured, dump the caches so we get a more stable
# view of what our static footprint really is
if [[ DUMP_CACHES ]] ; then
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

shouldn't this be: if [[ "$DUMP_CACHES" ]]; then

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

oops, yes! That got inherited from the footprint_data.sh, so has been in there for ages. Let me fix them both...

Graham Whaley added 5 commits October 5, 2018 10:40
Add a footprint test that runs faster than the footprint_data
test by:
 - launching containers in parallel
 - only taking a measure at the start/end, and not at every launch

Can also be very useful for:
 - launching many containers (to test scale out)
 - testing parallel launches

Fixes: kata-containers#767

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
Add a README file giving a brief description and introduction to the
available density related tests.

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
The ksm enabled check function missed being factored out to the
common lib with the other ksm code, and has been breeding. Reduce
its population to one copy, in the common library.

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
Fix tiny typo in footprint data scripts.

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
The check for DUMP_CACHES was incorrect, meaning the cache dump
probably always happened. Fix the expression.
There was a leftover commented out call and comments in the cleanup
routine - remove them.

Signed-off-by: Graham Whaley <graham.whaley@intel.com>
@grahamwhaley
Copy link
Contributor Author

Good spots @chavafg - fixed and pushed, in both the fast footprint and the original footprint.
/test

@chavafg
Copy link
Contributor

chavafg commented Oct 5, 2018

Seems like jenkins started some machines without nested virtualization

time="2018-10-05T10:00:40Z" level=info msg="kernel property found" arch=amd64 description="Intel KVM" name=kvm_intel pid=15968 source=runtime type=module
time="2018-10-05T10:00:40Z" level=error msg="open /sys/module/kvm_intel/parameters/unrestricted_guest: no such file or directory" arch=amd64 name=kata-runtime pid=15968 source=runtime
open /sys/module/kvm_intel/parameters/unrestricted_guest: no such file or directory

any idea @mnaser?
Restarting jobs...

@chavafg
Copy link
Contributor

chavafg commented Oct 9, 2018

lgtm

Approved with PullApprove

@chavafg chavafg merged commit b0c879e into kata-containers:master Oct 9, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants