Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

CI: extended_networking_minimal: unable to upload preserved contents #18794

Closed
sjenning opened this issue Mar 1, 2018 · 14 comments
Closed

CI: extended_networking_minimal: unable to upload preserved contents #18794

sjenning opened this issue Mar 1, 2018 · 14 comments
Assignees
@mrunalp @runcom
Labels
lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/P0

Comments

@sjenning
Copy link
Contributor

sjenning commented Mar 1, 2018

During extended_networking_minimal:

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18792/test_pull_request_origin_extended_networking_minimal/14936/

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18791/test_pull_request_origin_extended_networking_minimal/14935/

[openshift/dind] Created symlink /etc/systemd/system/systemd-udevd.service → /dev/null.
[openshift/dind] Created symlink /etc/systemd/system/systemd-vconsole-setup.service → /dev/null.
[openshift/dind] unable to upload preserved contents from /tmp/archived-path544299080 to /run/: API error (404): {"message":"Error processing tar file(exit status 1): chtimes /lock: no such file or directory"}
[ERROR] PID 16027: hack/dind-cluster.sh:56: `return "${result}"` exited with status 1.

and

[openshift/dind] Created symlink /etc/systemd/system/systemd-udevd.service → /dev/null.
[openshift/dind] Created symlink /etc/systemd/system/systemd-vconsole-setup.service → /dev/null.
[openshift/dind] unable to upload preserved contents from /tmp/archived-path060368074 to /run/: API error (404): {"message":"Error processing tar file(exit status 1): chmod /sepermit: no such file or directory"}
[ERROR] PID 15539: hack/dind-cluster.sh:56: `return "${result}"` exited with status 1.
@sjenning
Copy link
Contributor Author

sjenning commented Mar 1, 2018

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18652/test_pull_request_origin_extended_networking_minimal/14929/

@stevekuznetsov
Copy link
Contributor

/unassign
/asssign @marun @knobunc

@sjenning
Copy link
Contributor Author

sjenning commented Mar 1, 2018

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18791/test_pull_request_origin_extended_networking_minimal/14935/

@sjenning sjenning mentioned this issue Mar 1, 2018
Merged
@simonpasquier
Copy link
Contributor

https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/18734/test_pull_request_origin_extended_networking_minimal/14977/

@smarterclayton
Copy link
Contributor

openshift/release#638 temporarily disabled the job from being a blocker. We need to investigate and get resolution here.

@eparis
Copy link
Member

eparis commented Mar 2, 2018

can i have a BZ then?

@smarterclayton
Copy link
Contributor

I can't recreate it even on these boxes outside of the build. When this happens it's always after a large number of other builds complete. I wonder if that's related (device mapper cleaning things up in the background)

@smarterclayton
Copy link
Contributor

I can't reproduce it by running hack/build-images on the ec2 instance and then running the dind build back to back.

@smarterclayton
Copy link
Contributor

smarterclayton commented Mar 2, 2018 •
edited
Loading

A few things that "look" like device mapper errors from the last linked failed run

Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.104319097Z" level=debug msg="Calling GET /images/fedora:27/json"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.104389857Z" level=debug msg="Unable to determine container for fedora:27"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.104537015Z" level=debug msg="{Action=json, Username=origin, LoginUID=1001, PID=24991}"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.104566359Z" level=debug msg="AuthZ request using plugin rhel-push-plugin"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.105091856Z" level=error msg="Handler for GET /images/fedora:27/json returned error: No such image: fedora:27"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.105111544Z" level=debug msg="AuthZ response using plugin rhel-push-plugin"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.105404026Z" level=error msg="Handler for GET /images/fedora:27/json returned error: No such image: fedora:27"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.105957237Z" level=debug msg="Calling POST /images/create?fromImage=fedora&tag=27"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.106008683Z" level=debug msg="Unable to determine container for images"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.106116975Z" level=debug msg="{Action=create, Username=origin, LoginUID=1001, PID=24991}"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.106278653Z" level=debug msg="AuthZ request using plugin rhel-push-plugin"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.128854316Z" level=debug msg="hostDir: /etc/docker/certs.d/registry.access.redhat.com"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.140394550Z" level=debug msg="crt: /etc/docker/certs.d/registry.access.redhat.com/redhat-ca.crt"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.141006625Z" level=debug msg="hostDir: /etc/docker/certs.d/registry.access.redhat.com"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.151352842Z" level=debug msg="crt: /etc/docker/certs.d/registry.access.redhat.com/redhat-ca.crt"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.151700812Z" level=debug msg="Trying to pull registry.access.redhat.com/fedora from https://registry.access.redhat.com v2"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.763138866Z" level=error msg="Not continuing with pull after error: unknown: Not Found"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.763250226Z" level=debug msg="Trying to pull docker.io/fedora from https://registry-1.docker.io v2"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.894752389Z" level=debug msg="Pulling ref from V2 registry: docker.io/fedora:27"
Mar 02 11:15:40 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:40.989827266Z" level=debug msg="pulling blob \"sha256:a8ee583972c2295bb76704d4defe5116d5e4dd7ba3767aaa2cc8fcf71088ee06\""
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.928668361Z" level=debug msg="Downloaded a8ee583972c2 to tempfile /var/lib/docker/tmp/GetImageBlob803849943"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.928917920Z" level=debug msg="devmapper: AddDevice START(hash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6 basehash=)"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.928974666Z" level=debug msg="devmapper: Failed to read /var/lib/docker/devicemapper/metadata/ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6 with err: open /var/lib/docker/devicemapper/metadata/ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6: no such file or directory"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.932984090Z" level=debug msg="devmapper: registerDevice(130, ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.935259889Z" level=debug msg="devmapper: AddDevice END(hash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6 basehash=)"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.936176011Z" level=debug msg="devmapper: activateDeviceIfNeeded(ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.936196456Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded START(docker-202:2-96608165-ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:41 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:41.936229778Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded END(docker-202:2-96608165-ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:42 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:42.072455703Z" level=debug msg="Start untar layer"
Mar 02 11:15:47 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:47.217935068Z" level=debug msg="Untar time: 5.145472671s"
Mar 02 11:15:47 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:47.217980156Z" level=debug msg="devmapper: UnmountDevice START(hash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:47 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:47.217998483Z" level=debug msg="devmapper: Unmount(/var/lib/docker/devicemapper/mnt/ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.861100698Z" level=debug msg="devmapper: Unmount done"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.861190619Z" level=debug msg="devmapper: deactivateDevice START(ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.861259336Z" level=debug msg="devicemapper: RemoveDeviceDeferred START(docker-202:2-96608165-ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.870842046Z" level=debug msg="devicemapper: RemoveDeviceDeferred END(docker-202:2-96608165-ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.870865377Z" level=debug msg="devmapper: deactivateDevice END(ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.870878310Z" level=debug msg="devmapper: UnmountDevice END(hash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.870915605Z" level=debug msg="Applied tar sha256:d32459d9ce237564fb93573b85cbc707600d43fbe5e46e8eeef22cad914bb516 to ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6, size: 251669167"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.891105777Z" level=debug msg="AuthZ response using plugin rhel-push-plugin"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.892511706Z" level=debug msg="Calling GET /images/fedora:27/json"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.892563708Z" level=debug msg="Unable to determine container for fedora:27"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.892675644Z" level=debug msg="{Action=json, Username=origin, LoginUID=1001, PID=24991}"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.892694676Z" level=debug msg="AuthZ request using plugin rhel-push-plugin"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.894291454Z" level=debug msg="AuthZ response using plugin rhel-push-plugin"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.896101670Z" level=debug msg="Calling POST /containers/create?"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.896205563Z" level=debug msg="form data: {\"Cmd\":[\"sleep 86400\"],\"Entrypoint\":[\"/bin/sh\",\"-c\"],\"HostConfig\":{\"LogConfig\":{},\"MemorySwappiness\":0,\"RestartPolicy\":{}},\"Image\":\"fedora:27\"}"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.896233555Z" level=debug msg="Unable to determine container for containers"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.896322977Z" level=debug msg="{Action=create, Username=origin, LoginUID=1001, PID=24991}"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.896666946Z" level=debug msg="AuthZ request using plugin rhel-push-plugin"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.898685596Z" level=debug msg="devmapper: AddDevice START(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init basehash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.898728273Z" level=debug msg="devmapper: Failed to read /var/lib/docker/devicemapper/metadata/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init with err: open /var/lib/docker/devicemapper/metadata/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init: no such file or directory"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.902878281Z" level=debug msg="devmapper: registerDevice(131, da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.905247546Z" level=debug msg="devmapper: AddDevice END(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init basehash=ceeed5cdcf86a3aa3179bbda1c3160cf552f02d4d0cc800a05a187a94acc59f6)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.906065883Z" level=debug msg="devmapper: activateDeviceIfNeeded(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.906091863Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded START(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:49 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:49.906132125Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded END(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.037430746Z" level=debug msg="devmapper: UnmountDevice START(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.037458578Z" level=debug msg="devmapper: Unmount(/var/lib/docker/devicemapper/mnt/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.083197934Z" level=debug msg="devmapper: Unmount done"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.083246749Z" level=debug msg="devmapper: deactivateDevice START(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.083305020Z" level=debug msg="devicemapper: RemoveDeviceDeferred START(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.098906234Z" level=debug msg="devicemapper: RemoveDeviceDeferred END(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.098947503Z" level=debug msg="devmapper: deactivateDevice END(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.098966359Z" level=debug msg="devmapper: UnmountDevice END(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.098985898Z" level=debug msg="devmapper: AddDevice START(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e basehash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.099039391Z" level=debug msg="devmapper: Failed to read /var/lib/docker/devicemapper/metadata/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e with err: open /var/lib/docker/devicemapper/metadata/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e: no such file or directory"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.106421586Z" level=debug msg="devmapper: registerDevice(132, da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.108543036Z" level=debug msg="devmapper: AddDevice END(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e basehash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e-init)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.114982487Z" level=debug msg="devmapper: activateDeviceIfNeeded(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.115006096Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded START(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.115047842Z" level=debug msg="devmapper: cancelDeferredRemovalIfNeeded END(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.230587667Z" level=debug msg="container mounted via layerStore: /var/lib/docker/devicemapper/mnt/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e/rootfs"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.230624775Z" level=debug msg="devmapper: UnmountDevice START(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.230639991Z" level=debug msg="devmapper: Unmount(/var/lib/docker/devicemapper/mnt/da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.252162535Z" level=debug msg="devmapper: Unmount done"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.252215880Z" level=debug msg="devmapper: deactivateDevice START(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.252284576Z" level=debug msg="devicemapper: RemoveDeviceDeferred START(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.263840887Z" level=debug msg="devicemapper: RemoveDeviceDeferred END(docker-202:2-96608165-da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.263862231Z" level=debug msg="devmapper: deactivateDevice END(da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"
Mar 02 11:15:50 ip-172-18-14-24.ec2.internal dockerd-current[23742]: time="2018-03-02T11:15:50.263871367Z" level=debug msg="devmapper: UnmountDevice END(hash=da98ab82dfa1d9a2416b0d56d8c7087ff7dc853259061a2c7e615dfba7b07f7e)"

@runcom
Copy link
Member

runcom commented Mar 9, 2018

@nalind @rhvgoyal ^^^

@danwinship
Copy link
Contributor

danwinship commented Apr 3, 2018 •
edited
Loading

This is happening a lot in OSE (eg, https://ci.dev.openshift.redhat.com/jenkins/job/test_pull_request_ose_networking/306, https://ci.dev.openshift.redhat.com/jenkins/job/test_pull_request_ose_networking/303)

You should be able to reproduce it in origin master. Just make sure imagebuilder is installed, and repeatedly run

OS_BUILD_IMAGE_NUM_RETRIES=1 ./hack/dind-cluster.sh build-images

and it should fail within a few tries.

(@stevekuznetsov: possible workaround for OSE CI: don't install imagebuilder, let the scripts use docker build instead.)

@openshift-bot
Copy link
Contributor

Issues go stale after 90d of inactivity.

Mark the issue as fresh by commenting /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.
Exclude this issue from closing by commenting /lifecycle frozen.

If this issue is safe to close now please do so with /close.

/lifecycle stale

@openshift-ci-robot openshift-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Jul 2, 2018
@openshift-bot
Copy link
Contributor

Stale issues rot after 30d of inactivity.

Mark the issue as fresh by commenting /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.
Exclude this issue from closing by commenting /lifecycle frozen.

If this issue is safe to close now please do so with /close.

/lifecycle rotten
/remove-lifecycle stale

@openshift-ci-robot openshift-ci-robot added lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. and removed lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. labels Aug 1, 2018
@openshift-bot
Copy link
Contributor

Rotten issues close after 30d of inactivity.

Reopen the issue by commenting /reopen.
Mark the issue as fresh by commenting /remove-lifecycle rotten.
Exclude this issue from closing again by commenting /lifecycle frozen.

/close

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mrunalp mrunalp

@runcom runcom

Labels
lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/P0
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
10 participants
@mrunalp @danwinship @sjenning @runcom @smarterclayton @openshift-bot @simonpasquier @stevekuznetsov @eparis @openshift-ci-robot