kata-containers / runtime

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

Soak test failing in Debian 9 #1132

Closed GabyCT closed 4 years ago

GabyCT commented 5 years ago

While running the soak test in Debian 9, we see that some of the containers that are being launched have the Created status instead of Running which is making the soak test to fail.

$ docker ps -a
CONTAINER ID        IMAGE               COMMAND                  CREATED             STATUS              PORTS               NAMES
c9e24c2ab817        nginx:1.14          "nginx -g 'daemon of…"   3 minutes ago       Created             80/tcp              flamboyant_torvalds
18a01badbb11        nginx:1.14          "nginx -g 'daemon of…"   3 minutes ago       Up 3 minutes        80/tcp              gifted_davinci
775f20dfe806        nginx:1.14          "nginx -g 'daemon of…"   4 minutes ago       Up 3 minutes        80/tcp              keen_goldwasser
ceeadbb05348        nginx:1.14          "nginx -g 'daemon of…"   4 minutes ago       Up 4 minutes        80/tcp              festive_hugle
cd35a7567017        nginx:1.14          "nginx -g 'daemon of…"   5 minutes ago       Up 5 minutes        80/tcp              focused_goodall
1780030b0c3b        nginx:1.14          "nginx -g 'daemon of…"   6 minutes ago       Up 5 minutes        80/tcp              trusting_bose
f8995a60d486        nginx:1.14          "nginx -g 'daemon of…"   6 minutes ago       Up 6 minutes        80/tcp              sharp_lalande
690ebd601320        nginx:1.14          "nginx -g 'daemon of…"   6 minutes ago       Up 6 minutes        80/tcp              reverent_leakey
fdad286cee63        nginx:1.14          "nginx -g 'daemon of…"   7 minutes ago       Up 7 minutes        80/tcp              xenodochial_mendeleev
42ab47d578da        nginx:1.14          "nginx -g 'daemon of…"   8 minutes ago       Up 7 minutes        80/tcp              youthful_shannon
47fc3fb534d8        nginx:1.14          "nginx -g 'daemon of…"   8 minutes ago       Up 8 minutes        80/tcp              priceless_poitras
b2345b83ff4f        nginx:1.14          "nginx -g 'daemon of…"   9 minutes ago       Up 9 minutes        80/tcp              wonderful_jepsen
68d4894512ed        nginx:1.14          "nginx -g 'daemon of…"   9 minutes ago       Up 9 minutes        80/tcp              awesome_haibt
0dce1dd93eb7        nginx:1.14          "nginx -g 'daemon of…"   9 minutes ago       Up 9 minutes        80/tcp              frosty_goodall

Here it is the information of the setup and logs

# Meta details

Running `kata-collect-data.sh` version `1.5.0-rc2 (commit 4fda4933845d2f8590d65420e8036e494d6f7a0b)` at `2019-01-15.16:46:57.109457931+0000`.

---

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

# `kata-env`

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

[Runtime]
  Debug = true
  Trace = false
  DisableGuestSeccomp = true
  DisableNewNetNs = false
  Path = "/usr/local/bin/kata-runtime"
  [Runtime.Version]
    Semver = "1.5.0-rc2"
    Commit = "4fda4933845d2f8590d65420e8036e494d6f7a0b"
    OCI = "1.0.1-dev"
  [Runtime.Config]
    Path = "/usr/share/defaults/kata-containers/configuration.toml"

[Hypervisor]
  MachineType = "pc"
  Version = "QEMU emulator version 2.11.0 (v2.11.0-rc0-310-gf886228056-dirty)\nCopyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers"
  Path = "/usr/bin/qemu-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.5.0-rc2_agent_91a87bc7176.img"

[Kernel]
  Path = "/usr/share/kata-containers/vmlinuz-4.14.67-22"
  Parameters = "init=/usr/lib/systemd/systemd systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket agent.log=debug"

[Initrd]
  Path = ""

[Proxy]
  Type = "kataProxy"
  Version = "kata-proxy version 1.5.0-rc2-2029708f472b91e8167081ea87974b268589c8ab"
  Path = "/usr/libexec/kata-containers/kata-proxy"
  Debug = true

[Shim]
  Type = "kataShim"
  Version = "kata-shim version 1.5.0-rc2-4138b29661d044a298924ba60c5fd79a8b213862"
  Path = "/usr/libexec/kata-containers/kata-shim"
  Debug = true

[Agent]
  Type = "kata"

[Host]
  Kernel = "4.9.0-8-amd64"
  Architecture = "amd64"
  VMContainerCapable = true
  SupportVSocks = false
  [Host.Distro]
    Name = "Debian GNU/Linux"
    Version = "9"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz"

[Netmon]
  Version = "kata-netmon version 1.5.0-rc2"
  Path = "/usr/libexec/kata-containers/kata-netmon"
  Debug = true
  Enable = true

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

# The size in MiB will be plused to max memory of hypervisor.
# It is the memory address space for the NVDIMM devie.
# If set block storage driver (block_device_driver) to "nvdimm",
# should set memory_offset to the size of block device.
# Default 0
#memory_offset = 0

# 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 virtio-scsi, virtio-blk
# or nvdimm.
block_device_driver = "virtio-scsi"

# Specifies cache-related options will be set to block devices or not.
# Default false
#block_device_cache_set = true

# Specifies cache-related options for block devices.
# Denotes whether use of O_DIRECT (bypass the host page cache) is enabled.
# Default false
#block_device_cache_direct = true

# Specifies cache-related options for block devices.
# Denotes whether flush requests for the device are ignored.
# Default false
#block_device_cache_noflush = true

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

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

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

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

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

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

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

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

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

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

# Path to OCI hook binaries in the *guest rootfs*.
# This does not affect host-side hooks which must instead be added to
# the OCI spec passed to the runtime.
#
# You can create a rootfs with hooks by customizing the osbuilder scripts:
# https://github.com/kata-containers/osbuilder
#
# Hooks must be stored in a subdirectory of guest_hook_path according to their
# hook type, i.e. "guest_hook_path/{prestart,postart,poststop}".
# The agent will scan these directories for executable files and add them, in
# lexicographical order, to the lifecycle of the guest container.
# Hooks are executed in the runtime namespace of the guest. See the official documentation:
# https://github.com/opencontainers/runtime-spec/blob/v1.0.1/config.md#posix-platform-hooks
# Warnings will be logged if any error is encountered will scanning for hooks,
# but it will not abort container execution.
#guest_hook_path = "/usr/share/oci/hooks"

[factory]
# VM templating support. Once enabled, new VMs are created from template
# using vm cloning. They will share the same initial kernel, initramfs and
# agent memory by mapping it readonly. It helps speeding up new container
# creation and saves a lot of memory if there are many kata containers running
# on the same host.
#
# When disabled, new VMs are created from scratch.
#
# Note: Requires "initrd=" to be set ("image=" is not supported).
#
# 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

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

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

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

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

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

[runtime]
# If enabled, the runtime will log additional debug messages to the
# system log
# (default: disabled)
enable_debug = true
#
# Internetworking model
# Determines how the VM should be connected to the
# the container network interface
# Options:
#
#   - bridged
#     Uses a linux bridge to interconnect the container interface to
#     the VM. Works for most cases except macvlan and ipvlan.
#
#   - macvtap
#     Used when the Container network interface can be bridged using
#     macvtap.
#
#   - none
#     Used when customize network. Only creates a tap device. No veth pair.
#
#   - tcfilter
#     Uses tc filter rules to redirect traffic from the network interface
#     provided by plugin to a tap interface connected to the VM.
#
internetworking_model="macvtap"

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

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

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

KSM throttler

version

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

kata-ksm-throttler version 1.5.0-rc2-d70af5c

systemd service

Output of "systemctl show kata-ksm-throttler":

Type=simple
Restart=always
NotifyAccess=none
RestartUSec=100ms
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=0
WatchdogTimestamp=Tue 2019-01-15 16:26:52 UTC
WatchdogTimestampMonotonic=86715517911
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=99108
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=4294967295
GID=4294967295
ExecMainStartTimestamp=Tue 2019-01-15 16:26:52 UTC
ExecMainStartTimestampMonotonic=86715517874
ExecMainExitTimestampMonotonic=0
ExecMainPID=99108
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/usr/libexec/kata-ksm-throttler/kata-ksm-throttler ; argv[]=/usr/libexec/kata-ksm-throttler/kata-ksm-throttler -log debug ; ignore_errors=no ; start_time=[Tue 2019-01-15 16:26:52 UTC] ; stop_time=[n/a] ; pid=99108 ; code=(null) ; status=0/0 }
Slice=system.slice
ControlGroup=/system.slice/kata-ksm-throttler.service
MemoryCurrent=1466368
CPUUsageNSec=46762937
TasksCurrent=7
Delegate=no
CPUAccounting=no
CPUWeight=18446744073709551615
StartupCPUWeight=18446744073709551615
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=18446744073709551615
StartupIOWeight=18446744073709551615
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLow=0
MemoryHigh=18446744073709551615
MemoryMax=18446744073709551615
MemorySwapMax=18446744073709551615
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=yes
TasksMax=19660
UMask=0022
LimitCPU=18446744073709551615
LimitCPUSoft=18446744073709551615
LimitFSIZE=18446744073709551615
LimitFSIZESoft=18446744073709551615
LimitDATA=18446744073709551615
LimitDATASoft=18446744073709551615
LimitSTACK=18446744073709551615
LimitSTACKSoft=8388608
LimitCORE=18446744073709551615
LimitCORESoft=0
LimitRSS=18446744073709551615
LimitRSSSoft=18446744073709551615
LimitNOFILE=4096
LimitNOFILESoft=1024
LimitAS=18446744073709551615
LimitASSoft=18446744073709551615
LimitNPROC=31792
LimitNPROCSoft=31792
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=18446744073709551615
LimitLOCKSSoft=18446744073709551615
LimitSIGPENDING=31792
LimitSIGPENDINGSoft=31792
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
DynamicUser=no
RemoveIPC=no
MountFlags=0
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictNamespace=2114060288
KillMode=control-group
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=kata-ksm-throttler.service
Names=kata-ksm-throttler.service
Requires=sysinit.target system.slice
Conflicts=shutdown.target
Before=shutdown.target
After=systemd-journald.socket sysinit.target basic.target system.slice
Documentation=https://github.com/kata-containers/ksm-throttler
Description=KSM throttling daemon
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/kata-ksm-throttler.service
UnitFileState=disabled
UnitFilePreset=enabled
StateChangeTimestamp=Tue 2019-01-15 16:26:52 UTC
StateChangeTimestampMonotonic=86715517930
InactiveExitTimestamp=Tue 2019-01-15 16:26:52 UTC
InactiveExitTimestampMonotonic=86715517930
ActiveEnterTimestamp=Tue 2019-01-15 16:26:52 UTC
ActiveEnterTimestampMonotonic=86715517930
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=yes
AssertResult=yes
ConditionTimestamp=Tue 2019-01-15 16:26:52 UTC
ConditionTimestampMonotonic=86715516482
AssertTimestamp=Tue 2019-01-15 16:26:52 UTC
AssertTimestampMonotonic=86715516483
Transient=no
Perpetual=no
StartLimitIntervalSec=10000000
StartLimitBurst=5
StartLimitAction=none
InvocationID=5fddfa211b064af18fa1c6afc8e5ea58

Image details

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

agent:
  url: "https://github.com/kata-containers/agent"
  name: "kata-agent"
  version: "1.5.0-rc2-91a87bc7176750eee2f032aa564e8b28f4ad0e73"
  agent-is-init-daemon: "no"

Initrd details

No initrd


Logfiles

Runtime logs

Recent runtime problems found in system journal:

time="2019-01-15T16:22:12.539095481Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 error="open /run/vc/sbs/49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69/devices.json: no such file or directory" name=kata-runtime pid=98269 sandbox=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 sandboxid=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:22:12.573143822Z" level=debug arch=amd64 command=create container=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 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=98269 source=virtcontainers subsystem=qemu
time="2019-01-15T16:23:59.068007079Z" level=error msg="container 49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 is not running" arch=amd64 command=kata-network container=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 name=kata-runtime pid=98526 sandbox=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 source=runtime
time="2019-01-15T16:24:31.512131394Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b name=kata-runtime pid=98663 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:24:31.515963521Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b error="open /run/vc/sbs/b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b/devices.json: no such file or directory" name=kata-runtime pid=98663 sandbox=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b sandboxid=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b source=virtcontainers subsystem=sandbox
time="2019-01-15T16:24:31.541817803Z" level=debug arch=amd64 command=create container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b 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=98663 source=virtcontainers subsystem=qemu
time="2019-01-15T16:25:54.115044808Z" level=error msg="container b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b is not running" arch=amd64 command=kata-network container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b name=kata-runtime pid=98884 sandbox=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b source=runtime
time="2019-01-15T16:29:06.351369724Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0 name=kata-runtime pid=99937 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:29:06.355418452Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0 error="open /run/vc/sbs/0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0/devices.json: no such file or directory" name=kata-runtime pid=99937 sandbox=0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0 sandboxid=0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:29:06.381174733Z" level=debug arch=amd64 command=create container=0dce1dd93eb708b9a16f45464cc68c829ffa1b7afb5f3dce5f2e429852a1b7c0 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=99937 source=virtcontainers subsystem=qemu
time="2019-01-15T16:29:34.149926117Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf name=kata-runtime pid=100195 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:29:34.155837058Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf error="open /run/vc/sbs/68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf/devices.json: no such file or directory" name=kata-runtime pid=100195 sandbox=68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf sandboxid=68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf source=virtcontainers subsystem=sandbox
time="2019-01-15T16:29:34.205301105Z" level=debug arch=amd64 command=create container=68d4894512edb72fc5701b56f349323d910f5a65f1c405c2993658189b2aa8cf 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=100195 source=virtcontainers subsystem=qemu
time="2019-01-15T16:29:44.362479433Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6 name=kata-runtime pid=100435 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:29:44.365984457Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6 error="open /run/vc/sbs/b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6/devices.json: no such file or directory" name=kata-runtime pid=100435 sandbox=b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6 sandboxid=b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:29:44.399832694Z" level=debug arch=amd64 command=create container=b2345b83ff4fedc0fcf1c5fcfa62900053ac6740ed11d6753aadb9b62a867fe6 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=100435 source=virtcontainers subsystem=qemu
time="2019-01-15T16:30:30.194081402Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7 name=kata-runtime pid=100723 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:30:30.200102045Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7 error="open /run/vc/sbs/47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7/devices.json: no such file or directory" name=kata-runtime pid=100723 sandbox=47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7 sandboxid=47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:30:30.227667238Z" level=debug arch=amd64 command=create container=47fc3fb534d8bafece706f4c9c4fd7a4d95f8b6316f08cc9f007058a07f874a7 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=100723 source=virtcontainers subsystem=qemu
time="2019-01-15T16:31:05.254599238Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b name=kata-runtime pid=100977 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:31:05.257579759Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b error="open /run/vc/sbs/42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b/devices.json: no such file or directory" name=kata-runtime pid=100977 sandbox=42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b sandboxid=42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b source=virtcontainers subsystem=sandbox
time="2019-01-15T16:31:05.295056421Z" level=debug arch=amd64 command=create container=42ab47d578dafc4cef0d341db87d739175950c15e35110f1c2508715175d1f4b 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=100977 source=virtcontainers subsystem=qemu
time="2019-01-15T16:31:40.083785147Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac name=kata-runtime pid=101265 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:31:40.087732274Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac error="open /run/vc/sbs/fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac/devices.json: no such file or directory" name=kata-runtime pid=101265 sandbox=fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac sandboxid=fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac source=virtcontainers subsystem=sandbox
time="2019-01-15T16:31:40.114349661Z" level=debug arch=amd64 command=create container=fdad286cee631c2e114f30fd81a1e58bb3a8cf5540c51eebc3d66aaf8632d1ac 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=101265 source=virtcontainers subsystem=qemu
time="2019-01-15T16:32:10.276117503Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57 name=kata-runtime pid=101514 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:32:10.28132574Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57 error="open /run/vc/sbs/690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57/devices.json: no such file or directory" name=kata-runtime pid=101514 sandbox=690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57 sandboxid=690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:32:10.307546723Z" level=debug arch=amd64 command=create container=690ebd601320a64747829c55438c918f1e1ae91263271a7c8b2c89e37d3e3c57 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=101514 source=virtcontainers subsystem=qemu
time="2019-01-15T16:32:39.335526665Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691 name=kata-runtime pid=101774 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:32:39.343206918Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691 error="open /run/vc/sbs/f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691/devices.json: no such file or directory" name=kata-runtime pid=101774 sandbox=f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691 sandboxid=f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:32:39.394240575Z" level=debug arch=amd64 command=create container=f8995a60d486fbaf973deb84e01f158bbba39c59d37a26be780c1e9893fa8691 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=101774 source=virtcontainers subsystem=qemu
time="2019-01-15T16:33:11.186758094Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2 name=kata-runtime pid=102041 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:33:11.192677035Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2 error="open /run/vc/sbs/1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2/devices.json: no such file or directory" name=kata-runtime pid=102041 sandbox=1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2 sandboxid=1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:33:11.226522772Z" level=debug arch=amd64 command=create container=1780030b0c3b4255f22057713b5f9f2eb2d40248661732e5a46738d9014253a2 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=102041 source=virtcontainers subsystem=qemu
time="2019-01-15T16:33:42.090329118Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1 name=kata-runtime pid=102306 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:33:42.095459211Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1 error="open /run/vc/sbs/cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1/devices.json: no such file or directory" name=kata-runtime pid=102306 sandbox=cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1 sandboxid=cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:33:42.121764477Z" level=debug arch=amd64 command=create container=cd35a7567017e06bc8d5ad89e872ee0e05b41132aad157fda8e7e4e144d5bfb1 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=102306 source=virtcontainers subsystem=qemu
time="2019-01-15T16:34:14.812839549Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2 name=kata-runtime pid=102577 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:34:14.817777545Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2 error="open /run/vc/sbs/ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2/devices.json: no such file or directory" name=kata-runtime pid=102577 sandbox=ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2 sandboxid=ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:34:14.843806122Z" level=debug arch=amd64 command=create container=ceeadbb05348209ac9344bf60c375d766e05d35e9aca51827a0cb15fd93d4fb2 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=102577 source=virtcontainers subsystem=qemu
time="2019-01-15T16:34:51.487693938Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d name=kata-runtime pid=102850 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:34:51.494095935Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d error="open /run/vc/sbs/775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d/devices.json: no such file or directory" name=kata-runtime pid=102850 sandbox=775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d sandboxid=775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d source=virtcontainers subsystem=sandbox
time="2019-01-15T16:34:51.741197829Z" level=debug arch=amd64 command=create container=775f20dfe80608dd8f5370e6b9944d4517002bfae749d3bd3e2a739f3e183d7d 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=102850 source=virtcontainers subsystem=qemu
time="2019-01-15T16:35:26.227881048Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 name=kata-runtime pid=103113 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:35:26.234338248Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 error="open /run/vc/sbs/18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120/devices.json: no such file or directory" name=kata-runtime pid=103113 sandbox=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 sandboxid=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:35:26.266564947Z" level=debug arch=amd64 command=create container=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 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=103113 source=virtcontainers subsystem=qemu
time="2019-01-15T16:36:06.435139711Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 name=kata-runtime pid=103396 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:36:06.439823713Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 error="open /run/vc/sbs/c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2/devices.json: no such file or directory" name=kata-runtime pid=103396 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 sandboxid=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:36:06.473246026Z" level=debug arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 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=103396 source=virtcontainers subsystem=qemu
time="2019-01-15T16:36:33.920014773Z" level=error msg="Failed to check if grpc server is working: rpc error: code = Unavailable desc = transport is closing" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 name=kata-runtime pid=103396 source=runtime

Proxy logs

Recent proxy problems found in system journal:

time="2019-01-15T16:36:13.866000622Z" level=info msg="[    5.798178] systemd[70]: Failed to add rule for system call socketcall() / -10060, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.869139524Z" level=info msg="[    5.801215] systemd[79]: Failed to add rule for system call oldolduname() / -10036, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.872253925Z" level=info msg="[    5.804449] systemd[70]: Failed to add rule for system call pciconfig_iobase() / -10086, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.876190627Z" level=info msg="[    5.808222] systemd[79]: Failed to add rule for system call getresgid32() / -10019, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.880927029Z" level=info msg="[    5.813212] systemd[70]: Failed to add rule for system call fcntl64() / -10009, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.884039331Z" level=info msg="[    5.816156] systemd[79]: Failed to add rule for system call get_thread_area() / 211, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.887971032Z" level=info msg="[    5.820222] systemd[70]: Failed to add rule for system call mmap2() / -10029, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.891981834Z" level=info msg="[    5.824187] systemd[79]: Failed to add rule for system call sigaction() / -10054, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.894730236Z" level=info msg="[    5.826927] systemd[70]: Failed to add rule for system call epoll_wait_old() / 215, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.896989137Z" level=info msg="[    5.829466] systemd[79]: Failed to add rule for system call waitpid() / -10073, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.899185538Z" level=info msg="[    5.831665] systemd[70]: Failed to add rule for system call sigreturn() / -10058, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.900389438Z" level=info msg="[    5.833659] systemd[79]: Failed to add rule for system call truncate64() / -10066, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.901430939Z" level=info msg="[    5.834805] systemd[70]: Failed to add rule for system call getgid32() / -10017, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:13.902926939Z" level=info msg="[    5.835893] systemd[79]: Failed to add rule for system call setuid32() / -10052, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.978854801Z" level=info msg="[    5.837617] systemd[70]: Failed to add rule for system call s390_pci_mmio_read() / -10197, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.978947201Z" level=info msg="[    5.839709] systemd[79]: Failed to add rule for system call fstat64() / -10010, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.978982301Z" level=info msg="[    5.841325] systemd[70]: Failed to add rule for system call setgid32() / -10046, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979044401Z" level=info msg="[    5.842939] systemd[79]: Failed to add rule for system call fadvise64_64() / -10007, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979102001Z" level=info msg="[    5.844704] systemd[70]: Failed to add rule for system call geteuid32() / -10016, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979134801Z" level=info msg="[    5.846465] systemd[79]: Failed to add rule for system call getgroups32() / -10018, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979173401Z" level=info msg="[    5.848195] systemd[70]: Failed to add rule for system call olduname() / -10038, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979224101Z" level=info msg="[    5.849978] systemd[79]: Failed to add rule for system call send() / -109, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979249901Z" level=info msg="[    5.851866] systemd[70]: Failed to add rule for system call setgroups32() / -10047, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979310601Z" level=info msg="[    5.853514] systemd[79]: Failed to add rule for system call epoll_wait_old() / 215, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979369001Z" level=info msg="[    5.855312] systemd[70]: Failed to add rule for system call signal() / -10055, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979417701Z" level=info msg="[    5.856852] systemd[79]: Failed to add rule for system call setgroups32() / -10047, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979467501Z" level=info msg="[    5.858570] systemd[70]: Failed to add rule for system call getresgid32() / -10019, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979496301Z" level=info msg="[    5.860474] systemd[79]: Failed to add rule for system call _newselect() / -10032, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979510601Z" level=info msg="[    5.862185] systemd[70]: Failed to add rule for system call setresgid32() / -10049, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979557501Z" level=info msg="[    5.864118] systemd[79]: Failed to add rule for system call readdir() / -10041, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979614101Z" level=info msg="[    5.865730] systemd[70]: Failed to add rule for system call recv() / -110, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979667801Z" level=info msg="[    5.867408] systemd[79]: Failed to add rule for system call setresuid32() / -10050, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979700601Z" level=info msg="[    5.868418] systemd[70]: Failed to add rule for system call setresuid32() / -10050, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979719201Z" level=info msg="[    5.869293] systemd[79]: Failed to add rule for system call setreuid32() / -10051, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979875701Z" level=info msg="[    5.870189] systemd[70]: Failed to add rule for system call truncate64() / -10066, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979899901Z" level=info msg="[    5.872403] systemd[79]: Failed to add rule for system call fstatat64() / -10011, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979954301Z" level=info msg="[    5.874259] systemd[70]: Failed to add rule for system call fchown32() / -10008, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.979997001Z" level=info msg="[    5.876139] systemd[79]: Failed to add rule for system call lchown32() / -10025, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980062701Z" level=info msg="[    5.878351] systemd[70]: Failed to add rule for system call lstat64() / -10028, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980086301Z" level=info msg="[    5.879208] systemd[79]: Failed to add rule for system call sigreturn() / -10058, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980136001Z" level=info msg="[    5.880210] systemd[70]: Failed to add rule for system call _newselect() / -10032, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980155201Z" level=info msg="[    5.882787] systemd[70]: Failed to add rule for system call sendfile64() / -10043, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980206601Z" level=info msg="[    5.884664] systemd[79]: Failed to add rule for system call ugetrlimit() / -10068, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980241901Z" level=info msg="[    5.886359] systemd[70]: Failed to add rule for system call _llseek() / -10026, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980289701Z" level=info msg="[    5.887869] systemd[79]: Failed to add rule for system call setgid32() / -10046, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:23.980332301Z" level=info msg="[    5.889600] systemd[70]: Failed to add rule for system call pciconfig_read() / -10087, ignoring: Numerical argument out of domain\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:25.443633451Z" level=info msg="[    5.891535] systemd[79]: Fail\r\x1b[K[    \x1b[0;31m*\x1b[0;1;31m*\x1b[0m] A start job is running for Journal Service (11s / 1min 30s)\r\x1b[K[     \x1b[0;31m*\x1b[0m] A start job is running for Journal Service (12s / 1min 30s)\r\x1b[K[    \x1b[0;31m*\x1b[0;1;31m*\x1b[0m] A start job is running for Journal Service (12s / 1min 30s)[   17.376411] systemd-udevd[90]: passed device to netlink monitor 0x559779c43c20\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:25.967155458Z" level=info msg="\r\x1b[K[   \x1b[0;31m*\x1b[0;1;31m*\x1b[0m\x1b[0;31m*\x1b[0m] A start job is running for Journal Service (13s / 1min 30s)[   17.899202] systemd-journald[79]: Failed to open configuration file '/etc/systemd/journald.conf': No such file or directory\n" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=agent
time="2019-01-15T16:36:26.705621099Z" level=fatal msg="failed to handle exit signal" error="close unix @->/run/vc/vm/c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2/kata.sock: use of closed network connection" name=kata-proxy pid=103438 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=proxy
time="2019-01-15T16:37:37.806035251Z" level=info msg="[    4.098476] systemd[71]: Failed to add rule for system call setgroups32() / -10047, ignoring: Numerical argum[  129.312578] systemd-journald[79]: Sent WATCHDOG=1 notification.\n" name=kata-proxy pid=103157 sandbox=18a01badbb116f7f0d7ea27a2be92653d5b253cc377edd10a7eeb3d710e4b120 source=agent

Shim logs

Recent shim problems found in system journal:

time="2019-01-15T16:23:57.29816378Z" level=info msg="copy stderr failed" container=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 error="rpc error: code = Unknown desc = EOF" exec-id=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 name=kata-shim pid=1 source=shim
time="2019-01-15T16:23:57.298370082Z" level=info msg="copy stdout failed" container=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 error="rpc error: code = Unknown desc = EOF" exec-id=49d994ffbce60e64aa897cc8150b9303add2a83d94ae4f8721eb2d345ef7df69 name=kata-shim pid=1 source=shim
time="2019-01-15T16:25:52.900707157Z" level=info msg="copy stdout failed" container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b error="rpc error: code = Unknown desc = EOF" exec-id=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b name=kata-shim pid=1 source=shim
time="2019-01-15T16:25:52.913695348Z" level=info msg="copy stderr failed" container=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b error="rpc error: code = Unknown desc = EOF" exec-id=b95b530300da3c15dda3809d2c9dafeebb22e958a93545fc25173c907669141b 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:23:18 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:22:21 2018
  OS/Arch:          linux/amd64
  Experimental:     false

Output of "docker info":

Containers: 14
 Running: 13
 Paused: 0
 Stopped: 1
Images: 2
Server Version: 18.06.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: kata-runtime runc
Default Runtime: kata-runtime
Init Binary: docker-init
containerd version: 468a545b9edcd5932818eb9de8e72413e616e86e
runc version: 4fda4933845d2f8590d65420e8036e494d6f7a0b (expected: 69663f0bd4b60df09991c08812a60108003fa340)
init version: fec3683
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.9.0-8-amd64
Operating System: Debian GNU/Linux 9 (stretch)
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 7.783GiB
Name: gabydebqemu
ID: GFTU:ZROM:EZU7:YY2D:YJUG:YOMT:XYW6:6GGR:XZVX:LVQX:M6IM:GXHT
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 101
 Goroutines: 96
 System Time: 2019-01-15T16:46:59.637392538Z
 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=Mon 2019-01-14 17:20:33 UTC
WatchdogTimestampMonotonic=3536785467
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=111590
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusErrno=0
Result=success
UID=4294967295
GID=4294967295
ExecMainStartTimestamp=Mon 2019-01-14 17:20:22 UTC
ExecMainStartTimestampMonotonic=3526278900
ExecMainExitTimestampMonotonic=0
ExecMainPID=111590
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=2154491904
CPUUsageNSec=445325733037
TasksCurrent=552
Delegate=yes
CPUAccounting=no
CPUWeight=18446744073709551615
StartupCPUWeight=18446744073709551615
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=18446744073709551615
StartupIOWeight=18446744073709551615
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLow=0
MemoryHigh=18446744073709551615
MemoryMax=18446744073709551615
MemorySwapMax=18446744073709551615
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=yes
TasksMax=18446744073709551615
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=31792
LimitSIGPENDINGSoft=31792
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
DynamicUser=no
RemoveIPC=no
MountFlags=0
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
MemoryDenyWriteExecute=no
RestrictRealtime=no
RestrictNamespace=2114060288
KillMode=process
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=docker.service
Names=docker.service
Requires=sysinit.target system.slice docker.socket
Wants=network-online.target
WantedBy=multi-user.target
ConsistsOf=docker.socket
Conflicts=shutdown.target
Before=multi-user.target shutdown.target
After=basic.target firewalld.service sysinit.target network-online.target system.slice systemd-journald.socket docker.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=Mon 2019-01-14 17:20:33 UTC
StateChangeTimestampMonotonic=3536785470
InactiveExitTimestamp=Mon 2019-01-14 17:20:22 UTC
InactiveExitTimestampMonotonic=3526278947
ActiveEnterTimestamp=Mon 2019-01-14 17:20:33 UTC
ActiveEnterTimestampMonotonic=3536785470
ActiveExitTimestamp=Mon 2019-01-14 17:20:20 UTC
ActiveExitTimestampMonotonic=3523673223
InactiveEnterTimestamp=Mon 2019-01-14 17:20:21 UTC
InactiveEnterTimestampMonotonic=3524679959
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=Mon 2019-01-14 17:20:22 UTC
ConditionTimestampMonotonic=3526277570
AssertTimestamp=Mon 2019-01-14 17:20:22 UTC
AssertTimestampMonotonic=3526277571
Transient=no
Perpetual=no
StartLimitIntervalSec=60000000
StartLimitBurst=3
StartLimitAction=none
InvocationID=0e64c239ab8a4452a0b3c5e6a41d0068

No kubectl


Packages

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

ii  kata-containers-image            1.5.0~rc2-14                   amd64        Kata containers image
ii  kata-ksm-throttler               1.5.0~rc2.git+d70af5c-16       amd64

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

grahamwhaley commented 5 years ago

@GabyCT - if you can re-create (which it feels like), are you able to enable the kata debug in the config and then check the logs for the relevant container ID, and see if any reason pops out why one seems to be 'stuck'? @sboeuf - any thoughts - seen this before? (does not ring a bell with me). Anybody got any smart ideas about what might cause this? Seems odd that it is Debian specific, but so it seems....

GabyCT commented 5 years ago

@grahamwhaley ,this is the error for the specific container ID

time="2019-01-15T16:36:06.435139711Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 name=kata-runtime pid=103396 source=virtcontainers subsystem=kata_agent
time="2019-01-15T16:36:06.439823713Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 error="open /run/vc/sbs/c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2/devices.json: no such file or directory" name=kata-runtime pid=103396 sandbox=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 sandboxid=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 source=virtcontainers subsystem=sandbox
time="2019-01-15T16:36:06.473246026Z" level=debug arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 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=103396 source=virtcontainers subsystem=qemu
time="2019-01-15T16:36:33.920014773Z" level=error msg="Failed to check if grpc server is working: rpc error: code = Unavailable desc = transport is closing" arch=amd64 command=create container=c9e24c2ab817fefc4a433576fbb9ddf80a734837bd90a25a611fb5eff724c2e2 name=kata-runtime pid=103396 source=runtime
grahamwhaley commented 5 years ago

Ooh. Here is a question (that might be answered in the above system capture btw) - what back end graph storage driver is the Debian using - maybe that is making the difference? Could be the version of the driver as well (could be old?)

GabyCT commented 5 years ago

@grahamwhaley , it is using overlay2 and here it is the info

$modinfo overlay
filename:       /lib/modules/4.9.0-8-amd64/kernel/fs/overlayfs/overlay.ko
alias:          fs-overlay
license:        GPL
description:    Overlay filesystem
author:         Miklos Szeredi <miklos@szeredi.hu>
depends:
retpoline:      Y
intree:         Y
vermagic:       4.9.0-8-amd64 SMP mod_unload modversions
parm:           check_copy_up:bool
parm:           ovl_check_copy_up:Warn on copy-up when causing process also has a R/O fd open
jodh-intel commented 5 years ago

Is this still an issue @GabyCT?

GabyCT commented 5 years ago

@jodh-intel yes it is.

GabyCT commented 5 years ago

@jodh-intel , actually it is also present in other tests like the oci_call_test.sh. While doing this, we have the following error

$ docker run --rm --runtime=kata-runtime busybox true
docker: Error response from daemon: OCI runtime start failed: rpc error: code = Unavailable desc = transport is closing: unknown.

The same error like the soak test.

GabyCT commented 5 years ago

Looking the kata-runtime log, it seems that the same error is happening like the soak test

time="2019-01-31T19:04:24.88422483Z" level=debug msg="Could not retrieve anything from storage" arch=amd64 command=create container=db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2 name=kata-runtime pid=125811 source=virtcontainers subsystem=kata_agent
time="2019-01-31T19:04:24.886903537Z" level=warning msg="fetch sandbox device failed" arch=amd64 command=create container=db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2 error="open /run/vc/sbs/db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2/devices.json: no such file or directory" name=kata-runtime pid=125811 sandbox=db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2 sandboxid=db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2 source=virtcontainers subsystem=sandbox
time="2019-01-31T19:04:24.927344137Z" level=debug arch=amd64 command=create container=db72deb897d7fbd60cecde518ef4a79a36d918e08e055a44825ea626fdfa39a2 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=125811 source=virtcontainers subsystem=qemu

Shim log

time="2019-01-31T18:36:18.277179196Z" level=info msg="copy stdout failed" container=249e847d8d3bc3bb4c46e5e3ad30b46be580d1f4ffa030e4d97a9b833a8a71a5 error="rpc error: code = Unknown desc = EOF" exec-id=249e847d8d3bc3bb4c46e5e3ad30b46be580d1f4ffa030e4d97a9b833a8a71a5 name=kata-shim pid=1 source=shim
time="2019-01-31T18:36:18.292804355Z" level=info msg="copy stderr failed" container=249e847d8d3bc3bb4c46e5e3ad30b46be580d1f4ffa030e4d97a9b833a8a71a5 error="rpc error: code = Unknown desc = EOF" exec-id=249e847d8d3bc3bb4c46e5e3ad30b46be580d1f4ffa030e4d97a9b833a8a71a5 name=kata-shim pid=1 source=shim
devimc commented 5 years ago

might be the problem is the number of "physical" cpu

Output of "docker info":

...
Architecture: x86_64
CPUs: 2
...

can you try with 4 CPUs?

devimc commented 5 years ago

great, now I can reproduce this issue in all distros with 2 cpus

[Fail] Update CPU constraints Update CPU set [It] cpuset should be equal to 0 
/home/x/go/src/github.com/kata-containers/tests/integration/docker/cpu_test.go:376

[Fail] Update CPU constraints Update CPU set [It] cpuset should be equal to 2 
/home/x/go/src/github.com/kata-containers/tests/integration/docker/cpu_test.go:376

[Fail] Update CPU constraints Update CPU set [It] cpuset should be equal to 0-1 
/home/x/go/src/github.com/kata-containers/tests/integration/docker/cpu_test.go:376

[Fail] Update CPU constraints Update CPU set [It] cpuset should be equal to 0-2 
/home/x/go/src/github.com/kata-containers/tests/integration/docker/cpu_test.go:376
devimc commented 5 years ago

@GabyCT can we close this?

GabyCT commented 5 years ago

@devimc this is the error that I am getting

And we are out of memory on container 85 (2041942016 < (2*1024*1024*1024))
Checking 85 containers have all relevant components
devimc commented 5 years ago

@GabyCT thanks, @grahamwhaley is working on density stuff, may be he knows why it is failing

grahamwhaley commented 5 years ago

This isn't a density test - I think this is from the 'soak rm stability test': https://github.com/kata-containers/tests/blob/master/integration/stability/soak_parallel_rm.sh#L40, where we launch (by default) 110 containers, kill them all off, and check there are no 'fragments' left hanging around in the system that should not be (like proxies, sandbox files, mounts etc.). We do that 5 times...

It looks like Debian run failed to launch all 110 containers, which is probably either:

devimc commented 5 years ago

@grahamwhaley thanks, @GabyCT can you confirm if debian CI has enough RAM?

GabyCT commented 4 years ago

Closing this issue as the CI is running debian 10