SuccessConsole Output

Skipping 948 KB.. Full Log
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*manifestStore).Get" http.request.host="127.0.0.1:36277" http.request.id=6bf59594-43a0-4ba7-b2d8-589b1f7eceb3 http.request.method=GET http.request.remoteaddr="127.0.0.1:40508" http.request.uri="/v2/fuser/zapp/manifests/sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383" http.request.useragent=Go-http-client/1.1 vars.name=fuser/zapp vars.reference="sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/fuser/zapp/_manifests/revisions/sha256/f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383/link\")" http.request.host="127.0.0.1:36277" http.request.id=6bf59594-43a0-4ba7-b2d8-589b1f7eceb3 http.request.method=GET http.request.remoteaddr="127.0.0.1:40508" http.request.uri="/v2/fuser/zapp/manifests/sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383" http.request.useragent=Go-http-client/1.1 trace.duration="162.933µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=5e2ccee0-f47f-4253-955a-f91583d7e270 trace.line=82 vars.name=fuser/zapp vars.reference="sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Reader(\"/docker/registry/v2/blobs/sha256/f6/f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383/data\", 0)" http.request.host="127.0.0.1:36277" http.request.id=6bf59594-43a0-4ba7-b2d8-589b1f7eceb3 http.request.method=GET http.request.remoteaddr="127.0.0.1:40508" http.request.uri="/v2/fuser/zapp/manifests/sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383" http.request.useragent=Go-http-client/1.1 trace.duration="95.324µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Reader" trace.id=6fa713dc-fd34-412c-a5d8-4a262771f303 trace.line=107 vars.name=fuser/zapp vars.reference="sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*schema2ManifestHandler).Unmarshal" http.request.host="127.0.0.1:36277" http.request.id=6bf59594-43a0-4ba7-b2d8-589b1f7eceb3 http.request.method=GET http.request.remoteaddr="127.0.0.1:40508" http.request.uri="/v2/fuser/zapp/manifests/sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383" http.request.useragent=Go-http-client/1.1 vars.name=fuser/zapp vars.reference="sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="response completed" http.request.host="127.0.0.1:36277" http.request.id=6bf59594-43a0-4ba7-b2d8-589b1f7eceb3 http.request.method=GET http.request.remoteaddr="127.0.0.1:40508" http.request.uri="/v2/fuser/zapp/manifests/sha256:f664ee35ecfee30164f68639f7b7a67417dd0e03e4180c08976ad3447d34d383" http.request.useragent=Go-http-client/1.1 http.response.contenttype=application/vnd.docker.distribution.manifest.v2+json http.response.duration=9.341863ms http.response.status=200 http.response.written=731
    --- PASS: TestPullthroughManifestInsecure/pull_insecure_if_either_image_stream_is_insecure_or_the_tag (0.04s)
=== RUN   TestPullthroughManifestDockerReference
--- PASS: TestPullthroughManifestDockerReference (0.01s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/repo1\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/repo2\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/repo1\"] updated"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/repo2\"] updated"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).Get: starting with dgst=sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).remoteGet: starting with dgst=sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/repo1: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/repo1"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="(*cachedImageGetter).Get: got image sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6 from server"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: list user/...: err=no reaction implemented for {{user list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream repo1 { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="error getting secrets: error getting secrets for repository user/repo1: no reaction implemented for {{user list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream repo1 { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="error getting remote repository for image \"127.0.0.1:43351/repo/name:latest\": endpoint \"http://127.0.0.1:43351\" does not support v2 API"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).Get: starting with dgst=sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).remoteGet: starting with dgst=sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/repo2: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/repo2"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="(*cachedImageGetter).Get: got image sha256:7c23c7303f0fcdcbd55db6aae8ca3835e693b927d2bdc51c8678bb38920ce9a6 from server"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: list user/...: err=no reaction implemented for {{user list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream repo2 { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="error getting secrets: error getting secrets for repository user/repo2: no reaction implemented for {{user list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream repo2 { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="error getting remote repository for image \"127.0.0.1:45102/foo/bar:latest\": endpoint \"http://127.0.0.1:45102\" does not support v2 API"
=== RUN   TestPullthroughManifestMirroring
--- PASS: TestPullthroughManifestMirroring (0.01s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"myproject/myapp\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"myproject/myapp\"] updated"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).Get: starting with dgst=sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughManifestService).remoteGet: starting with dgst=sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get myproject/myapp: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream myproject/myapp"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="(*cachedImageGetter).Get: got image sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0 from server"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: list myproject/...: err=no reaction implemented for {{myproject list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream myapp { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="error getting secrets: error getting secrets for repository myproject/myapp: no reaction implemented for {{myproject list {image.openshift.io v1 imagestreams} secrets} image.openshift.io/v1, Kind=ImageStream myapp { }}"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="failed to mirror manifest 127.0.0.1:40970/remoteimage:latest: put aborted"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="cannot remember layers of image sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0: manifest is not present in image object sha256:74650f9ea72d624d418435f57b997feec86725c0dccb55d3c9e96d6b8d0669b0 (mediatype=\"\")"
=== RUN   TestRepositoryBlobStat
=== RUN   TestRepositoryBlobStat/local_stat
=== RUN   TestRepositoryBlobStat/blob_only_tagged_in_image_stream
=== RUN   TestRepositoryBlobStat/blob_referenced_only_by_not_managed_image_with_pullthrough_on
=== RUN   TestRepositoryBlobStat/layer_link_present_while_image_stream_not_found
=== RUN   TestRepositoryBlobStat/blob_only_tagged_by_not_managed_image_with_pullthrough_off
=== RUN   TestRepositoryBlobStat/blob_not_stored_locally_but_referred_in_image_stream
=== RUN   TestRepositoryBlobStat/blob_does_not_exist
=== RUN   TestRepositoryBlobStat/auth_not_performed
=== RUN   TestRepositoryBlobStat/deferred_error
--- PASS: TestRepositoryBlobStat (0.06s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/startedat\")" trace.duration="167.377µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=13d71bcf-b76d-4383-bdcd-54e716cadcd1 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/data\", false)" trace.duration="113.216µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=3224bbdc-9f34-4ebb-9473-43ff7463017d trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo:missing-layer-links/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/hashstates/sha256/4096\")" trace.duration="77.711µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=cbe057e2-2094-4e76-b424-201eb8d3308b trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/data\")" trace.duration="82.349µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=1c1bc368-3a37-45b2-a2f1-02de03a1131d trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/76/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b/data\")" trace.duration="80.872µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=fb24275a-751d-4304-a649-2a73718a7dc5 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/data\")" trace.duration="109.248µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=33ac094f-a8f5-4b79-9ee0-9ce71f675190 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf/data\", \"/docker/registry/v2/blobs/sha256/76/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b/data\"" trace.duration="188.807µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=cbba8137-1fbb-4aa4-9850-ab55d2f4c4c3 trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b/link\")" trace.duration="148.964µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=61720faf-09be-4a5f-8b8c-83006ffe129b trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/repo/_uploads/0498e6b2-1ed7-485b-95d1-9b113e917bbf\")" trace.duration="80.013µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=1bf24477-70fb-461f-b45e-3487ba64d459 trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/startedat\")" trace.duration="116.872µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=031184e7-71b6-4c16-a8b0-78f5fbefda89 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/data\", false)" trace.duration="100.203µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=6e9896f1-2312-4f77-91a6-0d9e1bdcefe3 trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo:missing-layer-links/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/hashstates/sha256/4096\")" trace.duration="41.832µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=f9afdafb-5bc9-4ebf-b0e8-06b0f87a4d79 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/data\")" trace.duration="96.598µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=ea249848-e686-496a-a04a-769f31177e4c trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/6a/6a9084e0590c635b75b45a9ef9147eb838d36341c829b1b26a8545d3dfd6de78/data\")" trace.duration="82.862µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=1f3a6a4d-b56f-4fe9-9204-d193d1982abb trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/data\")" trace.duration="112.024µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=fb8aa6db-1945-4ab8-9365-4974d05d4e58 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af/data\", \"/docker/registry/v2/blobs/sha256/6a/6a9084e0590c635b75b45a9ef9147eb838d36341c829b1b26a8545d3dfd6de78/data\"" trace.duration="180.984µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=6004ddad-b964-416d-998d-72fdff03ab7a trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/6a9084e0590c635b75b45a9ef9147eb838d36341c829b1b26a8545d3dfd6de78/link\")" trace.duration="137.54µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=ce426571-1d75-4675-a9cf-fe6138d255e4 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/repo/_uploads/27c64490-35ef-4b1a-9c2d-daec23b818af\")" trace.duration="79.485µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=689eec9b-ef62-4416-8067-50c8e96b23c3 trace.line=177
	repository_test.go:675: created image nm/repo@sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504 image with layers:
	repository_test.go:677:   sha256:6a9084e0590c635b75b45a9ef9147eb838d36341c829b1b26a8545d3dfd6de78 of size 4096
	repository_test.go:677:   sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b of size 4096
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/startedat\")" trace.duration="126.913µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=1d2b5254-1272-494f-aef1-4049d4154728 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/data\", false)" trace.duration="115.964µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=03d2c0c6-be0e-422f-a5ec-796854566d5b trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is:latest/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/hashstates/sha256/4096\")" trace.duration="40.105µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=722c0583-16b3-4079-8531-cf54af9a78bb trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/data\")" trace.duration="97.411µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=ecc6a432-accd-4c01-9b59-33de3e84f295 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/b7/b78c3b760ca0021d9dde2d915304cbe32e3b9c173ddb1440a19c82f93ccfc88e/data\")" trace.duration="87.515µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=334ca5f2-8a3a-44de-8dde-35af2cb641f2 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/data\")" trace.duration="79.511µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=76d8d8fe-9f54-4019-977d-44a7135e482a trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357/data\", \"/docker/registry/v2/blobs/sha256/b7/b78c3b760ca0021d9dde2d915304cbe32e3b9c173ddb1440a19c82f93ccfc88e/data\"" trace.duration="196.647µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=72d60a19-43b7-474e-b62c-25238e74b2cb trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b78c3b760ca0021d9dde2d915304cbe32e3b9c173ddb1440a19c82f93ccfc88e/link\")" trace.duration="147.212µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=cf18e31d-ec13-4e38-9559-396ed5badedb trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_uploads/4b7ed80a-fa4e-4c48-b5e2-6065f28cd357\")" trace.duration="82.592µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=d38145fa-756d-4941-99fd-9ed81d51bef3 trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/startedat\")" trace.duration="115.891µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=4241d0bb-601e-49a6-8f64-a3b278f2a5b5 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/data\", false)" trace.duration="119.342µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=d07258b3-273f-4fd0-90ee-80484e71e5ad trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is:latest/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/hashstates/sha256/4096\")" trace.duration="39.824µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=239bb76b-3404-44cb-9316-e7d128a75d42 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/data\")" trace.duration="78.558µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=e9ed145f-18c3-422f-8715-61c198826bc4 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/59/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/data\")" trace.duration="81.877µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=343e1aea-abce-4fe7-8113-5a91877172cf trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/data\")" trace.duration="77.364µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=763bfc33-c1a4-481f-8b25-410e9d9e5970 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7/data\", \"/docker/registry/v2/blobs/sha256/59/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/data\"" trace.duration="191.584µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=2e1ecc40-babe-4fe5-b6e1-bccc488315ea trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/link\")" trace.duration="135.858µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=4f026780-5d33-47bc-91b5-70669e765bf7 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_uploads/606aad25-4526-4ebd-b0d4-c4a61128eef7\")" trace.duration="76.446µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=0b51c93d-3ee3-4114-94f5-5215239db50c trace.line=177
	repository_test.go:675: created image nm/is@sha256:b99c6f34509187d48d8eb8dcf6607a244d86e978cbcb574616d631aa1e713087 image with layers:
	repository_test.go:677:   sha256:5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d of size 4096
	repository_test.go:677:   sha256:b78c3b760ca0021d9dde2d915304cbe32e3b9c173ddb1440a19c82f93ccfc88e of size 4096
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/startedat\")" trace.duration="133.838µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=9df5a32b-9342-40d2-982c-16656116b1d0 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/data\", false)" trace.duration="104.694µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=70a39988-2e72-45be-a68e-0adaad79c5eb trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged:missing-layer-links/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/hashstates/sha256/4096\")" trace.duration="44.508µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=c90f0a62-054a-486c-8f3f-9c88d41eb657 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/data\")" trace.duration="86.981µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=6d9f99ca-b600-4cdd-a713-e1509ff2273f trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/54/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/data\")" trace.duration="82.447µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=79f6ec49-e073-4df6-8c95-9eaef0578431 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/data\")" trace.duration="82.513µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=15d35c31-ad20-4d7d-a82d-263614300948 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7/data\", \"/docker/registry/v2/blobs/sha256/54/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/data\"" trace.duration="177.516µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=6cd5f017-1529-4956-86dd-6e9d0ff74f49 trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged/_layers/sha256/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/link\")" trace.duration="173.634µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=601d0c9c-bcec-4eff-9b1a-18eeb368bedf trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/df7c61a1-7243-435e-8ba7-e335176088f7\")" trace.duration="81.003µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=b9de4a63-f0e3-4efe-a931-83e48898d388 trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/startedat\")" trace.duration="156.119µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=09236db3-629e-48fe-8d75-be836339ef37 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/data\", false)" trace.duration="102.062µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=6dceb0a1-5b24-46d7-9456-c11343c9c70d trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged:missing-layer-links/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/hashstates/sha256/4096\")" trace.duration="74.85µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=e28d059b-27e0-4dd3-84e5-4d301c4544da trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/data\")" trace.duration="82.557µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=2cfddf89-58fd-457a-b28a-074a56b9b5e0 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/fc/fcbe824d788da1222a6a955564da8d1d676421df671193e7054b4dbaae7b4365/data\")" trace.duration="82.514µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=8da9aa55-3846-42b7-9ac4-474e3d049a31 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/data\")" trace.duration="106.55µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=dcf74fd5-1cd0-4f77-ae37-9986377a79be trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854/data\", \"/docker/registry/v2/blobs/sha256/fc/fcbe824d788da1222a6a955564da8d1d676421df671193e7054b4dbaae7b4365/data\"" trace.duration="181.564µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=487a406c-4377-443e-8356-f1eb06bbdad5 trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/unmanaged/_layers/sha256/fcbe824d788da1222a6a955564da8d1d676421df671193e7054b4dbaae7b4365/link\")" trace.duration="139.156µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=39d95cd8-51b5-41c5-a25e-bcae22e0d860 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/unmanaged/_uploads/262b3cef-571b-42e4-ad35-d57f65275854\")" trace.duration="81.746µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=b79020fc-336a-45d1-87d3-d97660b3c6ad trace.line=177
	repository_test.go:675: created image nm/unmanaged@sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979 image with layers:
	repository_test.go:677:   sha256:fcbe824d788da1222a6a955564da8d1d676421df671193e7054b4dbaae7b4365 of size 4096
	repository_test.go:677:   sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 of size 4096
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/6a9084e0590c635b75b45a9ef9147eb838d36341c829b1b26a8545d3dfd6de78\")" trace.duration="102.337µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=ed2ab6a7-a3bc-4eca-88b4-c7ba0364602b trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b\")" trace.duration="96.124µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=577efed6-7da5-43d7-a023-673fad6634bf trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/unmanaged/_layers/sha256/fcbe824d788da1222a6a955564da8d1d676421df671193e7054b4dbaae7b4365\")" trace.duration="99.885µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=17cdc286-af40-412d-81be-2141a48f5ba5 trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/unmanaged/_layers/sha256/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\")" trace.duration="105.746µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=6762c8d2-df43-4c20-87ba-2827ea8b78df trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/link\")" trace.duration="134.7µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=d961ed21-65fc-48c5-837b-51ad9890d551 trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/59/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/data\")" trace.duration="160.912µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=a2295a58-d531-4026-9375-cec5470eaa81 trace.line=137
    --- PASS: TestRepositoryBlobStat/local_stat (0.01s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/repo\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b/link\")" trace.duration="180.706µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=e76861d1-b856-4acd-ac1c-1e6b805f6f2f trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b in repository nm/repo: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/76/7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b/data\")" trace.duration="118.383µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=9a13698f-43e9-4b46-a8c8-3b9d86a4be7c trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="verifying presence of blob \"sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b\" in image stream nm/repo"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get nm/repo: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream nm/repo"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="getting image sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="(*cachedImageGetter).Get: got image sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504 from server"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="blob found under istag nm/repo:latest in image sha256:9a3d2eda26edea44fee6a64a0ad2c030ffe89eac9d4ff79be83ede11c43c6504"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="verified presence of blob \"sha256:7683bd72f9ea5d2161e948ad81237f8aa1661ebbdcd0685065c9380c0464594b\" in image stream nm/repo after 629.254µs"
    --- PASS: TestRepositoryBlobStat/blob_only_tagged_in_image_stream (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/unmanaged\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*pullthroughBlobStore).Stat: starting with dgst=sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/unmanaged/_layers/sha256/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/link\")" trace.duration="126.4µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=a1d2065f-911a-49b0-942a-57357495eb7b trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 in repository nm/unmanaged: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/54/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/data\")" trace.duration="114.547µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=8aff0a61-703c-4a0b-8263-1c93b951584f trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="verifying presence of blob \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" in image stream nm/unmanaged"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get nm/unmanaged: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream nm/unmanaged"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="getting image sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="(*cachedImageGetter).Get: got image sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979 from server"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="blob found under istag nm/unmanaged:latest in image sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="verified presence of blob \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" in image stream nm/unmanaged after 624.892µs"
    --- PASS: TestRepositoryBlobStat/blob_referenced_only_by_not_managed_image_with_pullthrough_on (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:b99c6f34509187d48d8eb8dcf6607a244d86e978cbcb574616d631aa1e713087\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/link\")" trace.duration="144.768µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=3990b0f9-caff-4c0a-a8e9-1c4b7b01d08d trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/59/5971eb25bcc5c8d6750355d5d02f6785d015dc6b1018c14f8835cd81263b8d2d/data\")" trace.duration="112.366µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=80091d0f-0489-455f-b637-12e77cb71c6b trace.line=137
    --- PASS: TestRepositoryBlobStat/layer_link_present_while_image_stream_not_found (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/repo\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:595b28f8add75521d467229ac215884d6ed5dcb4ab308a063048ee6e8e59c979\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/link\")" trace.duration="115.201µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=7f513b5b-2635-4ab0-9dba-1406ab1ee737 trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 in repository nm/repo: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/54/545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290/data\")" trace.duration="109.799µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=b4885891-038a-44df-ae11-b0330089a530 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="verifying presence of blob \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" in image stream nm/repo"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get nm/repo: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream nm/repo"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="getting image sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290: err=images.image.openshift.io \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" not found"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="failed to get image sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290: images.image.openshift.io \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" not found"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=error msg="failed to get image: unknown manifest name=repo revision=sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=warning msg="blob \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" exists locally but is not referenced in repository nm/repo"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="detected absence of blob \"sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290\" in image stream nm/repo after 712.12µs"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:545a57a612f23c5e7f36a0fb66ecb04512857988fc892b68beb082dedc7fc290 is neither empty nor referenced in image stream nm/repo"
    --- PASS: TestRepositoryBlobStat/blob_only_tagged_by_not_managed_image_with_pullthrough_off (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:b2c5513bd934a7efb412c0dd965600b8cb00575b585eaff1cb980b69037fe6cd"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b2c5513bd934a7efb412c0dd965600b8cb00575b585eaff1cb980b69037fe6cd/link\")" trace.duration="113.609µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=23290392-ba0a-41a6-831d-1893c9f1976b trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:b2c5513bd934a7efb412c0dd965600b8cb00575b585eaff1cb980b69037fe6cd in repository nm/is: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/b2/b2c5513bd934a7efb412c0dd965600b8cb00575b585eaff1cb980b69037fe6cd/data\")" trace.duration="94.67µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=65a1990d-4ac8-4cb6-8155-e09e8f36cb97 trace.line=137
    --- PASS: TestRepositoryBlobStat/blob_not_stored_locally_but_referred_in_image_stream (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/repo\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).images[\"sha256:b99c6f34509187d48d8eb8dcf6607a244d86e978cbcb574616d631aa1e713087\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:2dde6f11a89463bf20dba3b47d8b3b6de7cdcc19e50634e95a18dd95c278768d"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/repo/_layers/sha256/2dde6f11a89463bf20dba3b47d8b3b6de7cdcc19e50634e95a18dd95c278768d/link\")" trace.duration="120.904µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=bf9a344b-5872-4ac4-b5c0-2bad6914902c trace.line=82
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:2dde6f11a89463bf20dba3b47d8b3b6de7cdcc19e50634e95a18dd95c278768d in repository nm/repo: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/2d/2dde6f11a89463bf20dba3b47d8b3b6de7cdcc19e50634e95a18dd95c278768d/data\")" trace.duration="126.794µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=fda98388-5cfe-4cf5-8034-5d6c93db68c7 trace.line=137
    --- PASS: TestRepositoryBlobStat/blob_does_not_exist (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
    --- PASS: TestRepositoryBlobStat/auth_not_performed (0.00s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] created"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="Origin auth: found deferred error for nm/is: access denied"
    --- PASS: TestRepositoryBlobStat/deferred_error (0.00s)
=== RUN   TestRepositoryBlobStatCacheEviction
--- PASS: TestRepositoryBlobStatCacheEviction (0.52s)
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/startedat\")" trace.duration="159.073µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=5a97983a-63e9-4ea1-bc75-cfac44813fbe trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/data\", false)" trace.duration="133.596µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=cbfdcec2-f4cf-4420-b942-6fd7e74657ff trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is:latest/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/hashstates/sha256/4096\")" trace.duration="43.358µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=b743221d-f11e-4c27-a483-ff1f6a255a89 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/data\")" trace.duration="117.297µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=9b65fce5-47ce-4449-af24-23af4fef1bab trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/data\")" trace.duration="82.556µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=16140b93-b086-4341-b4c9-4884a9f04d64 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/data\")" trace.duration="77.255µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=948c362e-3d60-44c0-a5dd-2e8fd3b9d57d trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b/data\", \"/docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/data\"" trace.duration="236.136µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=54c4c21d-c274-4d62-9fee-a1827e1dd116 trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/link\")" trace.duration="145.749µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=438cc2c7-da13-4a82-a973-921fd102c277 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_uploads/77852810-b968-4e73-92bd-1555cd364b7b\")" trace.duration="103.796µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=f8a001c4-2686-441a-8dd8-abb93553ea9d trace.line=177
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*linkedBlobStore).Writer"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/startedat\")" trace.duration="113.677µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=b53f235e-ca74-4c4d-a1d9-e26481c50696 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Writer(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/data\", false)" trace.duration="141.551µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Writer" trace.id=4adef8c9-8a41-4804-8d89-57c2f6b02c82 trace.line=124
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="(*blobWriter).Commit"
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is:latest/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/hashstates/sha256/4096\")" trace.duration="39.889µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=5b4de762-bf37-45a3-a6b7-190a6b277eb3 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/data\")" trace.duration="79.032µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=e56b707d-0f37-4afb-add8-e64791b62cea trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/b3/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/data\")" trace.duration="82.919µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=be29fea5-8e2c-4a43-a5e5-d6166afef6fa trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/data\")" trace.duration="78.775µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=39262b26-ca1a-44e9-a9d7-1d8ad568e4f8 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Move(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef/data\", \"/docker/registry/v2/blobs/sha256/b3/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/data\"" trace.duration="196.08µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Move" trace.id=885e8b74-3152-4240-b347-0239f3fd1d54 trace.line=163
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.PutContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/link\")" trace.duration="147.998µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=9e2c2795-652b-430a-b3d8-d7af30f75aa6 trace.line=95
	logrus.go:28: time="2018-05-21T13:08:34Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_uploads/b5dc45db-e2aa-4b75-b389-f0f92f89d9ef\")" trace.duration="80.476µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=5b765079-1d86-4a1f-915d-5a27a153656f trace.line=177
	repository_test.go:675: created image nm/is@sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea image with layers:
	repository_test.go:677:   sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e of size 4096
	repository_test.go:677:   sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a of size 4096
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a\")" trace.duration="144.107µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=725832b5-b65e-4168-a62a-d0a366d69d6a trace.line=177
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"nm/is\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/link\")" trace.duration="107.3µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=8eb94f80-b5e0-4ef1-a013-23b39b0b16ea trace.line=82
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/b3/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/data\")" trace.duration="84.054µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=b9d7fc17-6a3e-486c-95db-2332edb25043 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/link\")" trace.duration="128.39µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=26a7032a-bde7-4386-8f30-ad52571f6516 trace.line=177
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e/link\")" trace.duration="123.823µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=f227b1a7-98a0-43d6-a4bc-b55fe5751ae4 trace.line=82
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e in repository nm/is: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="verifying presence of blob \"sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e\" in image stream nm/is"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get nm/is: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream nm/is"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="getting image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="blob found under istag nm/is:latest in image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="verified presence of blob \"sha256:b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e\" in image stream nm/is after 600.381µs"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/b3/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/blobs/sha256/b3/b37460b4bbe94760d233a3b3cc5a40f7e12cd6996c57a85ff084d1bb0fb2db9e\")" trace.duration="88.858µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=7bee2faa-116a-496e-acfe-88cea647120c trace.line=177
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/link\")" trace.duration="97.526µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=5bf166f9-8d86-4bcc-bb40-7b9a9a0d525e trace.line=82
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a in repository nm/is: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/data\")" trace.duration="115.764µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=2e4b923d-abf1-43fe-b934-e4a8b946baeb trace.line=137
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="found cached blob \"sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a\" in repository nm/is"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a"
	repository_test.go:476: sleeping 500ms while waiting for eviction of blob "sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a" from cache
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: starting with digest=sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.GetContent(\"/docker/registry/v2/repositories/nm/is/_layers/sha256/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/link\")" trace.duration="181.063µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).GetContent" trace.id=2ba2ffc4-b028-4508-bb45-41880505cf97 trace.line=82
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: could not stat layer link sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a in repository nm/is: unknown blob"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Stat(\"/docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a/data\")" trace.duration="151.617µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=01b14218-cada-4609-8151-b7e4193fc2a8 trace.line=137
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*blobDescriptorService).Stat: blob sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a exists in the global blob store"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="verifying presence of blob \"sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a\" in image stream nm/is"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get nm/is: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream nm/is"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="getting image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="blob found under istag nm/is:latest in image sha256:21dd54cb2ca4db47e7e25a21c21520539060505c083eb4875ac9188be934f9ea"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="verified presence of blob \"sha256:0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a\" in image stream nm/is after 968.222µs"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="inmemory.Delete(\"/docker/registry/v2/blobs/sha256/06/0665b67562d21a0f9dc78d7d17e7cc6663a663f6a8a83d6266abd2cbe636126a\")" trace.duration="133.816µs" trace.file=/go/src/github.com/openshift/image-registry/_output/local/go/src/github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base/base.go trace.func="github.com/openshift/image-registry/vendor/github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=4f6fcfdb-749a-4b9f-bd97-44568808dd2d trace.line=177
=== RUN   TestSignatureGet
--- PASS: TestSignatureGet (0.03s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="quota enforcement disabled"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=warning msg="No HTTP secret provided - generated random secret. This may cause problems with uploads if multiple registries are behind a load-balancer. To provide a shared secret, fill in http.secret in the configuration file or set the REGISTRY_HTTP_SECRET environment variable."
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="redis not configured"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="using inmemory blob descriptor cache"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="configured \"openshift\" access controller"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="configured token endpoint at \"/openshift/token\""
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="authorizing request" http.request.host="127.0.0.1:42640" http.request.id=586cee17-8891-4bd5-b39c-3e75c1761ea7 http.request.method=GET http.request.remoteaddr="127.0.0.1:48550" http.request.uri="/extensions/v2/user/app/signatures/sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b" http.request.useragent=Go-http-client/1.1 vars.digest="sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b" vars.name=user/app
	blobdescriptorservice_test.go:414: fake authorizer: authorizing access to signature:user/app:get
	blobdescriptorservice_test.go:414: fake authorizer: authorizing access to repository:user/app:pull
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*signatureHandler).Get" http.request.host="127.0.0.1:42640" http.request.id=586cee17-8891-4bd5-b39c-3e75c1761ea7 http.request.method=GET http.request.remoteaddr="127.0.0.1:48550" http.request.uri="/extensions/v2/user/app/signatures/sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b" http.request.useragent=Go-http-client/1.1 vars.digest="sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b" vars.name=user/app
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamImagesHandler: get user/app@sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="response completed" http.request.host="127.0.0.1:42640" http.request.id=586cee17-8891-4bd5-b39c-3e75c1761ea7 http.request.method=GET http.request.remoteaddr="127.0.0.1:48550" http.request.uri="/extensions/v2/user/app/signatures/sha256:bff08d8da5a030fc39fdfcddd533fac4bc76d877d1a33bc336f8115e18d9081b" http.request.useragent=Go-http-client/1.1 http.response.contenttype="application/json; charset=utf-8" http.response.duration=12.401613ms http.response.status=200 http.response.written=579
=== RUN   TestSignaturePut
--- PASS: TestSignaturePut (0.02s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="quota enforcement disabled"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=warning msg="No HTTP secret provided - generated random secret. This may cause problems with uploads if multiple registries are behind a load-balancer. To provide a shared secret, fill in http.secret in the configuration file or set the REGISTRY_HTTP_SECRET environment variable."
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="redis not configured"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="using inmemory blob descriptor cache"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="configured \"openshift\" access controller"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="configured token endpoint at \"/openshift/token\""
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="authorizing request" http.request.host="127.0.0.1:35954" http.request.id=262c6c35-6cd9-4129-a5b7-9d94aa81f8e9 http.request.method=PUT http.request.remoteaddr="127.0.0.1:57218" http.request.uri="/extensions/v2/user/app/signatures/sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" http.request.useragent=Go-http-client/1.1 vars.digest="sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" vars.name=user/app
	blobdescriptorservice_test.go:414: fake authorizer: authorizing access to signature:user/app:put
	blobdescriptorservice_test.go:414: fake authorizer: authorizing access to repository:user/app:pull
	blobdescriptorservice_test.go:414: fake authorizer: authorizing access to repository:user/app:push
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="Using \"localhost:5000\" as Docker Registry URL"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*signatureHandler).Put" http.request.host="127.0.0.1:35954" http.request.id=262c6c35-6cd9-4129-a5b7-9d94aa81f8e9 http.request.method=PUT http.request.remoteaddr="127.0.0.1:57218" http.request.uri="/extensions/v2/user/app/signatures/sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" http.request.useragent=Go-http-client/1.1 vars.digest="sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" vars.name=user/app
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*signatureHandler).Put signature successfully added to user/app@sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" http.request.host="127.0.0.1:35954" http.request.id=262c6c35-6cd9-4129-a5b7-9d94aa81f8e9 http.request.method=PUT http.request.remoteaddr="127.0.0.1:57218" http.request.uri="/extensions/v2/user/app/signatures/sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" http.request.useragent=Go-http-client/1.1 vars.digest="sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" vars.name=user/app
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="response completed" http.request.host="127.0.0.1:35954" http.request.id=262c6c35-6cd9-4129-a5b7-9d94aa81f8e9 http.request.method=PUT http.request.remoteaddr="127.0.0.1:57218" http.request.uri="/extensions/v2/user/app/signatures/sha256:958608f8ecc1dc62c93b6c610f3a834dae4220c9642e6e8b4e0f2b3ad7cbd238" http.request.useragent=Go-http-client/1.1 http.response.duration=7.663665ms http.response.status=201 http.response.written=0
=== RUN   TestTagGet
--- PASS: TestTagGet (0.01s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:599dd4226cce366723eec348793712dd86bd416c19fd48c30cdfdf21ab92f377\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:599dd4226cce366723eec348793712dd86bd416c19fd48c30cdfdf21ab92f377: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:599dd4226cce366723eec348793712dd86bd416c19fd48c30cdfdf21ab92f377 from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:599dd4226cce366723eec348793712dd86bd416c19fd48c30cdfdf21ab92f377: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:599dd4226cce366723eec348793712dd86bd416c19fd48c30cdfdf21ab92f377 from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
=== RUN   TestTagGetWithoutImageStream
--- PASS: TestTagGetWithoutImageStream (0.00s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=imagestreams.image.openshift.io \"app\" not found"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=error msg="failed to get image stream: imagestreams.image.openshift.io \"app\" not found"
=== RUN   TestTagGetAll
--- PASS: TestTagGetAll (0.01s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:3c49f8bdd301ec3c0ced9ceb65d331d167e519612d648355e105dbe635d2dcc6\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:3c49f8bdd301ec3c0ced9ceb65d331d167e519612d648355e105dbe635d2dcc6: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:3c49f8bdd301ec3c0ced9ceb65d331d167e519612d648355e105dbe635d2dcc6 from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:3c49f8bdd301ec3c0ced9ceb65d331d167e519612d648355e105dbe635d2dcc6: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:3c49f8bdd301ec3c0ced9ceb65d331d167e519612d648355e105dbe635d2dcc6 from server"
=== RUN   TestTagGetAllWithoutImageStream
--- PASS: TestTagGetAllWithoutImageStream (0.00s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=imagestreams.image.openshift.io \"app\" not found"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=error msg="failed to get image stream: imagestreams.image.openshift.io \"app\" not found"
=== RUN   TestTagLookup
--- PASS: TestTagLookup (0.01s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:76dd00b6c8369a640bda0ad817a39a26ded621cc8356887086d49a3c7c1020fe\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:76dd00b6c8369a640bda0ad817a39a26ded621cc8356887086d49a3c7c1020fe: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:76dd00b6c8369a640bda0ad817a39a26ded621cc8356887086d49a3c7c1020fe from server"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: got image stream user/app"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*cachedImageStreamGetter).getImageStream: returning cached copy"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imagesHandler: get sha256:76dd00b6c8369a640bda0ad817a39a26ded621cc8356887086d49a3c7c1020fe: err=<nil>"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=info msg="(*cachedImageGetter).Get: got image sha256:76dd00b6c8369a640bda0ad817a39a26ded621cc8356887086d49a3c7c1020fe from server"
=== RUN   TestTagLookupWithoutImageStream
--- PASS: TestTagLookupWithoutImageStream (0.00s)
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app-another\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).images[\"sha256:9c4120e83317fd9b795bb5b58a09f605959fdd434b4717c4a2a925f834712200\"] created"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreams[\"user/app-another\"] updated"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=debug msg="(*FakeOpenShift).imageStreamsHandler: get user/app: err=imagestreams.image.openshift.io \"app\" not found"
	logrus.go:28: time="2018-05-21T13:08:35Z" level=error msg="failed to get image stream: imagestreams.image.openshift.io \"app\" not found"
PASS
coverage: 59.4% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server	6.823s	coverage: 59.4% of statements
=== RUN   TestSimpleScope
--- PASS: TestSimpleScope (0.00s)
=== RUN   TestScopeWithClass
--- PASS: TestScopeWithClass (0.00s)
=== RUN   TestMultiScopes
--- PASS: TestMultiScopes (0.00s)
=== RUN   TestInvalidScope
time="2018-05-21T13:08:25Z" level=info msg="ignoring unsupported scope format repository" go.version=go1.8.3 instance.id=7cd54bd8-4884-43af-9307-f8acda2b1482 
time="2018-05-21T13:08:25Z" level=info msg="ignoring unsupported scope format repository:namespace/name" go.version=go1.8.3 instance.id=7cd54bd8-4884-43af-9307-f8acda2b1482 
time="2018-05-21T13:08:25Z" level=info msg="ignoring unsupported scope format repository:namespace/name:pull:push:get:put:read:write" go.version=go1.8.3 instance.id=7cd54bd8-4884-43af-9307-f8acda2b1482 
--- PASS: TestInvalidScope (0.00s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/auth	1.079s	coverage: 100.0% of statements
=== RUN   TestRepositoryScopedBlobDescriptor
--- PASS: TestRepositoryScopedBlobDescriptor (0.00s)
=== RUN   TestRepositoryScopedBlobDescriptorFail
--- PASS: TestRepositoryScopedBlobDescriptorFail (0.00s)
=== RUN   TestRepositoryScopedBlobDescriptorClear
--- PASS: TestRepositoryScopedBlobDescriptorClear (0.00s)
=== RUN   TestRepositoryScopedBlobDescriptorAdd
--- PASS: TestRepositoryScopedBlobDescriptorAdd (0.00s)
=== RUN   TestBlobStatter
--- PASS: TestBlobStatter (0.00s)
=== RUN   TestBlobStatterFail
--- PASS: TestBlobStatterFail (0.00s)
=== RUN   TestDigestCacheAddDigest
--- PASS: TestDigestCacheAddDigest (0.00s)
=== RUN   TestDigestCacheRemoveDigest
--- PASS: TestDigestCacheRemoveDigest (0.00s)
=== RUN   TestDigestCacheAddRepository
--- PASS: TestDigestCacheAddRepository (0.00s)
=== RUN   TestDigestCacheRemoveRepository
--- PASS: TestDigestCacheRemoveRepository (0.00s)
=== RUN   TestDigestCacheInvalidDigest
--- PASS: TestDigestCacheInvalidDigest (0.00s)
=== RUN   TestDigestCachePurge
--- PASS: TestDigestCachePurge (0.00s)
=== RUN   TestDigestCacheDigestMigration
--- PASS: TestDigestCacheDigestMigration (0.00s)
=== RUN   TestRepoDigest
--- PASS: TestRepoDigest (0.00s)
=== RUN   TestRepoDigestRemove
--- PASS: TestRepoDigestRemove (0.00s)
PASS
coverage: 86.3% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/cache	1.059s	coverage: 86.3% of statements
=== RUN   TestConfigurationParser
--- PASS: TestConfigurationParser (0.01s)
=== RUN   TestConfigurationOverwriteEnv
--- PASS: TestConfigurationOverwriteEnv (0.00s)
=== RUN   TestConfigurationWithEmptyOpenshiftOverwriteEnv
--- PASS: TestConfigurationWithEmptyOpenshiftOverwriteEnv (0.00s)
=== RUN   TestDockerConfigurationError
--- PASS: TestDockerConfigurationError (0.00s)
=== RUN   TestExtraConfigurationError
--- PASS: TestExtraConfigurationError (0.00s)
=== RUN   TestEmptyExtraConfigurationError
--- PASS: TestEmptyExtraConfigurationError (0.00s)
=== RUN   TestExtraConfigurationVersionError
--- PASS: TestExtraConfigurationVersionError (0.00s)
=== RUN   TestDefaultMiddleware
--- PASS: TestDefaultMiddleware (0.02s)
=== RUN   TestMiddlewareMigration
--- PASS: TestMiddlewareMigration (0.02s)
=== RUN   TestServerAddrEnvOrder
time="2018-05-21T13:08:25Z" level=info msg="DEPRECATED: \"DOCKER_REGISTRY_URL\" is deprecated, use the 'REGISTRY_OPENSHIFT_SERVER_ADDR' instead" 
time="2018-05-21T13:08:25Z" level=info msg="DEPRECATED: \"OPENSHIFT_DEFAULT_REGISTRY\" is deprecated, use the 'REGISTRY_OPENSHIFT_SERVER_ADDR' instead" 
--- PASS: TestServerAddrEnvOrder (0.01s)
=== RUN   TestServerAddrConfigPriority
time="2018-05-21T13:08:25Z" level=info msg="DEPRECATED: \"DOCKER_REGISTRY_URL\" is deprecated, use the 'REGISTRY_OPENSHIFT_SERVER_ADDR' instead" 
time="2018-05-21T13:08:25Z" level=info msg="DEPRECATED: \"OPENSHIFT_DEFAULT_REGISTRY\" is deprecated, use the 'REGISTRY_OPENSHIFT_SERVER_ADDR' instead" 
--- PASS: TestServerAddrConfigPriority (0.01s)
=== RUN   TestAudit
--- PASS: TestAudit (0.00s)
=== RUN   TestPreserveRedisCache
--- PASS: TestPreserveRedisCache (0.00s)
=== RUN   TestDisabledMiddleware
time="2018-05-21T13:08:25Z" level=error msg="wrong configuration detected, openshift repository middleware should not be disabled in the config file" 
--- PASS: TestDisabledMiddleware (0.01s)
=== RUN   TestGetBoolOption
--- PASS: TestGetBoolOption (0.00s)
=== RUN   TestGetDurationOption
--- PASS: TestGetDurationOption (0.00s)
PASS
coverage: 80.8% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/configuration	1.136s	coverage: 80.8% of statements
=== RUN   TestUnmarshalManifestSchema1
=== RUN   TestUnmarshalManifestSchema1/valid_manifest_with_sizes
=== RUN   TestUnmarshalManifestSchema1/valid_manifest_with_missing_sizes
=== RUN   TestUnmarshalManifestSchema1/having_shorter_history
=== RUN   TestUnmarshalManifestSchema1/having_shorter_fs_layers
=== RUN   TestUnmarshalManifestSchema1/additional_signatures
=== RUN   TestUnmarshalManifestSchema1/manifest_missing_signatures
=== RUN   TestUnmarshalManifestSchema1/just_external_signatures
=== RUN   TestUnmarshalManifestSchema1/invalid_manifest
=== RUN   TestUnmarshalManifestSchema1/manifest_schema_2
--- PASS: TestUnmarshalManifestSchema1 (0.06s)
    --- PASS: TestUnmarshalManifestSchema1/valid_manifest_with_sizes (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/valid_manifest_with_missing_sizes (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/having_shorter_history (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/having_shorter_fs_layers (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/additional_signatures (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/manifest_missing_signatures (0.00s)
    --- PASS: TestUnmarshalManifestSchema1/just_external_signatures (0.01s)
    --- PASS: TestUnmarshalManifestSchema1/invalid_manifest (0.00s)
    --- PASS: TestUnmarshalManifestSchema1/manifest_schema_2 (0.00s)
=== RUN   TestUnmarshalManifestSchema2
=== RUN   TestUnmarshalManifestSchema2/valid_nginx_image_with_sizes_in_manifest
=== RUN   TestUnmarshalManifestSchema2/invalid_schema2_image
=== RUN   TestUnmarshalManifestSchema2/manifest_schema1_image
--- PASS: TestUnmarshalManifestSchema2 (0.00s)
    --- PASS: TestUnmarshalManifestSchema2/valid_nginx_image_with_sizes_in_manifest (0.00s)
    --- PASS: TestUnmarshalManifestSchema2/invalid_schema2_image (0.00s)
    --- PASS: TestUnmarshalManifestSchema2/manifest_schema1_image (0.00s)
PASS
coverage: 73.1% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/manifest	1.773s	coverage: 73.1% of statements
=== RUN   TestLimiter
--- PASS: TestLimiter (0.00s)
=== RUN   TestLimiterContext
--- PASS: TestLimiterContext (0.00s)
=== RUN   TestMaxConnections
--- PASS: TestMaxConnections (0.01s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/maxconnections	1.040s	coverage: 100.0% of statements
=== RUN   TestApp
time="2018-05-21T13:08:28Z" level=warning msg="No HTTP secret provided - generated random secret. This may cause problems with uploads if multiple registries are behind a load-balancer. To provide a shared secret, fill in http.secret in the configuration file or set the REGISTRY_HTTP_SECRET environment variable." go.version=go1.8.3 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
time="2018-05-21T13:08:28Z" level=info msg="Starting upload purge in 17m0s" go.version=go1.8.3 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
time="2018-05-21T13:08:28Z" level=info msg="redis not configured" go.version=go1.8.3 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
=== RUN   TestApp/foo_get_blob
time="2018-05-21T13:08:28Z" level=info msg="response completed" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=62554a06-900a-47f0-ae49-4a82e6b1fde0 http.request.method=HEAD http.request.remoteaddr="127.0.0.1:39650" http.request.uri="/v2/foo/blobs/sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae/" http.request.useragent=Go-http-client/1.1 http.response.duration=1.961084ms http.response.status=301 http.response.written=0 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
time="2018-05-21T13:08:28Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae" err.message="blob unknown to registry" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=ad6b474e-e791-470c-94ed-0733a4c6d32e http.request.method=HEAD http.request.referer="http://127.0.0.1:35608/v2/foo/blobs/sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae/" http.request.remoteaddr="127.0.0.1:39650" http.request.uri="/v2/foo/blobs/sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae" http.request.useragent=Go-http-client/1.1 http.response.contenttype="application/json; charset=utf-8" http.response.duration=14.241293ms http.response.status=404 http.response.written=157 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 vars.digest="sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae" vars.name=foo 
=== RUN   TestApp/foo_start_blob_upload
time="2018-05-21T13:08:28Z" level=info msg="response completed" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=93fcee82-fb06-40db-b3b9-48ef74dcce75 http.request.method=POST http.request.remoteaddr="127.0.0.1:39650" http.request.uri=/v2/foo/blobs/uploads/ http.request.useragent=Go-http-client/1.1 http.response.duration=11.904058ms http.response.status=202 http.response.written=0 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
=== RUN   TestApp/foo_put_blob_foo
time="2018-05-21T13:08:28Z" level=info msg="response completed" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=a917d88a-3903-4322-980e-c1aa3f8134ac http.request.method=PUT http.request.remoteaddr="127.0.0.1:39650" http.request.uri="/v2/foo/blobs/uploads/12a5105b-e07d-466d-affd-44def5a157ff?_state=S25DhRKLNZLR-WwcTudmIGdPxsm_revIb0mJ3dPDbpp7Ik5hbWUiOiJmb28iLCJVVUlEIjoiMTJhNTEwNWItZTA3ZC00NjZkLWFmZmQtNDRkZWY1YTE1N2ZmIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDE4LTA1LTIxVDEzOjA4OjI4LjUyOTEyMzkxWiJ9&digest=sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae" http.request.useragent=Go-http-client/1.1 http.response.duration=15.646883ms http.response.status=201 http.response.written=0 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
=== RUN   TestApp/bar_mount_blob
time="2018-05-21T13:08:28Z" level=info msg="response completed" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=d104a22c-fac3-49f8-94cf-6d221bbd8eff http.request.method=POST http.request.remoteaddr="127.0.0.1:39650" http.request.uri="/v2/bar/blobs/uploads/?mount=sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae&from=foo" http.request.useragent=Go-http-client/1.1 http.response.duration=12.833109ms http.response.status=201 http.response.written=0 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
=== RUN   TestApp/foo_delete_blob
time="2018-05-21T13:08:28Z" level=info msg="response completed" go.version=go1.8.3 http.request.host="127.0.0.1:35608" http.request.id=a2b07a41-d627-4d47-b6a7-20a41a504a38 http.request.method=DELETE http.request.remoteaddr="127.0.0.1:39650" http.request.uri="/v2/foo/blobs/sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae" http.request.useragent=Go-http-client/1.1 http.response.duration=9.693578ms http.response.status=202 http.response.written=0 instance.id=5e439fa4-53f6-4ba4-b9a0-d2794e590194 
--- PASS: TestApp (0.12s)
    --- PASS: TestApp/foo_get_blob (0.02s)
    --- PASS: TestApp/foo_start_blob_upload (0.01s)
    --- PASS: TestApp/foo_put_blob_foo (0.02s)
    --- PASS: TestApp/bar_mount_blob (0.02s)
    --- PASS: TestApp/foo_delete_blob (0.01s)
PASS
coverage: 71.6% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/supermiddleware	1.161s	coverage: 71.6% of statements
=== RUN   TestWrapper
--- PASS: TestWrapper (0.00s)
PASS
coverage: 89.0% of statements
ok  	github.com/openshift/image-registry/pkg/dockerregistry/server/wrapped	1.049s	coverage: 89.0% of statements
=== RUN   TestIdentifyCandidateRepositories
--- PASS: TestIdentifyCandidateRepositories (0.00s)
=== RUN   TestCachedImageGetter
--- PASS: TestCachedImageGetter (0.00s)
	logrus.go:28: time="2018-05-21T13:08:33Z" level=error msg="failed to get image sha256:0000000000000000000000000000000000000000000000000000000000000001: images.image.openshift.io \"images\" not found"
	logrus.go:28: time="2018-05-21T13:08:33Z" level=info msg="(*cachedImageGetter).Get: got image sha256:0000000000000000000000000000000000000000000000000000000000000001 from server"
	logrus.go:28: time="2018-05-21T13:08:33Z" level=info msg="(*cachedImageGetter).Get: found image sha256:0000000000000000000000000000000000000000000000000000000000000001 in cache"
PASS
coverage: 20.3% of statements
ok  	github.com/openshift/image-registry/pkg/imagestream	1.760s	coverage: 20.3% of statements
=== RUN   TestReadDockerConfigFile
--- PASS: TestReadDockerConfigFile (0.00s)
=== RUN   TestDockerConfigJsonJSONDecode
--- PASS: TestDockerConfigJsonJSONDecode (0.00s)
=== RUN   TestDockerConfigJSONDecode
--- PASS: TestDockerConfigJSONDecode (0.00s)
=== RUN   TestDockerConfigEntryJSONDecode
--- PASS: TestDockerConfigEntryJSONDecode (0.00s)
=== RUN   TestDecodeDockerConfigFieldAuth
--- PASS: TestDecodeDockerConfigFieldAuth (0.00s)
=== RUN   TestDockerConfigEntryJSONCompatibleEncode
--- PASS: TestDockerConfigEntryJSONCompatibleEncode (0.00s)
=== RUN   TestUrlsMatch
--- PASS: TestUrlsMatch (0.00s)
=== RUN   TestDockerKeyringForGlob
--- PASS: TestDockerKeyringForGlob (0.00s)
=== RUN   TestKeyringMiss
--- PASS: TestKeyringMiss (0.00s)
=== RUN   TestKeyringMissWithDockerHubCredentials
--- PASS: TestKeyringMissWithDockerHubCredentials (0.00s)
=== RUN   TestKeyringHitWithUnqualifiedDockerHub
--- PASS: TestKeyringHitWithUnqualifiedDockerHub (0.00s)
=== RUN   TestKeyringHitWithUnqualifiedLibraryDockerHub
--- PASS: TestKeyringHitWithUnqualifiedLibraryDockerHub (0.00s)
=== RUN   TestKeyringHitWithQualifiedDockerHub
--- PASS: TestKeyringHitWithQualifiedDockerHub (0.00s)
=== RUN   TestIsDefaultRegistryMatch
--- PASS: TestIsDefaultRegistryMatch (0.00s)
=== RUN   TestLazyKeyring
--- PASS: TestLazyKeyring (0.00s)
=== RUN   TestDockerKeyringLookup
--- PASS: TestDockerKeyringLookup (0.00s)
=== RUN   TestIssue3797
--- PASS: TestIssue3797 (0.00s)
=== RUN   TestCachingProvider
--- PASS: TestCachingProvider (2.00s)
PASS
coverage: 58.0% of statements
ok  	github.com/openshift/image-registry/pkg/kubernetes-common/credentialprovider	3.696s	coverage: 58.0% of statements
=== RUN   TestConstantMaps
--- PASS: TestConstantMaps (0.15s)
PASS
coverage: 0.0% of statements
ok  	github.com/openshift/image-registry/pkg/origin-common/crypto	1.165s	coverage: 0.0% of statements
=== RUN   TestPing
--- PASS: TestPing (0.02s)
=== RUN   TestShouldRetry
--- PASS: TestShouldRetry (0.00s)
=== RUN   TestRetryFailure
--- PASS: TestRetryFailure (0.00s)
=== RUN   TestBasicCredentials
--- PASS: TestBasicCredentials (0.00s)
PASS
coverage: 41.3% of statements
ok  	github.com/openshift/image-registry/pkg/origin-common/image/registryclient	1.806s	coverage: 41.3% of statements
=== RUN   TestHubFallback
--- PASS: TestHubFallback (0.00s)
=== RUN   Test_BasicFromKeyring
=== RUN   Test_BasicFromKeyring/exact
=== RUN   Test_BasicFromKeyring/https_scheme
=== RUN   Test_BasicFromKeyring/canonical_https
=== RUN   Test_BasicFromKeyring/only_https
=== RUN   Test_BasicFromKeyring/only_https_scheme
=== RUN   Test_BasicFromKeyring/mismatched_scheme_-_http
=== RUN   Test_BasicFromKeyring/don't_assume_port_80_in_keyring_is_https
=== RUN   Test_BasicFromKeyring/exact_http
=== RUN   Test_BasicFromKeyring/exact_http#01
=== RUN   Test_BasicFromKeyring/keyring_canonical_https
=== RUN   Test_BasicFromKeyring/host_is_for_port_80_only
=== RUN   Test_BasicFromKeyring/host_is_for_port_443_only
=== RUN   Test_BasicFromKeyring/canonical_http
=== RUN   Test_BasicFromKeyring/http_scheme
=== RUN   Test_BasicFromKeyring/https_not_canonical
=== RUN   Test_BasicFromKeyring/http_not_canonical
=== RUN   Test_BasicFromKeyring/mismatched_scheme
--- PASS: Test_BasicFromKeyring (0.00s)
    --- PASS: Test_BasicFromKeyring/exact (0.00s)
    --- PASS: Test_BasicFromKeyring/https_scheme (0.00s)
    --- PASS: Test_BasicFromKeyring/canonical_https (0.00s)
    --- PASS: Test_BasicFromKeyring/only_https (0.00s)
    --- PASS: Test_BasicFromKeyring/only_https_scheme (0.00s)
    --- PASS: Test_BasicFromKeyring/mismatched_scheme_-_http (0.00s)
    --- PASS: Test_BasicFromKeyring/don't_assume_port_80_in_keyring_is_https (0.00s)
    --- PASS: Test_BasicFromKeyring/exact_http (0.00s)
    --- PASS: Test_BasicFromKeyring/exact_http#01 (0.00s)
    --- PASS: Test_BasicFromKeyring/keyring_canonical_https (0.00s)
    --- PASS: Test_BasicFromKeyring/host_is_for_port_80_only (0.00s)
    --- PASS: Test_BasicFromKeyring/host_is_for_port_443_only (0.00s)
    --- PASS: Test_BasicFromKeyring/canonical_http (0.00s)
    --- PASS: Test_BasicFromKeyring/http_scheme (0.00s)
    --- PASS: Test_BasicFromKeyring/https_not_canonical (0.00s)
    --- PASS: Test_BasicFromKeyring/http_not_canonical (0.00s)
    --- PASS: Test_BasicFromKeyring/mismatched_scheme (0.00s)
PASS
coverage: 92.6% of statements
ok  	github.com/openshift/image-registry/pkg/origin-common/image/registryclient/dockercredentials	1.589s	coverage: 92.6% of statements
=== RUN   TestIsErrorQuotaExceeded
--- PASS: TestIsErrorQuotaExceeded (0.00s)
=== RUN   TestIsErrorLimitExceeded
--- PASS: TestIsErrorLimitExceeded (0.00s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/pkg/origin-common/quota/util	1.560s	coverage: 100.0% of statements
=== RUN   TestSchemeHost
--- PASS: TestSchemeHost (0.00s)
PASS
coverage: 71.2% of statements
ok  	github.com/openshift/image-registry/pkg/origin-common/util/httprequest	1.020s	coverage: 71.2% of statements
=== RUN   TestCounter
--- PASS: TestCounter (0.00s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/pkg/testutil/counter	1.013s	coverage: 100.0% of statements
=== RUN   TestAddSuite
--- PASS: TestAddSuite (0.00s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/tools/junitreport/pkg/builder/flat	1.014s	coverage: 100.0% of statements
=== RUN   TestGetParentName
--- PASS: TestGetParentName (0.00s)
=== RUN   TestAddSuite
--- PASS: TestAddSuite (0.00s)
PASS
coverage: 98.5% of statements
ok  	github.com/openshift/image-registry/tools/junitreport/pkg/builder/nested	1.012s	coverage: 98.5% of statements
=== RUN   TestMarksTestBeginning
--- PASS: TestMarksTestBeginning (0.00s)
=== RUN   TestExtractTestName
--- PASS: TestExtractTestName (0.00s)
=== RUN   TestExtractResult
--- PASS: TestExtractResult (0.00s)
=== RUN   TestExtractDuration
--- PASS: TestExtractDuration (0.00s)
=== RUN   TestExtractMessage
--- PASS: TestExtractMessage (0.00s)
=== RUN   TestMarksTestCompletion
--- PASS: TestMarksTestCompletion (0.00s)
=== RUN   TestMarksSuiteBeginning
--- PASS: TestMarksSuiteBeginning (0.00s)
=== RUN   TestExtractSuiteName
--- PASS: TestExtractSuiteName (0.00s)
=== RUN   TestMarksSuiteCompletion
--- PASS: TestMarksSuiteCompletion (0.00s)
=== RUN   TestFlatParse
--- PASS: TestFlatParse (0.05s)
=== RUN   TestNestedParse
--- PASS: TestNestedParse (0.06s)
PASS
coverage: 100.0% of statements
ok  	github.com/openshift/image-registry/tools/junitreport/pkg/parser/oscmd	1.130s	coverage: 100.0% of statements
=== RUN   TestPush
--- PASS: TestPush (0.00s)
=== RUN   TestPop
--- PASS: TestPop (0.00s)
=== RUN   TestPeek
--- PASS: TestPeek (0.00s)
=== RUN   TestIsEmpty
--- PASS: TestIsEmpty (0.00s)
PASS
coverage: 17.2% of statements
ok  	github.com/openshift/image-registry/tools/junitreport/pkg/parser/stack	1.013s	coverage: 17.2% of statements
[INFO] No compiled `junitreport` binary was found. Attempting to build one using:
[INFO]   $ hack/build-go.sh tools/junitreport
++ Building go targets for linux/amd64: tools/junitreport
[INFO] hack/build-go.sh exited with code 0 after 00h 00m 06s
[INFO] jUnit XML report placed at _output/scripts/test-go/artifacts/gotest_report_nGjXi.xml
Of 188 tests executed in 32.895s, 188 succeeded, 0 failed, and 0 were skipped.
[INFO] hack/test-go.sh exited with code 0 after 00h 01m 20s
+ set +o xtrace
########## FINISHED STAGE: SUCCESS: RUN UNIT TESTS [00h 01m 37s] ##########
[PostBuildScript] - Executing post build scripts.
[workspace] $ /bin/bash /tmp/jenkins9128758607819638264.sh
########## STARTING STAGE: DOWNLOAD ARTIFACTS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/gathered
+ rm -rf /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/gathered
+ mkdir -p /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/gathered
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo stat /data/src/github.com/openshift/origin/_output/scripts
stat: cannot stat ‘/data/src/github.com/openshift/origin/_output/scripts’: No such file or directory
+ tree /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/gathered
/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/gathered

0 directories, 0 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins8230450708878378822.sh
########## STARTING STAGE: GENERATE ARTIFACTS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/generated
+ rm -rf /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/generated
+ mkdir /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/generated
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo docker version && sudo docker info && sudo docker images && sudo docker ps -a 2>&1'
  WARNING: You're not using the default seccomp profile
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo cat /etc/sysconfig/docker /etc/sysconfig/docker-network /etc/sysconfig/docker-storage /etc/sysconfig/docker-storage-setup /etc/systemd/system/docker.service 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo find /var/lib/docker/containers -name *.log | sudo xargs tail -vn +1 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'oc get --raw /metrics --server=https://$( uname --nodename ):10250 --config=/etc/origin/master/admin.kubeconfig 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo ausearch -m AVC -m SELINUX_ERR -m USER_AVC 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'oc get --raw /metrics --config=/etc/origin/master/admin.kubeconfig 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo df -T -h && sudo pvs && sudo vgs && sudo lvs && sudo findmnt --all 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo yum list installed 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo journalctl --dmesg --no-pager --all --lines=all 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo journalctl _PID=1 --no-pager --all --lines=all 2>&1'
+ tree /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/generated
/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/generated
├── avc_denials.log
├── containers.log
├── dmesg.log
├── docker.config
├── docker.info
├── filesystem.info
├── installed_packages.log
├── master-metrics.log
├── node-metrics.log
└── pid1.journal

0 directories, 10 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins5698612832280363748.sh
########## STARTING STAGE: FETCH SYSTEMD JOURNALS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/journals
+ rm -rf /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/journals
+ mkdir /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/journals
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit docker.service --no-pager --all --lines=all
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit dnsmasq.service --no-pager --all --lines=all
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit systemd-journald.service --no-pager --all --lines=all
+ tree /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/journals
/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/artifacts/journals
├── dnsmasq.service
├── docker.service
└── systemd-journald.service

0 directories, 3 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins5955191471083670746.sh
########## STARTING STAGE: ASSEMBLE GCS OUTPUT ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
+ trap 'exit 0' EXIT
+ mkdir -p gcs/artifacts gcs/artifacts/generated gcs/artifacts/journals gcs/artifacts/gathered
++ python -c 'import json; import urllib; print json.load(urllib.urlopen('\''https://ci.openshift.redhat.com/jenkins/job/test_pull_request_image_registry_unit/256/api/json'\''))['\''result'\'']'
+ result=SUCCESS
+ cat
++ date +%s
+ cat /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/builds/256/log
+ cp artifacts/generated/avc_denials.log artifacts/generated/containers.log artifacts/generated/dmesg.log artifacts/generated/docker.config artifacts/generated/docker.info artifacts/generated/filesystem.info artifacts/generated/installed_packages.log artifacts/generated/master-metrics.log artifacts/generated/node-metrics.log artifacts/generated/pid1.journal gcs/artifacts/generated/
+ cp artifacts/journals/dnsmasq.service artifacts/journals/docker.service artifacts/journals/systemd-journald.service gcs/artifacts/journals/
+ cp -r 'artifacts/gathered/*' gcs/artifacts/
cp: cannot stat ‘artifacts/gathered/*’: No such file or directory
++ export status=FAILURE
++ status=FAILURE
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins4645595323216685119.sh
########## STARTING STAGE: PUSH THE ARTIFACTS AND METADATA ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ mktemp
+ script=/tmp/tmp.F1trqPNUUi
+ cat
+ chmod +x /tmp/tmp.F1trqPNUUi
+ scp -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config /tmp/tmp.F1trqPNUUi openshiftdevel:/tmp/tmp.F1trqPNUUi
+ ssh -F /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/.ssh_config -t openshiftdevel 'bash -l -c "timeout 300 /tmp/tmp.F1trqPNUUi"'
+ cd /home/origin
+ trap 'exit 0' EXIT
+ [[ -n {"type":"presubmit","job":"test_pull_request_image_registry_unit","buildid":"2f40111a-5cf7-11e8-ae4a-0a58ac100556","refs":{"org":"openshift","repo":"image-registry","base_ref":"master","base_sha":"2cc0b44a964479580e22adcf285a12455e0cf80f","pulls":[{"number":85,"author":"dmage","sha":"7f20f625da16a16c91bb1a431bcea858f73703a1"}]}} ]]
++ jq --compact-output .buildid
+ [[ "2f40111a-5cf7-11e8-ae4a-0a58ac100556" =~ ^"[0-9]+"$ ]]
+ echo 'Using BUILD_NUMBER'
Using BUILD_NUMBER
++ jq --compact-output '.buildid |= "256"'
+ JOB_SPEC='{"type":"presubmit","job":"test_pull_request_image_registry_unit","buildid":"256","refs":{"org":"openshift","repo":"image-registry","base_ref":"master","base_sha":"2cc0b44a964479580e22adcf285a12455e0cf80f","pulls":[{"number":85,"author":"dmage","sha":"7f20f625da16a16c91bb1a431bcea858f73703a1"}]}}'
+ docker run -e 'JOB_SPEC={"type":"presubmit","job":"test_pull_request_image_registry_unit","buildid":"256","refs":{"org":"openshift","repo":"image-registry","base_ref":"master","base_sha":"2cc0b44a964479580e22adcf285a12455e0cf80f","pulls":[{"number":85,"author":"dmage","sha":"7f20f625da16a16c91bb1a431bcea858f73703a1"}]}}' -v /data:/data:z registry.svc.ci.openshift.org/ci/gcsupload:latest --dry-run=false --gcs-path=gs://origin-ci-test --gcs-credentials-file=/data/credentials.json --path-strategy=single --default-org=openshift --default-repo=origin '/data/gcs/*'
Unable to find image 'registry.svc.ci.openshift.org/ci/gcsupload:latest' locally
Trying to pull repository registry.svc.ci.openshift.org/ci/gcsupload ... 
latest: Pulling from registry.svc.ci.openshift.org/ci/gcsupload
6d987f6f4279: Already exists
4cccebe844ee: Already exists
cafcba51f636: Pulling fs layer
cafcba51f636: Download complete
cafcba51f636: Pull complete
Digest: sha256:c452798b56e3f4649c557c3ff7273126042065e3be152689a1ffb880638e617d
Status: Downloaded newer image for registry.svc.ci.openshift.org/ci/gcsupload:latest
{"component":"gcsupload","level":"warning","msg":"Encountered error in resolving items to upload for /data/gcs/*: stat /data/gcs/*: no such file or directory","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/directory/test_pull_request_image_registry_unit/latest-build.txt","level":"info","msg":"Queued for upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/pull/openshift_image-registry/85/test_pull_request_image_registry_unit/latest-build.txt","level":"info","msg":"Queued for upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/directory/test_pull_request_image_registry_unit/256.txt","level":"info","msg":"Queued for upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/directory/test_pull_request_image_registry_unit/256.txt","level":"info","msg":"Finished upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/pull/openshift_image-registry/85/test_pull_request_image_registry_unit/latest-build.txt","level":"info","msg":"Finished upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","dest":"pr-logs/directory/test_pull_request_image_registry_unit/latest-build.txt","level":"info","msg":"Finished upload","time":"2018-05-21T13:09:14Z"}
{"component":"gcsupload","level":"info","msg":"Finished upload to GCS","time":"2018-05-21T13:09:14Z"}
+ exit 0
+ set +o xtrace
########## FINISHED STAGE: SUCCESS: PUSH THE ARTIFACTS AND METADATA [00h 00m 05s] ##########
[workspace] $ /bin/bash /tmp/jenkins582975027856342791.sh
########## STARTING STAGE: DEPROVISION CLOUD RESOURCES ##########
+ [[ -s /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83
++ export PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config
+ oct deprovision

PLAYBOOK: main.yml *************************************************************
4 plays in /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml

PLAY [ensure we have the parameters necessary to deprovision virtual hosts] ****

TASK [ensure all required variables are set] ***********************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:9
skipping: [localhost] => (item=origin_ci_inventory_dir)  => {
    "changed": false, 
    "generated_timestamp": "2018-05-21 09:09:16.012298", 
    "item": "origin_ci_inventory_dir", 
    "skip_reason": "Conditional check failed", 
    "skipped": true
}
skipping: [localhost] => (item=origin_ci_aws_region)  => {
    "changed": false, 
    "generated_timestamp": "2018-05-21 09:09:16.015149", 
    "item": "origin_ci_aws_region", 
    "skip_reason": "Conditional check failed", 
    "skipped": true
}

PLAY [deprovision virtual hosts in EC2] ****************************************

TASK [Gathering Facts] *********************************************************
ok: [localhost]

TASK [deprovision a virtual EC2 host] ******************************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:28
included: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml for localhost

TASK [update the SSH configuration to remove AWS EC2 specifics] ****************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:2
ok: [localhost] => {
    "changed": false, 
    "generated_timestamp": "2018-05-21 09:09:16.854758", 
    "msg": ""
}

TASK [rename EC2 instance for termination reaper] ******************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:8
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-05-21 09:09:17.440549", 
    "msg": "Tags {'Name': 'oct-terminate'} created for resource i-047abbed8a86d6d93."
}

TASK [tear down the EC2 instance] **********************************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:15
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-05-21 09:09:18.295131", 
    "instance_ids": [
        "i-047abbed8a86d6d93"
    ], 
    "instances": [
        {
            "ami_launch_index": "0", 
            "architecture": "x86_64", 
            "block_device_mapping": {
                "/dev/sda1": {
                    "delete_on_termination": true, 
                    "status": "attached", 
                    "volume_id": "vol-0d02acf6ac26438ad"
                }, 
                "/dev/sdb": {
                    "delete_on_termination": true, 
                    "status": "attached", 
                    "volume_id": "vol-0f94c8820b64835cc"
                }
            }, 
            "dns_name": "ec2-52-90-254-97.compute-1.amazonaws.com", 
            "ebs_optimized": false, 
            "groups": {
                "sg-7e73221a": "default"
            }, 
            "hypervisor": "xen", 
            "id": "i-047abbed8a86d6d93", 
            "image_id": "ami-0f07d2d9a03af96ec", 
            "instance_type": "m4.xlarge", 
            "kernel": null, 
            "key_name": "libra", 
            "launch_time": "2018-05-21T13:02:44.000Z", 
            "placement": "us-east-1d", 
            "private_dns_name": "ip-172-18-14-96.ec2.internal", 
            "private_ip": "172.18.14.96", 
            "public_dns_name": "ec2-52-90-254-97.compute-1.amazonaws.com", 
            "public_ip": "52.90.254.97", 
            "ramdisk": null, 
            "region": "us-east-1", 
            "root_device_name": "/dev/sda1", 
            "root_device_type": "ebs", 
            "state": "running", 
            "state_code": 16, 
            "tags": {
                "Name": "oct-terminate", 
                "openshift_etcd": "", 
                "openshift_master": "", 
                "openshift_node": ""
            }, 
            "tenancy": "default", 
            "virtualization_type": "hvm"
        }
    ], 
    "tagged_instances": []
}

TASK [remove the serialized host variables] ************************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:22
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-05-21 09:09:18.550757", 
    "path": "/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory/host_vars/172.18.14.96.yml", 
    "state": "absent"
}

PLAY [deprovision virtual hosts locally manged by Vagrant] *********************

TASK [Gathering Facts] *********************************************************
ok: [localhost]

PLAY [clean up local configuration for deprovisioned instances] ****************

TASK [remove inventory configuration directory] ********************************
task path: /var/lib/jenkins/origin-ci-tool/7a5c5e83c372ad2e6b3b64b3efa16fe2cb37ef83/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:61
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-05-21 09:09:19.036206", 
    "path": "/var/lib/jenkins/jobs/test_pull_request_image_registry_unit/workspace/.config/origin-ci-tool/inventory", 
    "state": "absent"
}

PLAY RECAP *********************************************************************
localhost                  : ok=8    changed=4    unreachable=0    failed=0   

+ set +o xtrace
########## FINISHED STAGE: SUCCESS: DEPROVISION CLOUD RESOURCES [00h 00m 05s] ##########
Archiving artifacts
[WS-CLEANUP] Deleting project workspace...[WS-CLEANUP] done
Finished: SUCCESS