Hi, All,

 

When loading container image, my case uses `ubuntu`, by CC 2.1, the process stuck in the middle and failed to load the container image completely. Running by `--runtime=runc` have no issue, docker can load container image completely and enter the bash.

 

I also enabled the debugging mode, and collected a cc-oci-runtime.log. From the log, it seems to be live to me, and I didn’t see any explicit error message. Could anyone help to take a look on this and what might be the root cause?

 

My environment,

Ubuntu 16.04.02 with kernel package 4.8.0-39-generic.

Clear Container 2.1 installed following Wiki from github.

Docker 1.12.1.0~xenial

 

Here is the cc-oci-runtime.log,

 

2017-03-30T08:14:24.678459Z:2972:cc-oci-runtime:debug:called as: /usr/bin/cc-oci-runtime create --bundle /var/run/docker/libcontainerd/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33 --console /dev/pts/2 --pid-file /run/docker/libcontainerd/containerd/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/init/pid f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33

2017-03-30T08:14:24.679107Z:2972:cc-oci-runtime:debug:path '/var/run/docker/libcontainerd/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33' resolved to '/run/docker/libcontainerd/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33'

2017-03-30T08:14:24.679261Z:2972:cc-oci-runtime:debug:using config_file /run/docker/libcontainerd/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/config.json

2017-03-30T08:14:24.690270Z:2972:cc-oci-runtime:debug:path '/var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d' resolved to '/var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d'

2017-03-30T08:14:24.690679Z:2972:cc-oci-runtime:debug:Reading VM configuration from /usr/share/defaults/cc-oci-runtime/vm.json

2017-03-30T08:14:24.705489Z:2972:cc-oci-runtime:debug:path '/usr/bin/qemu-lite-system-x86_64' resolved to '/usr/bin/qemu-lite-system-x86_64'

2017-03-30T08:14:24.743396Z:2972:cc-oci-runtime:debug:path '/usr/share/clear-containers/clear-containers.img' resolved to '/usr/share/clear-containers/clear-13280-containers.img'

2017-03-30T08:14:24.743596Z:2972:cc-oci-runtime:debug:path '/usr/share/clear-containers/vmlinux.container' resolved to '/usr/share/clear-containers/vmlinux-4.9.4-53.container'

2017-03-30T08:14:24.744094Z:2972:cc-oci-runtime:debug:OCI spec versions: config=1.0.0-rc1, runtime=1.0.0-rc1

2017-03-30T08:14:24.744322Z:2972:cc-oci-runtime:debug:creating directory /var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33

2017-03-30T08:14:24.744501Z:2972:cc-oci-runtime:debug:setting up namespaces

2017-03-30T08:14:24.745003Z:2972:cc-oci-runtime:debug:created mount namespace

2017-03-30T08:14:24.746288Z:2972:cc-oci-runtime:debug:created network namespace

2017-03-30T08:14:24.746435Z:2972:cc-oci-runtime:debug:ignoring uts namespace request

2017-03-30T08:14:24.746557Z:2972:cc-oci-runtime:debug:ignoring pid namespace request

2017-03-30T08:14:24.746675Z:2972:cc-oci-runtime:debug:ignoring ipc namespace request

2017-03-30T08:14:24.746791Z:2972:cc-oci-runtime:debug:finished namespace setup

2017-03-30T08:14:24.746929Z:2972:cc-oci-runtime:debug:ignoring mount /proc

2017-03-30T08:14:24.747048Z:2972:cc-oci-runtime:debug:ignoring mount /dev

2017-03-30T08:14:24.747165Z:2972:cc-oci-runtime:debug:ignoring mount /dev/pts

2017-03-30T08:14:24.747284Z:2972:cc-oci-runtime:debug:ignoring mount /sys

2017-03-30T08:14:24.747402Z:2972:cc-oci-runtime:debug:ignoring mount /sys/fs/cgroup

2017-03-30T08:14:24.747520Z:2972:cc-oci-runtime:debug:ignoring mount /dev/mqueue

2017-03-30T08:14:24.747742Z:2972:cc-oci-runtime:debug:mounting /var/lib/docker/containers/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/resolv.conf of type bind onto /var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d/etc/resolv.conf with options '' and flags 0x45000

2017-03-30T08:14:24.748612Z:2972:cc-oci-runtime:debug:mounting /var/lib/docker/containers/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/hostname of type bind onto /var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d/etc/hostname with options '' and flags 0x45000

2017-03-30T08:14:24.749017Z:2972:cc-oci-runtime:debug:mounting /var/lib/docker/containers/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/hosts of type bind onto /var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d/etc/hosts with options '' and flags 0x45000

2017-03-30T08:14:24.749347Z:2972:cc-oci-runtime:debug:ignoring mount /dev/shm

2017-03-30T08:14:24.749528Z:2972:cc-oci-runtime:debug:connecting to proxy cc-proxy

2017-03-30T08:14:24.750225Z:2972:cc-oci-runtime:debug:connected to proxy socket /var/run/cc-oci-runtime/proxy.sock

2017-03-30T08:14:24.750739Z:2972:cc-oci-runtime:debug:hypervisor child pid is 2977

2017-03-30T08:14:24.751460Z:2972:cc-oci-runtime:debug:shim process running with pid 2978

2017-03-30T08:14:24.751789Z:2978:cc-oci-runtime:debug:shim child waiting for proxy socket fd on fd 7

2017-03-30T08:14:24.752604Z:2977:cc-oci-runtime:debug:disconnecting from proxy

2017-03-30T08:14:24.752734Z:2972:cc-oci-runtime:debug:created state file /var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/state.json

2017-03-30T08:14:24.753111Z:2977:cc-oci-runtime:debug:reading hypervisor command-line length from pipe

2017-03-30T08:14:24.944353Z:2972:cc-oci-runtime:debug:building hypervisor command-line

2017-03-30T08:14:24.944888Z:2972:cc-oci-runtime:debug:Discovering container interfaces

2017-03-30T08:14:24.945037Z:2972:cc-oci-runtime:debug:Interface := [lo]

2017-03-30T08:14:24.945165Z:2972:cc-oci-runtime:debug:Interface := [eth0]

2017-03-30T08:14:24.945290Z:2972:cc-oci-runtime:debug:Interface := [lo]

2017-03-30T08:14:24.945412Z:2972:cc-oci-runtime:debug:Interface := [eth0]

2017-03-30T08:14:24.945591Z:2972:cc-oci-runtime:debug:IP := [172.17.0.2]

2017-03-30T08:14:24.945734Z:2972:cc-oci-runtime:debug:IP := [255.255.0.0]

2017-03-30T08:14:24.945872Z:2972:cc-oci-runtime:debug:MTU for interface eth0: 1500

 

2017-03-30T08:14:24.946008Z:2972:cc-oci-runtime:debug:Interface := [lo]

2017-03-30T08:14:24.946135Z:2972:cc-oci-runtime:debug:Interface := [eth0]

2017-03-30T08:14:24.946260Z:2972:cc-oci-runtime:debug:IP := [fe80::42:acff:fe11:2]

2017-03-30T08:14:24.946454Z:2972:cc-oci-runtime:debug:netlink_get_default_gw

2017-03-30T08:14:24.946671Z:2972:cc-oci-runtime:debug:table=254

2017-03-30T08:14:24.946840Z:2972:cc-oci-runtime:debug:IP := [172.17.0.1]

2017-03-30T08:14:24.947020Z:2972:cc-oci-runtime:debug:gateway : 172.17.0.1

2017-03-30T08:14:24.947336Z:2972:cc-oci-runtime:debug:ifname=eth0

2017-03-30T08:14:24.947476Z:2972:cc-oci-runtime:debug:table=254

2017-03-30T08:14:24.947602Z:2972:cc-oci-runtime:debug:IP := [172.17.0.0]

2017-03-30T08:14:24.947752Z:2972:cc-oci-runtime:debug:destination : 172.17.0.0

2017-03-30T08:14:24.947898Z:2972:cc-oci-runtime:debug:ifname=eth0

2017-03-30T08:14:24.948024Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948147Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948267Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948386Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948505Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948623Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948741Z:2972:cc-oci-runtime:debug:table=255

2017-03-30T08:14:24.948869Z:2972:cc-oci-runtime:debug:[1] networks discovered

2017-03-30T08:14:24.949494Z:2972:cc-oci-runtime:debug:MTU set for interface ceth0 as 1500

 

2017-03-30T08:14:24.949643Z:2972:cc-oci-runtime:debug:netlink_link_add_bridge beth0

2017-03-30T08:14:24.950263Z:2972:cc-oci-runtime:debug:netlink_link_set_addr eth0

2017-03-30T08:14:24.950418Z:2972:cc-oci-runtime:debug:macaddr 02:00:ca:fe:00:00

2017-03-30T08:14:24.950687Z:2972:cc-oci-runtime:debug:netlink_link_set_master 2 3

2017-03-30T08:14:24.951112Z:2972:cc-oci-runtime:debug:netlink_link_set_master 5 3

2017-03-30T08:14:24.951584Z:2972:cc-oci-runtime:debug:netlink_link_enable[1] ceth0

2017-03-30T08:14:24.951849Z:2972:cc-oci-runtime:debug:netlink_link_enable[1] eth0

2017-03-30T08:14:24.952031Z:2972:cc-oci-runtime:debug:netlink_link_enable[1] beth0

2017-03-30T08:14:24.952352Z:2972:cc-oci-runtime:debug:network configuration complete

2017-03-30T08:14:24.952492Z:2972:cc-oci-runtime:debug:PCI Offset used for network: 8

2017-03-30T08:14:24.952685Z:2972:cc-oci-runtime:debug:using /usr/share/defaults/cc-oci-runtime/hypervisor.args

2017-03-30T08:14:24.958229Z:2972:cc-oci-runtime:debug:guest agent ctl socket: /var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-ctl.sock

2017-03-30T08:14:24.958397Z:2972:cc-oci-runtime:debug:guest agent tty socket: /var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-tty.sock

2017-03-30T08:14:24.958767Z:2972:cc-oci-runtime:debug:checking child setup (blocking)

2017-03-30T08:14:24.958821Z:2977:cc-oci-runtime:debug:reading hypervisor command-line from pipe

2017-03-30T08:14:24.959128Z:2977:cc-oci-runtime:debug:running command:

2017-03-30T08:14:24.959293Z:2977:cc-oci-runtime:debug:arg: '/usr/bin/qemu-lite-system-x86_64'

2017-03-30T08:14:24.959431Z:2977:cc-oci-runtime:debug:arg: '-name'

2017-03-30T08:14:24.959570Z:2977:cc-oci-runtime:debug:arg: 'ed1bc6bdfaff'

2017-03-30T08:14:24.959746Z:2977:cc-oci-runtime:debug:arg: '-machine'

2017-03-30T08:14:24.959943Z:2977:cc-oci-runtime:debug:arg: 'pc-lite,accel=kvm,kernel_irqchip,nvdimm'

2017-03-30T08:14:24.960120Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.960256Z:2977:cc-oci-runtime:debug:arg: 'nvdimm,memdev=mem0,id=nv0'

2017-03-30T08:14:24.960389Z:2977:cc-oci-runtime:debug:arg: '-object'

2017-03-30T08:14:24.960511Z:2977:cc-oci-runtime:debug:arg: 'memory-backend-file,id=mem0,mem-path=/usr/share/clear-containers/clear-13280-containers.img,size=235929600'

2017-03-30T08:14:24.960647Z:2977:cc-oci-runtime:debug:arg: '-m'

2017-03-30T08:14:24.960780Z:2977:cc-oci-runtime:debug:arg: '2G,slots=2,maxmem=3G'

2017-03-30T08:14:24.960903Z:2977:cc-oci-runtime:debug:arg: '-kernel'

2017-03-30T08:14:24.961025Z:2977:cc-oci-runtime:debug:arg: '/usr/share/clear-containers/vmlinux-4.9.4-53.container'

2017-03-30T08:14:24.961148Z:2977:cc-oci-runtime:debug:arg: '-append'

2017-03-30T08:14:24.961282Z:2977:cc-oci-runtime:debug:arg: 'root=/dev/pmem0p1 rootflags=dax,data=ordered,errors=remount-ro rw rootfstype=ext4 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 panic=1 console=hvc0 console=hvc1 initcall_debug init=/usr/lib/systemd/systemd systemd.unit=cc-agent.target iommu=off quiet systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket systemd.show_status=false cryptomgr.notests ip=::::::f328bbeddc77::off::'

2017-03-30T08:14:24.961481Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.961609Z:2977:cc-oci-runtime:debug:arg: 'virtio-9p-pci,fsdev=workload9p,mount_tag=rootfs'

2017-03-30T08:14:24.961734Z:2977:cc-oci-runtime:debug:arg: '-fsdev'

2017-03-30T08:14:24.961856Z:2977:cc-oci-runtime:debug:arg: 'local,id=workload9p,path=/var/lib/docker/aufs/mnt/4d6b595d689e88a17b9eec145e5b6918d7894200b9c5c8e1be8713bd2d9db81d,security_model=none'

2017-03-30T08:14:24.961982Z:2977:cc-oci-runtime:debug:arg: '-smp'

2017-03-30T08:14:24.962101Z:2977:cc-oci-runtime:debug:arg: '2,sockets=1,cores=2,threads=1'

2017-03-30T08:14:24.962224Z:2977:cc-oci-runtime:debug:arg: '-cpu'

2017-03-30T08:14:24.962343Z:2977:cc-oci-runtime:debug:arg: 'host'

2017-03-30T08:14:24.962463Z:2977:cc-oci-runtime:debug:arg: '-rtc'

2017-03-30T08:14:24.962581Z:2977:cc-oci-runtime:debug:arg: 'base=utc,driftfix=slew'

2017-03-30T08:14:24.962701Z:2977:cc-oci-runtime:debug:arg: '-no-user-config'

2017-03-30T08:14:24.962820Z:2977:cc-oci-runtime:debug:arg: '-nodefaults'

2017-03-30T08:14:24.962938Z:2977:cc-oci-runtime:debug:arg: '-global'

2017-03-30T08:14:24.963076Z:2977:cc-oci-runtime:debug:arg: 'kvm-pit.lost_tick_policy=discard'

2017-03-30T08:14:24.963247Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.963374Z:2977:cc-oci-runtime:debug:arg: 'virtio-serial-pci,id=virtio-serial0'

2017-03-30T08:14:24.963495Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.963615Z:2977:cc-oci-runtime:debug:arg: 'virtconsole,chardev=charconsole0,id=console0'

2017-03-30T08:14:24.963798Z:2977:cc-oci-runtime:debug:arg: '-chardev'

2017-03-30T08:14:24.963933Z:2977:cc-oci-runtime:debug:arg: 'socket,path=/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/console.sock,server,nowait,id=charconsole0,signal=off'

2017-03-30T08:14:24.964072Z:2977:cc-oci-runtime:debug:arg: '-chardev'

2017-03-30T08:14:24.964197Z:2977:cc-oci-runtime:debug:arg: 'socket,id=procsock,path=/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/process.sock,server,nowait'

2017-03-30T08:14:24.964349Z:2977:cc-oci-runtime:debug:arg: '-chardev'

2017-03-30T08:14:24.964505Z:2977:cc-oci-runtime:debug:arg: 'socket,id=charch0,path=/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-ctl.sock,server,nowait'

2017-03-30T08:14:24.964639Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.964770Z:2977:cc-oci-runtime:debug:arg: 'virtserialport,bus=virtio-serial0.0,nr=1,chardev=charch0,id=channel0,name=sh.hyper.channel.0'

2017-03-30T08:14:24.964899Z:2977:cc-oci-runtime:debug:arg: '-chardev'

2017-03-30T08:14:24.965032Z:2977:cc-oci-runtime:debug:arg: 'socket,id=charch1,path=/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-tty.sock,server,nowait'

2017-03-30T08:14:24.965169Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.965293Z:2977:cc-oci-runtime:debug:arg: 'virtserialport,bus=virtio-serial0.0,nr=2,chardev=charch1,id=channel1,name=sh.hyper.channel.1'

2017-03-30T08:14:24.965427Z:2977:cc-oci-runtime:debug:arg: '-uuid'

2017-03-30T08:14:24.965559Z:2977:cc-oci-runtime:debug:arg: '04cc03c8-80f5-492d-9f85-ed1bc6bdfaff'

2017-03-30T08:14:24.965691Z:2977:cc-oci-runtime:debug:arg: '-qmp'

2017-03-30T08:14:24.965823Z:2977:cc-oci-runtime:debug:arg: 'unix:/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/hypervisor.sock,server,nowait'

2017-03-30T08:14:24.965960Z:2977:cc-oci-runtime:debug:arg: '-nographic'

2017-03-30T08:14:24.966083Z:2977:cc-oci-runtime:debug:arg: '-vga'

2017-03-30T08:14:24.966234Z:2977:cc-oci-runtime:debug:arg: 'none'

2017-03-30T08:14:24.966366Z:2977:cc-oci-runtime:debug:arg: '-netdev'

2017-03-30T08:14:24.966498Z:2977:cc-oci-runtime:debug:arg: 'tap,ifname=ceth0,script=no,downscript=no,id=ceth0,vhost=on'

2017-03-30T08:14:24.966628Z:2977:cc-oci-runtime:debug:arg: '-device'

2017-03-30T08:14:24.966759Z:2977:cc-oci-runtime:debug:arg: 'driver=virtio-net-pci,bus=/pci-lite-host/pcie.0,addr=8,netdev=ceth0,mac=02:42:ac:11:00:02'

2017-03-30T08:14:24.967390Z:2972:cc-oci-runtime:debug:child setup successful

2017-03-30T08:14:26.480977Z:2972:cc-oci-runtime:debug:CTL created event: 3

2017-03-30T08:14:26.481280Z:2972:cc-oci-runtime:debug:communicating with proxy

2017-03-30T08:14:26.481434Z:2972:cc-oci-runtime:debug:CTL created event: 1

2017-03-30T08:14:26.481670Z:2972:cc-oci-runtime:debug:sending message (length 447) to proxy socket

2017-03-30T08:14:26.481809Z:2972:cc-oci-runtime:debug:writing message data to proxy socket: {"id":"hello","data":{"containerId":"f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33","ctlSerial":"/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-ctl.sock","ioSerial":"/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/ga-tty.sock","console":"/var/run/cc-oci-runtime/f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33/console.sock"}}

2017-03-30T08:16:24.533699Z:2978:cc-oci-runtime:critical:failed to read proxy socket fd

2017-03-30T08:16:24.560025Z:3165:cc-oci-runtime:debug:called as: /usr/bin/cc-oci-runtime delete f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33

2017-03-30T08:16:24.578748Z:3165:cc-oci-runtime:debug:connecting to proxy cc-proxy

2017-03-30T08:16:24.579874Z:3165:cc-oci-runtime:debug:connected to proxy socket /var/run/cc-oci-runtime/proxy.sock

2017-03-30T08:16:24.580276Z:3165:cc-oci-runtime:debug:communicating with proxy

2017-03-30T08:16:24.580412Z:3165:cc-oci-runtime:debug:sending message (length 105) to proxy socket

2017-03-30T08:16:24.580508Z:3165:cc-oci-runtime:debug:writing message data to proxy socket: {"id":"attach","data":{"containerId":"f328bbeddc778633efee38e0be7b1a7bd3da84d730bbdf38f9b09df3150cbc33"}}

2017-03-30T08:16:24.583491Z:3165:cc-oci-runtime:debug:proxy msg length: 37

2017-03-30T08:16:24.583638Z:3165:cc-oci-runtime:debug:message read from proxy socket: {"success":true,"data":{"version":1}}

2017-03-30T08:16:24.584115Z:3165:cc-oci-runtime:debug:msg received: {"success":true,"data":{"version":1}}

2017-03-30T08:16:24.584300Z:3165:cc-oci-runtime:debug:communicating with proxy

2017-03-30T08:16:24.584402Z:3165:cc-oci-runtime:debug:sending message (length 58) to proxy socket

2017-03-30T08:16:24.584488Z:3165:cc-oci-runtime:debug:writing message data to proxy socket: {"id":"hyper","data":{"hyperName":"destroypod","data":{}}}

 

Thanks in advance,

Horace