search

clearcontainers / tests

Clear Container Tests Repository
Apache License 2.0
13 stars 18 forks source link

Test and add qemu-cc to the CI #364

Open chavafg opened 7 years ago

chavafg commented 7 years ago

OBS staging packages already provide new qemu-cc which is the qemu version with Q35 support.

Before moving to use this qemu by default, proper testing should be done and the CI should work with this qemu version.

chavafg commented 7 years ago

Functional and Docker integration tests pass correctly: 

Execute Tests
Warning: Permanently added '[127.0.0.1]:10022' (ECDSA) to the list of known hosts.
Warning: Permanently added '[127.0.0.1]:10022' (ECDSA) to the list of known hosts.
ln -sf . vendor/src
GOPATH=/home/fuentess/go/src/github.com/clearcontainers/tests/vendor go build ./vendor/github.com/onsi/ginkgo/ginkgo
unlink vendor/src
./ginkgo functional/ -- -runtime cc-runtime -timeout 5
Running Suite: Functional Suite
===============================
Random Seed: 1502398990
Will run 27 of 27 specs

•••••••••••••••••••••••••••
Ran 27 of 27 Specs in 15.317 seconds
SUCCESS! -- 27 Passed | 0 Failed | 0 Pending | 0 Skipped PASS

Ginkgo ran 1 suite in 15.87189425s
Test Suite Passed
./ginkgo ./integration/docker/ -- -timeout 5
Running command '/usr/bin/docker [docker pull busybox]'
Running Suite: Integration Suite
================================
Random Seed: 1502399006
Will run 36 of 36 specs

•••••••••••
------------------------------
S [SKIPPING] [1.557 seconds]
attach
/home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/attach_test.go:50
  attach with docker
  /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/attach_test.go:49
    check attach functionality
    /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/attach_test.go:48
      should attach exit code [It]
      /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/attach_test.go:47

      Issue https://github.com/clearcontainers/runtime/issues/363

      /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/attach_test.go:44
------------------------------
••••••••••••
------------------------------
• [SLOW TEST:12.782 seconds]
restart
/home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/restart_test.go:55
  restart with docker
  /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/restart_test.go:54
    restart a container
    /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/restart_test.go:53
      should be running
      /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/restart_test.go:52
------------------------------
•
------------------------------
S [SKIPPING] [0.009 seconds]
user
/home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/user_test.go:63
  set user with docker
  /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/user_test.go:62
    run as non-root user
    /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/user_test.go:46
      should display the non-root user [It]
      /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/user_test.go:45

      Issue https://github.com/clearcontainers/runtime/issues/386

      /home/fuentess/go/src/github.com/clearcontainers/tests/integration/docker/user_test.go:41
------------------------------
•••••••••
Ran 34 of 36 Specs in 64.163 seconds
SUCCESS! -- 34 Passed | 0 Failed | 0 Pending | 2 Skipped PASS

Ginkgo ran 1 suite in 1m7.797771937s
Test Suite Passed
jcvenegas commented 7 years ago

I tested in my fedora box and got crio-errors.

I used the default storage driver:

-       RUNTIME=${CC_RUNTIME} STORAGE_OPTS="--storage-driver=aufs" ./test/test_runner.sh crio.bats
+       RUNTIME=${CC_RUNTIME}  ./test/test_runner.sh crio.bat
Environment: 

```
cat /etc/clear-containers/configuration.toml 
# XXX: Warning: this file is auto-generated from file "config/configuration.toml.in".

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

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

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

[agent.hyperstart]
pause_root_path = "/var/lib/clear-containers/runtime/bundles/pause_bundle"

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

$ cat /etc/os-release 
NAME=Fedora
VERSION="25 (Workstation Edition)"
```
crio-tets logs: 
```ok 1 ctr not found correct error message
not ok 2 ctr termination reason Completed
# (from function `cleanup_pods' in file helpers.bash, line 304,
#  in test file crio.bats, line 52)
#   `cleanup_pods' failed
# 0
# time="2017-08-10 15:55:00.013643121-05:00" level=info msg="[graphdriver] using prior storage driver "overlay"" 
# time="2017-08-10 15:55:00.023352441-05:00" level=debug msg="sandboxes: map[]" 
# time="2017-08-10 15:55:01.140093478-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:redis:alpine,},}" 
# time="2017-08-10 15:55:01.140207614-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/redis:alpine"" 
# time="2017-08-10 15:55:01.141099827-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:f6d996365dbd7b1c0502295a5e0f2a4ba74d994dbe1838ddb1c381b786b5a860,RepoTags:[docker.io/library/redis:alpine redis:alpine],RepoDigests:[],Size_:27495390,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.196875473-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:redis:alpine,},}" 
# time="2017-08-10 15:55:01.196930872-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/redis:alpine"" 
# time="2017-08-10 15:55:01.197191434-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:f6d996365dbd7b1c0502295a5e0f2a4ba74d994dbe1838ddb1c381b786b5a860,RepoTags:[docker.io/library/redis:alpine redis:alpine],RepoDigests:[],Size_:27495390,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.246668603-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:mrunalp/oom,},}" 
# time="2017-08-10 15:55:01.246740117-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/mrunalp/oom:latest"" 
# time="2017-08-10 15:55:01.246948493-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:5aea63bb0bacf0003a7273839164c37d0a57e09290c3eb2d270ba0910cac93bc,RepoTags:[docker.io/mrunalp/oom:latest mrunalp/oom docker.io/library/mrunalp/oom],RepoDigests:[],Size_:5719481,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.304232381-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:redis@sha256:03789f402b2ecfb98184bf128d180f398f81c63364948ff1454583b02442f73b,},}" 
# time="2017-08-10 15:55:01.304304628-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/redis:latest@03789f402b2ecfb98184bf128d180f398f81c63364948ff1454583b02442f73b"" 
# time="2017-08-10 15:55:01.304561536-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:03789f402b2ecfb98184bf128d180f398f81c63364948ff1454583b02442f73b,RepoTags:[docker.io/library/redis:latest redis@sha256:03789f402b2ecfb98184bf128d180f398f81c63364948ff1454583b02442f73b docker.io/library/redis@sha256:03789f402b2ecfb98184bf128d180f398f81c63364948ff1454583b02442f73b],RepoDigests:[],Size_:19826844,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.357016936-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:runcom/stderr-test,},}" 
# time="2017-08-10 15:55:01.357099895-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/runcom/stderr-test:latest"" 
# time="2017-08-10 15:55:01.357402972-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:1f79cc812fd71bd1120df467370082aa4cbe98532cf51dfc8e7d95e3126d5651,RepoTags:[docker.io/runcom/stderr-test:latest runcom/stderr-test:latest],RepoDigests:[],Size_:4906035,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.419362170-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:runcom/stderr-test,},}" 
# time="2017-08-10 15:55:01.419422241-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/runcom/stderr-test:latest"" 
# time="2017-08-10 15:55:01.419618823-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:1f79cc812fd71bd1120df467370082aa4cbe98532cf51dfc8e7d95e3126d5651,RepoTags:[docker.io/runcom/stderr-test:latest runcom/stderr-test:latest],RepoDigests:[],Size_:4906035,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.479954923-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:busybox,},}" 
# time="2017-08-10 15:55:01.480034459-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/busybox:latest"" 
# time="2017-08-10 15:55:01.480300255-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:933333d9cc1406782b6ff598e5d33da74baab0e2b8edecbe4c64140cc38a3b1e,RepoTags:[docker.io/library/busybox:latest busybox:latest],RepoDigests:[],Size_:1131226,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.535855394-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:busybox,},}" 
# time="2017-08-10 15:55:01.535927621-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/busybox:latest"" 
# time="2017-08-10 15:55:01.536098967-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:933333d9cc1406782b6ff598e5d33da74baab0e2b8edecbe4c64140cc38a3b1e,RepoTags:[docker.io/library/busybox:latest busybox:latest],RepoDigests:[],Size_:1131226,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.595073098-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:mrunalp/image-volume-test,},}" 
# time="2017-08-10 15:55:01.595133823-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/mrunalp/image-volume-test:latest"" 
# time="2017-08-10 15:55:01.595318606-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:3d949a7f063b7a164a12c0c724b7bce5f9db8c4236328f9360c7fba3303bfb0d,RepoTags:[docker.io/mrunalp/image-volume-test:latest mrunalp/image-volume-test docker.io/library/mrunalp/image-volume-test],RepoDigests:[],Size_:1095628,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.651939718-05:00" level=debug msg="ImageStatusRequest: &ImageStatusRequest{Image:&ImageSpec{Image:mrunalp/image-volume-test,},}" 
# time="2017-08-10 15:55:01.651997820-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/mrunalp/image-volume-test:latest"" 
# time="2017-08-10 15:55:01.652165503-05:00" level=debug msg="ImageStatusResponse: &ImageStatusResponse{Image:&Image{Id:3d949a7f063b7a164a12c0c724b7bce5f9db8c4236328f9360c7fba3303bfb0d,RepoTags:[docker.io/mrunalp/image-volume-test:latest mrunalp/image-volume-test docker.io/library/mrunalp/image-volume-test],RepoDigests:[],Size_:1095628,Uid:nil,Username:,},}" 
# time="2017-08-10 15:55:01.701578190-05:00" level=debug msg="RunPodSandboxRequest &RunPodSandboxRequest{Config:&PodSandboxConfig{Metadata:&PodSandboxMetadata{Name:podsandbox1,Uid:redhat-test-crio,Namespace:redhat.test.crio,Attempt:1,},Hostname:crioctl_host,LogDirectory:,DnsConfig:&DNSConfig{Servers:[],Searches:[8.8.8.8],Options:[],},PortMappings:[],Labels:map[string]string{group: test,},Annotations:map[string]string{owner: hmeng,security.alpha.kubernetes.io/seccomp/pod: unconfined,security.alpha.kubernetes.io/sysctls: kernel.shm_rmid_forced=1,net.ipv4.ip_local_port_range=1024 65000,security.alpha.kubernetes.io/unsafe-sysctls: 
kernel.msgmax=8192,},Linux:&LinuxPodSandboxConfig{CgroupParent:/Burstable/pod_123-456,SecurityContext:&LinuxSandboxSecurityContext{NamespaceOptions:&NamespaceOption{HostNetwork:false,HostPid:false,HostIpc:false,},SelinuxOptions:nil,RunAsUser:nil,ReadonlyRootfs:false,SupplementalGroups:[],Privileged:false,},},},}" 
# time="2017-08-10 15:55:01.701644764-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/kubernetes/pause:latest"" 
# time="2017-08-10 15:55:01.701883165-05:00" level=debug msg="exporting opaque data as blob "sha256:bc77a30241e2bf6ccd79e9245ee59511d621a9dc45be0ac5fe4ef1ab9d1fbd37"" 
# time="2017-08-10 15:55:01.702704099-05:00" level=debug msg="created pod sandbox "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57"" 
# time="2017-08-10 15:55:01.702951075-05:00" level=debug msg="pod sandbox "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57" has work directory "/tmp/tmp.ZhEmlcnSJq/crio/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata"" 
# time="2017-08-10 15:55:01.702996623-05:00" level=debug msg="pod sandbox "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57" has run directory "/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata"" 
# time="2017-08-10 15:55:01.780426734-05:00" level=debug msg="mounted container "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57" at "/tmp/tmp.ZhEmlcnSJq/crio/overlay/7c8e4a2392f3fa6319fc46385321d1976f671cbd4113f08d98f5dd6881251fe5/merged"" 
# time="2017-08-10 15:55:01.781915170-05:00" level=info msg="Got netns path /var/run/netns/k8s_podsandbox1_redhat.test.crio_redhat-test-crio_1-2595e305" 
# time="2017-08-10 15:55:01.781923169-05:00" level=info msg="Using netns path redhat.test.crio" 
# time="2017-08-10 15:55:01.781928057-05:00" level=info msg="About to run with conf.Network.Type=loopback" 
# time="2017-08-10 15:55:01.784244751-05:00" level=info msg="Got netns path /var/run/netns/k8s_podsandbox1_redhat.test.crio_redhat-test-crio_1-2595e305" 
# time="2017-08-10 15:55:01.784261541-05:00" level=info msg="Using netns path redhat.test.crio" 
# time="2017-08-10 15:55:01.784272294-05:00" level=info msg="About to run with conf.Network.Type=bridge" 
# time="2017-08-10 15:55:03.696247123-05:00" level=debug msg="running conmon: /home/jcvenega/go/src/github.com/kubernetes-incubator/cri-o/conmon/conmon" args=[-c df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57 -u df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57 -r /bin/cc-runtime -b /tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata -p /tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata/pidfile -l /var/log/crio/pods/df54aa4cea3e3a7ec4da99c5b720436358c94ef99
47f7a20477611002bc17e57/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57.log] 
# time="2017-08-10 15:55:04.641160610-05:00" level=debug msg="Received container pid: 32400" 
# time="2017-08-10 15:55:04.688998502-05:00" level=debug msg="RunPodSandboxResponse: &RunPodSandboxResponse{PodSandboxId:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,}" 
# df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57
# time="2017-08-10 15:55:04.746235574-05:00" level=debug msg="CreateContainerRequest &CreateContainerRequest{PodSandboxId:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,Config:&ContainerConfig{Metadata:&ContainerMetadata{Name:container1,Attempt:1,},Image:&ImageSpec{Image:redis:alpine,},Command:[/bin/ls],Args:[],WorkingDir:/,Envs:[&KeyValue{Key:PATH,Value:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin,} &KeyValue{Key:TERM,Value:xterm,} &KeyValue{Key:TESTDIR,Value:test/dir1,} &KeyValue{Key:TESTFILE,Value:test/file1,}],Mounts:[],Devices:[],Labels:map[string]string{batch: no,type: small,},Annotations
:map[string]string{daemon: crio,owner: dragon,},LogPath:,Stdin:false,StdinOnce:false,Tty:false,Linux:&LinuxContainerConfig{Resources:&LinuxContainerResources{CpuPeriod:10000,CpuQuota:20000,CpuShares:512,MemoryLimitInBytes:0,OomScoreAdj:30,},SecurityContext:&LinuxContainerSecurityContext{Capabilities:&Capability{AddCapabilities:[setuid setgid],DropCapabilities:[audit_read],},Privileged:false,NamespaceOptions:nil,SelinuxOptions:&SELinuxOption{User:system_u,Role:system_r,Type:container_t,Level:s0:c4,c5,},RunAsUser:nil,RunAsUsername:,ReadonlyRootfs:false,SupplementalGroups:[],},},},SandboxConfig:nil,}" 
# time="2017-08-10 15:55:04.746482304-05:00" level=debug msg="setting container's log_path" ctr.logfile= log_path="/var/log/crio/pods/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d.log" sbox.logdir="/var/log/crio/pods/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57" 
# time="2017-08-10 15:55:04.746628969-05:00" level=debug msg="pod container state &{State:{Version:1.0.0-rc5 ID:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57 Status:running Pid:32400 Bundle:/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata Annotations:map[com.github.containers.virtcontainers.pkg.oci.bundle_path:/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata com.github.containers.virtcontainers.pkg.oci.config_path:/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54
aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata/config.json com.github.containers.virtcontainers.pkg.oci.container_type:pod_sandbox]} Created:2017-08-10 15:55:01.704074447 -0500 CDT Started:2017-08-10 15:55:04.674728743 -0500 CDT Finished:0001-01-01 00:00:00 +0000 UTC ExitCode:0 OOMKilled:false Error:}" 
# time="2017-08-10 15:55:04.746758596-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/redis:alpine"" 
# time="2017-08-10 15:55:04.747196545-05:00" level=debug msg="exporting opaque data as blob "sha256:9d8fa9aa0e5b35f1790162225a6ffe6207a3ca73d967d8f6920ed0f293086ff9"" 
# time="2017-08-10 15:55:04.748421731-05:00" level=debug msg="created container "13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d"" 
# time="2017-08-10 15:55:04.748796222-05:00" level=debug msg="container "13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d" has work directory "/tmp/tmp.ZhEmlcnSJq/crio/overlay-containers/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d/userdata"" 
# time="2017-08-10 15:55:04.748853002-05:00" level=debug msg="container "13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d" has run directory "/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d/userdata"" 
# time="2017-08-10 15:55:04.832487772-05:00" level=debug msg="mounted container "13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d" at "/tmp/tmp.ZhEmlcnSJq/crio/overlay/af7bb289afd5c1b15d572c94ffdaf2358772f3a06d3555b8f9b3294ba4b209d7/merged"" 
# time="2017-08-10 15:55:04.832557818-05:00" level=debug msg="OCI process args [/bin/ls]" 
# time="2017-08-10 15:55:04.832584845-05:00" level=debug msg="CONTAINER USER: " 
# time="2017-08-10 15:55:04.832788821-05:00" level=debug msg="UID: 0, GID: 0, Groups: [0 1 2 3 4 6 10 11 20 26 27]" 
# time="2017-08-10 15:55:04.834155985-05:00" level=debug msg="running conmon: /home/jcvenega/go/src/github.com/kubernetes-incubator/cri-o/conmon/conmon" args=[-c 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d -u 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d -r /bin/cc-runtime -b /tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d/userdata -p /tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d/userdata/pidfile -l /var/log/crio/pods/df54aa4cea3e3a7ec4da99c5b720436358c94ef99
47f7a20477611002bc17e57/13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d.log] 
# time="2017-08-10 15:55:04.845979807-05:00" level=debug msg="Received container pid: 32471" 
# time="2017-08-10 15:55:04.858328157-05:00" level=debug msg="CreateContainerResponse: &CreateContainerResponse{ContainerId:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,}" 
# 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d
# time="2017-08-10 15:55:04.912486726-05:00" level=debug msg="StartContainerRequest &StartContainerRequest{ContainerId:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,}" 
# time="2017-08-10 15:55:04.939920961-05:00" level=debug msg="StartContainerResponse &StartContainerResponse{}" 
# 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d
# time="2017-08-10 15:55:05.064799973-05:00" level=debug msg="ContainerStatusRequest &ContainerStatusRequest{ContainerId:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,}" 
# time="2017-08-10 15:55:05.077654282-05:00" level=debug msg="parsed reference into "[overlay@/tmp/tmp.ZhEmlcnSJq/crio+/tmp/tmp.ZhEmlcnSJq/crio-run]docker.io/library/redis:alpine"" 
# time="2017-08-10 15:55:05.078023224-05:00" level=debug msg="ContainerStatusResponse: &ContainerStatusResponse{Status:&ContainerStatus{Id:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,Metadata:&ContainerMetadata{Name:container1,Attempt:1,},State:CONTAINER_EXITED,CreatedAt:1502398504746649205,StartedAt:1502398504939883123,FinishedAt:1502398504943646120,ExitCode:0,Image:&ImageSpec{Image:redis:alpine,},ImageRef:f6d996365dbd7b1c0502295a5e0f2a4ba74d994dbe1838ddb1c381b786b5a860,Reason:Completed,Message:,Labels:map[string]string{batch: no,type: small,},Annotations:map[string]string{daemon: crio,owner: dragon,},Moun
ts:[&Mount{ContainerPath:/dev/shm,HostPath:/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata/shm,Readonly:false,SelinuxRelabel:false,} &Mount{ContainerPath:/etc/resolv.conf,HostPath:/tmp/tmp.ZhEmlcnSJq/crio-run/overlay-containers/df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57/userdata/resolv.conf,Readonly:false,SelinuxRelabel:false,}],},}" 
# ID: 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d
# Name: container1
# Attempt: 1
# Status: CONTAINER_EXITED
# Created: 2017-08-10 15:55:04.746649205 -0500 CDT
# Started: 2017-08-10 15:55:04.939883123 -0500 CDT
# Finished: 2017-08-10 15:55:04.94364612 -0500 CDT
# Exit Code: 0
# Reason: Completed
# Image: redis:alpine
# time="2017-08-10 15:55:05.134521967-05:00" level=debug msg="ListContainersRequest &ListContainersRequest{Filter:&ContainerFilter{Id:,State:nil,PodSandboxId:,LabelSelector:map[string]string{},},}" 
# time="2017-08-10 15:55:05.141750818-05:00" level=debug msg="ListContainersResponse: &ListContainersResponse{Containers:[&Container{Id:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,PodSandboxId:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,Metadata:&ContainerMetadata{Name:container1,Attempt:1,},Image:&ImageSpec{Image:redis:alpine,},ImageRef:,State:CONTAINER_EXITED,CreatedAt:1502398504746649205,Labels:map[string]string{batch: no,type: small,},Annotations:map[string]string{daemon: crio,owner: dragon,},}],}" 
# time="2017-08-10 15:55:05.211007156-05:00" level=debug msg="StopContainerRequest &StopContainerRequest{ContainerId:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,Timeout:10,}" 
# time="2017-08-10 15:55:05.223458044-05:00" level=debug msg="StopContainerResponse: &StopContainerResponse{}" 
# 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d
# time="2017-08-10 15:55:05.298731436-05:00" level=debug msg="RemoveContainerRequest &RemoveContainerRequest{ContainerId:13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d,}" 
# time="2017-08-10 15:55:05.327414817-05:00" level=debug msg="RemoveContainerResponse: &RemoveContainerResponse{}" 
# 13688a5a438f71120e6709d5a0c8d60160bc43c3becbea7e13c32dacf664587d
# time="2017-08-10 15:55:05.390935675-05:00" level=debug msg="ListPodSandboxRequest &ListPodSandboxRequest{Filter:&PodSandboxFilter{Id:,State:nil,LabelSelector:map[string]string{},},}" 
# time="2017-08-10 15:55:05.397696538-05:00" level=debug msg="ListPodSandboxResponse &ListPodSandboxResponse{Items:[&PodSandbox{Id:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,Metadata:&PodSandboxMetadata{Name:podsandbox1,Uid:redhat-test-crio,Namespace:redhat.test.crio,Attempt:1,},State:SANDBOX_READY,CreatedAt:1502398501704074447,Labels:map[string]string{group: test,},Annotations:map[string]string{owner: hmeng,security.alpha.kubernetes.io/seccomp/pod: unconfined,security.alpha.kubernetes.io/sysctls: kernel.shm_rmid_forced=1,net.ipv4.ip_local_port_range=1024 65000,security.alpha.kubernetes.io/unsafe-sysctls: 
kernel.msgmax=8192,},}],}" 
# time="2017-08-10 15:55:05.468667617-05:00" level=debug msg="StopPodSandboxRequest &StopPodSandboxRequest{PodSandboxId:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,}" 
# time="2017-08-10 15:55:05.468749760-05:00" level=info msg="Got netns path /var/run/netns/cni-4d41ff4b-f238-1770-c8b4-77cd1ebebfae" 
# time="2017-08-10 15:55:05.468757374-05:00" level=info msg="Using netns path redhat.test.crio" 
# time="2017-08-10 15:55:05.468763023-05:00" level=info msg="About to run with conf.Network.Type=bridge" 
# time="2017-08-10 15:55:05.662466126-05:00" level=debug msg="Failed to unmount 7c8e4a2392f3fa6319fc46385321d1976f671cbd4113f08d98f5dd6881251fe5 overlay: device or resource busy" 
# time="2017-08-10 15:55:05.662494096-05:00" level=debug msg="failed to unmount container "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57": device or resource busy" 
# time="2017-08-10 15:55:05.662502447-05:00" level=warning msg="failed to stop sandbox container in pod sandbox df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57: device or resource busy" 
# time="2017-08-10 15:55:05.662510616-05:00" level=debug msg="StopPodSandboxResponse: &StopPodSandboxResponse{}" 
# df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57
# time="2017-08-10 15:55:05.720275712-05:00" level=debug msg="RemovePodSandboxRequest &RemovePodSandboxRequest{PodSandboxId:df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57,}" 
# time="2017-08-10 15:55:05.785289265-05:00" level=debug msg="Failed to unmount 7c8e4a2392f3fa6319fc46385321d1976f671cbd4113f08d98f5dd6881251fe5 overlay: device or resource busy" 
# time="2017-08-10 15:55:05.785326313-05:00" level=debug msg="failed to unmount container "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57": device or resource busy" 
# time="2017-08-10 15:55:05.785336801-05:00" level=warning msg="failed to stop sandbox container in pod sandbox df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57: device or resource busy" 
# time="2017-08-10 15:55:05.785388057-05:00" level=debug msg="Failed to unmount 7c8e4a2392f3fa6319fc46385321d1976f671cbd4113f08d98f5dd6881251fe5 overlay: device or resource busy" 
# time="2017-08-10 15:55:05.785408950-05:00" level=debug msg="failed to delete pod sandbox "df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57": device or resource busy" 
# removing the pod sandbox failed: rpc error: code = 2 desc = failed to remove pod sandbox df54aa4cea3e3a7ec4da99c5b720436358c94ef9947f7a20477611002bc17e57: device or resource busy
# rm: cannot remove '/tmp/tmp.ZhEmlcnSJq/crio/overlay/7c8e4a2392f3fa6319fc46385321d1976f671cbd4113f08d98f5dd6881251fe5/merged': Device or resource busy
not ok 3 ctr termination reason Error
```
chavafg commented 7 years ago

On ubuntu 14.04 (Semaphore Environment) there are also cri-o errors, which can be found here: https://semaphoreci.com/clearcontainers/tests/branches/pull-request-365/builds/1

On ubuntu 16.04 all tests passed correctly, including cri-o

amshinde commented 7 years ago

@chavafg I had been seeing similar issues locally on ubuntu 16.04 itself with q35 repo. crio tests had been passing with qemu-lite. Once, I made the switch to our agent, the issue was resolved.

So, qemu-lite seemed to manage mounts in a permissive manner that worked with hyperstart, but q35 didnt which was causing issues. cc-agent resolves this somehow. We do need to understand the exact root cause. But the combination of q35 repo with cc-agent has resolved the crio test failures.

@sboeuf can confirm for ubuntu 14.04 on semaphore CI.

sboeuf commented 7 years ago

@amshinde @chavafg Yes I confirm that I can reproduce the errors with Semaphore and q35-lite. And I also confirm that the new agent solves our issue here. We can maintain this issue opened after we switched to the new agent tomorrow. That way, even if we don't want to solve it right now (because it becomes low priority after we switched), we can still track it and take a look later.

chavafg commented 7 years ago

@sboeuf @amshinde Now with the new agent merged, re executed the cri-o tests, but still I am seeing the same failures.