runtime icon indicating copy to clipboard operation
runtime copied to clipboard

Published 20 hours ago • verified publisher icon clearcontainers

unable to start a container using --device option

Open devimc opened this issue 8 years ago • 6 comments

Description of problem

unable to start a container when --device option is provided

Expected result

$ docker run --device /dev/loop0p1 -ti debian bash
root@21a6d3069b10:/#

Actual result

$ docker run --device /dev/loop0p1 -ti debian bash
docker: Error response from daemon: exit status 1: "ERROR received from VM agent\n"

Meta details

Running cc-collect-data.sh version 3.0.6 (commit 549ba28) at 2017-11-05.20:42:43.764534281.

Runtime is /usr/bin/cc-runtime.

cc-env

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

[Meta]
  Version = "1.0.5"

[Runtime]
  [Runtime.Version]
    Semver = "3.0.6"
    Commit = "549ba28"
    OCI = "1.0.0-dev"
  [Runtime.Config]
    Path = "/usr/share/defaults/clear-containers/configuration.toml"
    GlobalLogPath = ""

[Hypervisor]
  MachineType = "pc"
  Version = "QEMU emulator version 2.7.1(2.7.1+git.d4a337fe91-9.1.cc), Copyright (c) 2003-2016 Fabrice Bellard and the QEMU Project developers"
  Path = "/usr/bin/qemu-lite-system-x86_64"

[Image]
  Path = "/usr/share/clear-containers/clear-18770-containers.img"

[Kernel]
  Path = "/usr/share/clear-containers/vmlinuz-4.9.58-79.1.container"
  Parameters = ""

[Proxy]
  Type = "ccProxy"
  Version = "Version: 3.0.6+git.3020872"
  URL = "unix:///var/run/clear-containers/proxy.sock"

[Shim]
  Type = "ccShim"
  Version = "shim version: 3.0.6 (commit: 11b5eef)"
  Path = "/usr/libexec/clear-containers/cc-shim"

[Agent]
  Type = "hyperstart"
  Version = "<<unknown>>"

[Host]
  Kernel = "4.13.10-100.fc25.x86_64"
  CCCapable = true
  [Host.Distro]
    Name = "Fedora"
    Version = "25"
  [Host.CPU]
    Vendor = "GenuineIntel"
    Model = "Intel(R) Core(TM) i7-4700MQ CPU @ 2.40GHz"

Runtime config files

Runtime default config files

/usr/share/defaults/clear-containers/configuration.toml
/usr/share/defaults/clear-containers/configuration.toml

Runtime config file contents

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

# XXX: Warning: this file is auto-generated from file "config/configuration.toml.in".

[hypervisor.qemu]
path = "/usr/bin/qemu-lite-system-x86_64"
kernel = "/usr/share/clear-containers/vmlinuz.container"
image = "/usr/share/clear-containers/clear-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
kernel_params = ""

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

# Default memory size in MiB for POD/VM.
# If unspecified then it will be set 2048 MiB.
#default_memory = 2048
disable_block_device_use = 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

# Debug changes the default hypervisor and kernel parameters to
# enable debug output where available.
# Default false
# these logs can be obtained in the cc-proxy logs  when the 
# proxy is set to run in debug mode
# /usr/libexec/clear-containers/cc-proxy -log debug
# or by stopping the cc-proxy service and running the cc-proxy 
# explicitly using the same command line
# 
#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

[proxy.cc]
url = "unix:///var/run/clear-containers/proxy.sock"

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

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

[agent.hyperstart]
pause_root_path = "@PAUSEROOTPATH@"

[runtime]
## Uncomment to enable the global logging to the default path.
#global_log_path = "/var/lib/clear-containers/runtime/runtime.log"

# If enabled, the runtime will log additional debug messages to the global
# log, assuming that is also enabled.
# (default: disabled)
#enable_debug = true

Logfiles

Runtime logs

Global log not enabled.

Proxy logs

Recent proxy problems found in system journal:

time="2017-11-03T19:01:27.283856178-06:00" level=debug msg="{\\\"channel\\\":\\\"ctl\\\",\\\"command\\\":\\\"newcontainer\\\",\\\"error\\\":\\\"Process could not be started: container_linux.go:295: starting container process caused \\\\\\\"process_linux.go:399: container init caused \\\\\\\\\\\\\\\"rootfs_linux.go:58: mounting \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/shareDir/dev/vdb\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" to rootfs \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/hyper/f5eb24a9cc74876315e77bb637784308dea338c87fc0523f0a6db0067bb3f3df/root/rootfs\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" at \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/dev/loop0\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" caused \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"stat /tmp/shareDir/dev/vdb: no such file or directory\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"\\\\\\\\\\\\\\\"\\\\\\\"\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"command failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":200,\\\"time\\\":\\\"2017-11-04T01:01:27.262945661Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=f5eb24a9cc74876315e77bb637784308dea338c87fc0523f0a6db0067bb3f3df
time="2017-11-03T19:01:57.320227274-06:00" level=error msg="timeout waiting for process with token cVvFgWrCL9IwA_ijKAb_FTGV3orBzaqukhlSF2QQoao=" name=cc-proxy pid=28725 section=io source=proxy vm=f5eb24a9cc74876315e77bb637784308dea338c87fc0523f0a6db0067bb3f3df
time="2017-11-03T19:01:57.320341066-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=86 name=cc-proxy pid=28725 source=proxy
time="2017-11-03T19:02:57.681337716-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":196,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-04T01:02:57.66234008Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=e55ee3aebd6f995872c5e3f5d1bf21f58c189b83492a5d80233aa3a466c129b4
time="2017-11-03T19:02:57.68223615-06:00" level=debug msg="{\\\"container\\\":\\\"e55ee3aebd6f995872c5e3f5d1bf21f58c189b83492a5d80233aa3a466c129b4\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":196,\\\"time\\\":\\\"2017-11-04T01:02:57.663095842Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=e55ee3aebd6f995872c5e3f5d1bf21f58c189b83492a5d80233aa3a466c129b4
time="2017-11-03T19:02:57.682259264-06:00" level=debug msg="{\\\"container\\\":\\\"e55ee3aebd6f995872c5e3f5d1bf21f58c189b83492a5d80233aa3a466c129b4\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":196,\\\"time\\\":\\\"2017-11-04T01:02:57.663173081Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=e55ee3aebd6f995872c5e3f5d1bf21f58c189b83492a5d80233aa3a466c129b4
time="2017-11-03T19:02:57.682311309-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=92 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:33:38.577179081-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:33:38.561482805Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=f1de2f03cd213e8ab6a0045b7170a1ae56696421570c8aa49f7fe43afaf111a8
time="2017-11-05T20:33:38.577542616-06:00" level=debug msg="{\\\"container\\\":\\\"f1de2f03cd213e8ab6a0045b7170a1ae56696421570c8aa49f7fe43afaf111a8\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"time\\\":\\\"2017-11-06T02:33:38.561886211Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=f1de2f03cd213e8ab6a0045b7170a1ae56696421570c8aa49f7fe43afaf111a8
time="2017-11-05T20:33:38.577594793-06:00" level=debug msg="{\\\"container\\\":\\\"f1de2f03cd213e8ab6a0045b7170a1ae56696421570c8aa49f7fe43afaf111a8\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"time\\\":\\\"2017-11-06T02:33:38.561955134Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=f1de2f03cd213e8ab6a0045b7170a1ae56696421570c8aa49f7fe43afaf111a8
time="2017-11-05T20:33:38.577650407-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=99 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:34:06.249889174-06:00" level=debug msg="{\\\"data\\\":\\\"ls: /dev/loop: No such file or directory\\\\r\\\\n\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Read from sequence\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:34:06.218950599Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc
time="2017-11-05T20:34:09.227363456-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:34:09.196387714Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc
time="2017-11-05T20:34:09.227572376-06:00" level=debug msg="{\\\"container-pid\\\":\\\"3\\\",\\\"error\\\":\\\"exit status 130\\\",\\\"level\\\":\\\"error\\\",\\\"msg\\\":\\\"Process wait failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"time\\\":\\\"2017-11-06T02:34:09.196613485Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc
time="2017-11-05T20:34:09.227982676-06:00" level=debug msg="{\\\"container\\\":\\\"39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"time\\\":\\\"2017-11-06T02:34:09.19702904Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc
time="2017-11-05T20:34:09.228112317-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=106 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:34:09.22814969-06:00" level=debug msg="{\\\"container\\\":\\\"39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"time\\\":\\\"2017-11-06T02:34:09.197153623Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=39ac640e14505f6f132c063b90b20b0b0dd834ae26ce39f417f6c34d8f3625fc
time="2017-11-05T20:35:32.0916981-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":200,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:35:32.077525031Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa
time="2017-11-05T20:35:32.091846795-06:00" level=debug msg="{\\\"container-pid\\\":\\\"3\\\",\\\"error\\\":\\\"exit status 130\\\",\\\"level\\\":\\\"error\\\",\\\"msg\\\":\\\"Process wait failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":200,\\\"time\\\":\\\"2017-11-06T02:35:32.077704882Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa
time="2017-11-05T20:35:32.092336275-06:00" level=debug msg="{\\\"container\\\":\\\"d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":200,\\\"time\\\":\\\"2017-11-06T02:35:32.078172633Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa
time="2017-11-05T20:35:32.09246911-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=113 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:35:32.094845204-06:00" level=debug msg="{\\\"container\\\":\\\"d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":200,\\\"time\\\":\\\"2017-11-06T02:35:32.078261571Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=d2985931204c445ccabd0b9d3103b73e7b003412b390841fa5540f8ea1328daa
time="2017-11-05T20:35:42.787008714-06:00" level=debug msg="{\\\"data\\\":\\\"not found\\\\r\\\\n\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Read from sequence\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:35:42.770437605Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:42.78705208-06:00" level=debug msg="00000000  6e 6f 74 20 66 6f 75 6e  64 0d 0a                 |not found..|" name=cc-proxy pid=28725 source=proxy wm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:45.251829884-06:00" level=debug msg="{\\\"data\\\":\\\"sh: lsb: not found\\\\r\\\\n\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Read from sequence\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:35:45.235290336Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:46.513288293-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:35:46.496745808Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:46.513455213-06:00" level=debug msg="{\\\"container-pid\\\":\\\"3\\\",\\\"error\\\":\\\"exit status 127\\\",\\\"level\\\":\\\"error\\\",\\\"msg\\\":\\\"Process wait failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"time\\\":\\\"2017-11-06T02:35:46.496937632Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:46.514042289-06:00" level=debug msg="{\\\"container\\\":\\\"06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"time\\\":\\\"2017-11-06T02:35:46.497306652Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:46.514077462-06:00" level=debug msg="{\\\"container\\\":\\\"06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":189,\\\"time\\\":\\\"2017-11-06T02:35:46.497352841Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=06a84dfdb8a307d887ea6da77586cb3aab7b1a080362ee7a39e5ea803e737d32
time="2017-11-05T20:35:46.514055746-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=120 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:35:55.509655821-06:00" level=debug msg="{\\\"data\\\":\\\"bash: lskl: command not found\\\\r\\\\n\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Read from sequence\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:35:55.489190209Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:35:55.509711853-06:00" level=debug msg="00000010  61 6e 64 20 6e 6f 74 20  66 6f 75 6e 64 0d 0a     |and not found..|" name=cc-proxy pid=28725 source=proxy wm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:04.512012016-06:00" level=debug msg="{\\\"data\\\":\\\"ls: cannot access '/dev/loop': No such file or directory\\\\r\\\\n\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Read from sequence\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:36:04.491558919Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:04.512062619-06:00" level=debug msg="00000000  6c 73 3a 20 63 61 6e 6e  6f 74 20 61 63 63 65 73  |ls: cannot acces|" name=cc-proxy pid=28725 source=proxy wm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:05.668475988-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:36:05.648032087Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:05.669074075-06:00" level=debug msg="{\\\"container-pid\\\":\\\"3\\\",\\\"error\\\":\\\"exit status 130\\\",\\\"level\\\":\\\"error\\\",\\\"msg\\\":\\\"Process wait failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"time\\\":\\\"2017-11-06T02:36:05.648675698Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:05.670392757-06:00" level=debug msg="{\\\"container\\\":\\\"758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"time\\\":\\\"2017-11-06T02:36:05.649790914Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:36:05.670412783-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=127 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:36:05.670420672-06:00" level=debug msg="{\\\"container\\\":\\\"758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":195,\\\"time\\\":\\\"2017-11-06T02:36:05.649861076Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=758deb2dc8e2960c74fa88680abbeb690425249660ba0fda48a4916dd3c6a17c
time="2017-11-05T20:38:08.451907599-06:00" level=debug msg="{\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"signal: killed\\\",\\\"time\\\":\\\"2017-11-06T02:38:08.430720449Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:08.452047475-06:00" level=debug msg="{\\\"container-pid\\\":\\\"3\\\",\\\"error\\\":\\\"container_linux.go:295: starting container process caused \\\\\\\"process_linux.go:399: container init caused \\\\\\\\\\\\\\\"rootfs_linux.go:58: mounting \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/shareDir/dev/vdb\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" to rootfs \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/hyper/2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e/root/rootfs\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" at \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/dev/loop0p1\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" caused \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"stat /tmp/shareDir/dev/vdb: no such file or directory\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"\\\\\\\\\\\\\\\"\\\\\\\"\\\",\\\"level\\\":\\\"error\\\",\\\"msg\\\":\\\"Could not run process\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":191,\\\"time\\\":\\\"2017-11-06T02:38:08.430861907Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:08.452117287-06:00" level=debug msg="{\\\"container\\\":\\\"2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":191,\\\"time\\\":\\\"2017-11-06T02:38:08.430974641Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:08.45216338-06:00" level=debug msg="{\\\"container\\\":\\\"2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":191,\\\"time\\\":\\\"2017-11-06T02:38:08.431028789Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:08.452389588-06:00" level=debug msg="{\\\"channel\\\":\\\"ctl\\\",\\\"command\\\":\\\"newcontainer\\\",\\\"error\\\":\\\"Process could not be started: container_linux.go:295: starting container process caused \\\\\\\"process_linux.go:399: container init caused \\\\\\\\\\\\\\\"rootfs_linux.go:58: mounting \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/shareDir/dev/vdb\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" to rootfs \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/tmp/hyper/2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e/root/rootfs\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" at \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"/dev/loop0p1\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\" caused \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"stat /tmp/shareDir/dev/vdb: no such file or directory\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"\\\\\\\\\\\\\\\"\\\\\\\"\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"command failed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":191,\\\"time\\\":\\\"2017-11-06T02:38:08.431232528Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:24.693334433-06:00" level=debug msg="{\\\"error\\\":\\\"read /dev/ptmx: input/output error\\\",\\\"level\\\":\\\"info\\\",\\\"msg\\\":\\\"Sequence has been closed\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"sequence\\\":3,\\\"time\\\":\\\"2017-11-06T02:38:24.678546345Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=21a6d3069b10395d14e89d7336afce0f6a5b37bd3a066e2ed62aab2a5931f477
time="2017-11-05T20:38:24.694074079-06:00" level=debug msg="{\\\"container\\\":\\\"21a6d3069b10395d14e89d7336afce0f6a5b37bd3a066e2ed62aab2a5931f477\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"time\\\":\\\"2017-11-06T02:38:24.679320116Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=21a6d3069b10395d14e89d7336afce0f6a5b37bd3a066e2ed62aab2a5931f477
time="2017-11-05T20:38:24.694126855-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=140 name=cc-proxy pid=28725 source=proxy
time="2017-11-05T20:38:24.694156135-06:00" level=debug msg="{\\\"container\\\":\\\"21a6d3069b10395d14e89d7336afce0f6a5b37bd3a066e2ed62aab2a5931f477\\\",\\\"container-pid\\\":\\\"3\\\",\\\"level\\\":\\\"warning\\\",\\\"msg\\\":\\\"Container process no longer exists\\\",\\\"name\\\":\\\"cc-agent\\\",\\\"pid\\\":190,\\\"time\\\":\\\"2017-11-06T02:38:24.679386125Z\\\"}" name=cc-proxy pid=28725 source=qemu vm=21a6d3069b10395d14e89d7336afce0f6a5b37bd3a066e2ed62aab2a5931f477
time="2017-11-05T20:38:38.463627687-06:00" level=error msg="timeout waiting for process with token eBs-eMMzb4NePdosbCEI3fZllSbbEHvJ8xsQ9P8NW1A=" name=cc-proxy pid=28725 section=io source=proxy vm=2efb75bfc037b5ae3e71eb93d6ef22cb0eb0b041663fb61108c05c0fec51157e
time="2017-11-05T20:38:38.463737219-06:00" level=error msg="error serving client: write unix /var/run/clear-containers/proxy.sock->@: use of closed network connection" client=134 name=cc-proxy pid=28725 source=proxy

Shim logs

Recent shim problems found in system journal:

time="2017-11-03T18:44:48.582882216-0600" level="debug" pid=28813 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T18:55:32.956528991-0600" level="debug" pid=31498 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T18:59:51.303995470-0600" level="debug" pid=32396 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T19:00:14.550008588-0600" level="debug" pid=32499 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T19:00:46.931340164-0600" level="debug" pid=32626 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T19:01:00.850547757-0600" level="debug" pid=32727 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-03T19:02:57.682081418-0600" level="debug" pid=1583 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-05T20:33:38.577580823-0600" level="debug" pid=7976 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-05T20:34:09.228037002-0600" level="debug" pid=8088 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-05T20:35:32.092384596-0600" level="debug" pid=8216 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-05T20:35:46.513853822-0600" level="debug" pid=8361 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"
time="2017-11-05T20:36:05.670218697-0600" level="debug" pid=8463 function="send_proxy_message" line=300 source="shim" name="cc-shim" msg="Sending frame of type:0, opcode:5, payload:(empty)"

Container manager details

Have docker

Docker

Output of "docker info":

Containers: 2
 Running: 0
 Paused: 0
 Stopped: 2
Images: 2
Server Version: 17.09.0-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: cc-runtime runc
Default Runtime: cc-runtime
Init Binary: docker-init
containerd version: 06b9cb35161009dcb7123345749fef02f7cea8e0
runc version: 549ba28 (expected: 3f2f8b84a77f73d38244dd690525642a72156c64)
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.13.10-100.fc25.x86_64
Operating System: Fedora 25 (Twenty Five)
OSType: linux
Architecture: x86_64
CPUs: 8
Total Memory: 15.55GiB
Name: juliomon-mobl1.zpn.intel.com
ID: T2UT:USSQ:4LEN:H777:GQU5:Z33X:2I4K:URU5:UIND:JPQK:OWPB:XZ67
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 18
 Goroutines: 29
 System Time: 2017-11-05T20:42:43.881534753-06:00
 EventsListeners: 0
Http Proxy: http://proxy-chain.intel.com:911
Https Proxy: http://proxy-chain.intel.com:911
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

No kubectl

Packages

No dpkg Have rpm Output of "rpm -qa|egrep "(cc-proxy|cc-runtime|cc-shim|clear-containers-image|linux-container|qemu-lite|qemu-system-x86|cc-oci-runtime)"":

clear-containers-image-18770-38.1.x86_64
cc-proxy-bin-3.0.6+git.3020872-11.1.x86_64
cc-runtime-bin-3.0.6+git.549ba28-11.1.x86_64
cc-proxy-config-3.0.6+git.3020872-11.1.x86_64
cc-proxy-3.0.6+git.3020872-11.1.x86_64
cc-runtime-config-3.0.6+git.549ba28-11.1.x86_64
linux-container-4.9.58-79.1.x86_64
qemu-lite-bin-2.7.1+git.d4a337fe91-9.1.x86_64
cc-shim-bin-3.0.6+git.11b5eef-11.1.x86_64
qemu-lite-data-2.7.1+git.d4a337fe91-9.1.x86_64
cc-shim-3.0.6+git.11b5eef-11.1.x86_64
cc-runtime-3.0.6+git.549ba28-11.1.x86_64
qemu-lite-2.7.1+git.d4a337fe91-9.1.x86_64

devimc avatar Nov 06 '17 02:11 devimc

seems like part of the issue was introduced in the revision e1cc3cb69a0738bb678a208750577fdd5296c577, checking out 1 commit before that revision the container runs, but the device is not hot plugged

$ docker run --device /dev/loop0p1 -ti debian ls /dev/loop*
ls: cannot access '/dev/loop0': No such file or directory
ls: cannot access '/dev/loop0p1': No such file or directory
ls: cannot access '/dev/loop-control': No such file or directory

@mcastelino @amshinde any idea about this issue?

devimc avatar Nov 06 '17 03:11 devimc

@devimc Can you try with https://github.com/clearcontainers/proxy/pull/163? The above commit added vendoring to runtime, but not to the proxy.

amshinde avatar Nov 06 '17 06:11 amshinde

@amshinde no, it doesn't work

devimc avatar Nov 06 '17 13:11 devimc

@devimc After the vendoring, the issue is resolved for me using the Ubuntu 18770 image. However it worked for you only with a newer image on Fedora. I am wondering if you needed to restart docker after updating your image, I have seen docker using an older image before. @jcvenegas @gorozco1 Can you confirm when this change go into the image : https://github.com/clearcontainers/agent/pull/134

amshinde avatar Nov 08 '17 05:11 amshinde

@amshinde @devimc : https://github.com/clearcontainers/runtime/pull/798 Includes the https://github.com/clearcontainers/agent/pull/134

jcvenegas avatar Nov 08 '17 15:11 jcvenegas

thanks @jcvenegas

devimc avatar Nov 08 '17 20:11 devimc