Snapshot gets deleted when an image is being pulled. #3787
Description
[BeforeEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:50
[BeforeEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/image.go:37
[It] listImage should get exactly 3 image in the result list [Conformance]
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/image.go:126
STEP: Remove image : gcr.io/cri-tools/test-image-1:latest
STEP: Remove image : gcr.io/cri-tools/test-image-2:latest
STEP: Remove image : gcr.io/cri-tools/test-image-3:latest
STEP: Pull image : gcr.io/cri-tools/test-image-1:latest
E1029 06:07:43.037887 4062 remote_image.go:113] PullImage "gcr.io/cri-tools/test-image-1:latest" from image service failed: rpc error: code = NotFound desc = failed to pull and unpack image "gcr.io/cri-tools/test-image-1:latest": unpack: failed to prepare extraction snapshot "extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found
Oct 29 06:07:43.037: INFO: Unexpected error occurred: rpc error: code = NotFound desc = failed to pull and unpack image "gcr.io/cri-tools/test-image-1:latest": unpack: failed to prepare extraction snapshot "extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found
[AfterEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:51
• Failure [0.709 seconds]
[k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:72
listImage should get exactly 3 image in the result list [Conformance] [It]
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/image.go:126
failed to pull image: rpc error: code = NotFound desc = failed to pull and unpack image "gcr.io/cri-tools/test-image-1:latest": unpack: failed to prepare extraction snapshot "extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found
Unexpected error:
<*status.statusError | 0xc000334730>: {
Code: 5,
Message: "failed to pull and unpack image \"gcr.io/cri-tools/test-image-1:latest\": unpack: failed to prepare extraction snapshot \"extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee\": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found",
Details: nil,
XXX_NoUnkeyedLiteral: {},
XXX_unrecognized: nil,
XXX_sizecache: 0,
}
rpc error: code = NotFound desc = failed to pull and unpack image "gcr.io/cri-tools/test-image-1:latest": unpack: failed to prepare extraction snapshot "extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found
occurred
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/util.go:328
------------------------------
[BeforeEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:50
[BeforeEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/image.go:37
[It] image status should support all kinds of references [Conformance]
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/validate/image.go:60
STEP: Remove image : gcr.io/cri-tools/test-image-tag:all
STEP: Pull image : gcr.io/cri-tools/test-image-tag:all
STEP: Get image status for image: gcr.io/cri-tools/test-image-tag:all
STEP: Get image status for image: sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36
STEP: Get image status for image: gcr.io/cri-tools/test-image-tag:all
STEP: Get image status for image: gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce
STEP: Remove image : gcr.io/cri-tools/test-image-tag:all
STEP: Remove image : gcr.io/cri-tools/test-image-tag:all
STEP: Remove image by ID : sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36
STEP: Check image list empty
STEP: Get image status for image: gcr.io/cri-tools/test-image-tag:all
[AfterEach] [k8s.io] Image Manager
/home/travis/gopath/src/github.com/kubernetes-incubator/cri-tools/pkg/framework/framework.go:51
The 2 images pulled/removed in parallel causing this are:
gcr.io/cri-tools/test-image-digest@sha256:9179135b4b4cc5a8721e09379244807553c318d92fa3111a65133241551ca343gcr.io/cri-tools/test-image-1:latest
related containerd log
time="2019-10-29T06:07:42.383585169Z" level=info msg="PullImage \"gcr.io/cri-tools/test-image-1:latest\""
time="2019-10-29T06:07:42.459277336Z" level=debug msg=resolving host=gcr.io
time="2019-10-29T06:07:42.459378649Z" level=debug msg="do request" host=gcr.io request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=HEAD url="https://gcr.io/v2/cri-tools/test-image-1/manifests/latest"
time="2019-10-29T06:07:42.472952613Z" level=debug msg="fetch response received" digest="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36" mediatype=application/vnd.docker.container.image.v1+json response.header.accept-ranges=bytes response.header.cache-control="public, max-age=3600" response.header.content-length=1812 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 06:07:42 GMT" response.header.etag="\"dcfc83e7960dd0711243692f37cc4f73\"" response.header.expires="Tue, 29 Oct 2019 07:07:42 GMT" response.header.last-modified="Thu, 08 Aug 2019 21:31:41 GMT" response.header.server=UploadServer response.header.x-goog-generation=1565299901230199 response.header.x-goog-hash="crc32c=zJQtEw==" response.header.x-goog-hash.1="md5=3PyD55YN0HESQ2kvN8xPcw==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=1812 response.header.x-guploader-uploadid=AEnB2Up-hr-KjcSmJOgDCi8NJ_MUl0oJTf2F8swEz5nMF0HNTBx-NXSMd90M7LetayQVYQiLsb-ljt678l_pvHQHrHjCtnI_gQ response.status="200 OK" size=1812 url="https://gcr.io/v2/cri-tools/test-image-tag/blobs/sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36"
time="2019-10-29T06:07:42.506531652Z" level=debug msg="fetch response received" host=gcr.io response.header.content-length=1359 response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Tue, 29 Oct 2019 06:07:42 GMT" response.header.docker-content-digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" response.header.docker-distribution-api-version=registry/2.0 response.header.server="Docker Registry" response.header.x-frame-options=SAMEORIGIN response.header.x-xss-protection=0 response.status="200 OK" url="https://gcr.io/v2/cri-tools/test-image-1/manifests/latest"
time="2019-10-29T06:07:42.506635673Z" level=debug msg=resolved desc.digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" host=gcr.io
time="2019-10-29T06:07:42.506773147Z" level=debug msg=fetch digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=1359
time="2019-10-29T06:07:42.540416110Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:5e6ec7f28fb77f84f64b8c29fcb0a746260563f5858315e3e9fcc4aee2844840 22500707 [] map[] <nil>}"
time="2019-10-29T06:07:42.540480501Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:5e6ec7f28fb77f84f64b8c29fcb0a746260563f5858315e3e9fcc4aee2844840 22500707 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:3c816b4ead84066ec2cadec2b943993aaacc3fe35fcd77ada3d09dc4f3937313 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.556527590Z" level=debug msg="do request" digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" mediatype=application/vnd.docker.distribution.manifest.list.v2+json request.header.accept="application/vnd.docker.distribution.manifest.list.v2+json, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=1359 url="https://gcr.io/v2/cri-tools/test-image-1/manifests/sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9"
time="2019-10-29T06:07:42.558143955Z" level=debug msg="create image" name="gcr.io/cri-tools/hostnet-nginx-amd64:latest" target="sha256:b36d3a8eaf71524768fe86ac52b54d5495f6651411a4cc204243c6796a94446d"
time="2019-10-29T06:07:42.561714757Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:42.566394768Z" level=debug msg=fetch digest="sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip size=101
time="2019-10-29T06:07:42.572617935Z" level=debug msg="do request" digest="sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip request.header.accept="application/vnd.docker.image.rootfs.diff.tar.gzip, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=101 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6"
time="2019-10-29T06:07:42.574339007Z" level=debug msg="create image" name="gcr.io/cri-tools/test-image-tag:all" target="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:42.575829104Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:42.575897712Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.575820115 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:42.575940240Z" level=info msg="ImageCreate event &ImageCreate{Name:gcr.io/cri-tools/test-image-tag:all,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.576567395Z" level=debug msg=fetch digest="sha256:268449409a783c0b51b294340457a2603fec06d259f51ab996463b5115de19f6" mediatype=application/vnd.docker.container.image.v1+json size=1812
time="2019-10-29T06:07:42.582570938Z" level=debug msg="do request" digest="sha256:268449409a783c0b51b294340457a2603fec06d259f51ab996463b5115de19f6" mediatype=application/vnd.docker.container.image.v1+json request.header.accept="application/vnd.docker.container.image.v1+json, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=1812 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:268449409a783c0b51b294340457a2603fec06d259f51ab996463b5115de19f6"
time="2019-10-29T06:07:42.582781934Z" level=debug msg=fetch digest="sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip size=699165
time="2019-10-29T06:07:42.590301815Z" level=debug msg="do request" digest="sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip request.header.accept="application/vnd.docker.image.rootfs.diff.tar.gzip, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=699165 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358"
time="2019-10-29T06:07:42.591951857Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:42.592231906Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443 91 [] map[] <nil>}"
time="2019-10-29T06:07:42.592267181Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}"
time="2019-10-29T06:07:42.592287740Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.597301067Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:42.607835548Z" level=debug msg="schedule snapshotter cleanup" snapshotter=overlayfs
time="2019-10-29T06:07:42.609902627Z" level=debug msg="removed snapshot" key=k8s.io/153/9bc25272a5ff5d9d53d272add94d36e58a7d4a68dd96b20230161f4de201374c snapshotter=overlayfs
time="2019-10-29T06:07:42.611461056Z" level=debug msg="removed snapshot" key=k8s.io/152/611880d5e727de23950096a1d3cd480eeccacea4611d8ed07616eb63d4664c8c snapshotter=overlayfs
time="2019-10-29T06:07:42.612331909Z" level=debug msg="snapshot garbage collected" d=4.44783ms snapshotter=overlayfs
time="2019-10-29T06:07:42.612363357Z" level=debug msg="garbage collected" d=3.034018ms
time="2019-10-29T06:07:42.617147891Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.591941586 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:42.617199079Z" level=info msg="ImageCreate event &ImageCreate{Name:gcr.io/cri-tools/hostnet-nginx-amd64:latest,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.618419080Z" level=debug msg="fetch response received" digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" mediatype=application/vnd.docker.distribution.manifest.list.v2+json response.header.content-length=1359 response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Tue, 29 Oct 2019 06:07:42 GMT" response.header.docker-content-digest="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9" response.header.docker-distribution-api-version=registry/2.0 response.header.server="Docker Registry" response.header.x-frame-options=SAMEORIGIN response.header.x-xss-protection=0 response.status="200 OK" size=1359 url="https://gcr.io/v2/cri-tools/test-image-1/manifests/sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9"
time="2019-10-29T06:07:42.631495058Z" level=debug msg=fetch digest="sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f" mediatype=application/vnd.docker.distribution.manifest.v2+json size=733
time="2019-10-29T06:07:42.656741172Z" level=debug msg="do request" digest="sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f" mediatype=application/vnd.docker.distribution.manifest.v2+json request.header.accept="application/vnd.docker.distribution.manifest.v2+json, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=733 url="https://gcr.io/v2/cri-tools/test-image-1/manifests/sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f"
time="2019-10-29T06:07:42.683801615Z" level=debug msg="cni result for sandbox \"749fad248f71f787e6bc150f9a97ff3838e7c9317d3c3f5370ed593864aab324\": {\"Interfaces\":{\"cni0\":{\"IPConfigs\":null,\"Mac\":\"1e:ea:0d:f1:df:8b\",\"Sandbox\":\"\"},\"eth0\":{\"IPConfigs\":[{\"IP\":\"10.88.0.52\",\"Gateway\":\"10.88.0.1\"}],\"Mac\":\"c2:67:5f:5f:0d:8e\",\"Sandbox\":\"/var/run/netns/cni-127d945f-0b33-50e3-93fa-cafe62d8673e\"},\"veth713833d2\":{\"IPConfigs\":null,\"Mac\":\"e6:7c:4b:52:6f:34\",\"Sandbox\":\"\"}},\"DNS\":[{},{}],\"Routes\":[{\"dst\":\"0.0.0.0/0\"}]}"
time="2019-10-29T06:07:42.689617655Z" level=debug msg="fetch response received" digest="sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f" mediatype=application/vnd.docker.distribution.manifest.v2+json response.header.content-length=733 response.header.content-type=application/vnd.docker.distribution.manifest.v2+json response.header.date="Tue, 29 Oct 2019 06:07:42 GMT" response.header.docker-content-digest="sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f" response.header.docker-distribution-api-version=registry/2.0 response.header.server="Docker Registry" response.header.x-frame-options=SAMEORIGIN response.header.x-xss-protection=0 response.status="200 OK" size=733 url="https://gcr.io/v2/cri-tools/test-image-1/manifests/sha256:f99af165fcf3c03f42b8cafe7211815482129ba1014801d7d393a13c4f1c981f"
time="2019-10-29T06:07:42.689913154Z" level=debug msg="fetch response received" digest="sha256:268449409a783c0b51b294340457a2603fec06d259f51ab996463b5115de19f6" mediatype=application/vnd.docker.container.image.v1+json response.header.accept-ranges=bytes response.header.age=2162 response.header.cache-control="public, max-age=3600" response.header.content-length=1812 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 05:31:40 GMT" response.header.etag="\"f21db4e4f5c79cc5d23115850a2d628f\"" response.header.expires="Tue, 29 Oct 2019 06:31:40 GMT" response.header.last-modified="Tue, 20 Feb 2018 18:32:57 GMT" response.header.server=UploadServer response.header.x-goog-generation=1519151577659894 response.header.x-goog-hash="crc32c=GdGeZA==" response.header.x-goog-hash.1="md5=8h205PXHnMXSMRWFCi1ijw==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=1812 response.header.x-guploader-uploadid=AEnB2UrnU9sdwej90cHGzzYgJFZwBuMVm-kQNfCK9M_epSQo2Yv3AV4LecbPbBadPd1HkQqNWOmANIIK_ExgxewT5WqAVK9QIw response.status="200 OK" size=1812 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:268449409a783c0b51b294340457a2603fec06d259f51ab996463b5115de19f6"
time="2019-10-29T06:07:42.690032350Z" level=debug msg="fetch response received" digest="sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip response.header.accept-ranges=bytes response.header.age=2162 response.header.cache-control="public, max-age=3600" response.header.content-length=101 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 05:31:40 GMT" response.header.etag="\"a1746b875792d567be51b25ba0c876a3\"" response.header.expires="Tue, 29 Oct 2019 06:31:40 GMT" response.header.last-modified="Tue, 20 Feb 2018 18:32:54 GMT" response.header.server=UploadServer response.header.x-goog-generation=1519151574889380 response.header.x-goog-hash="crc32c=U4uwqw==" response.header.x-goog-hash.1="md5=oXRrh1eS1We+UbJboMh2ow==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=101 response.header.x-guploader-uploadid=AEnB2Upcmw5aiC1pNMPR5DJPYnqmBnPNrp_kWnmGg19JqDdmVxAjE953wrlKFwFQtxZRAk3ruN1nTnJXCYpQH7xZvVf-nMmbuabqfR5TRGIBOU8v6otpflo response.status="200 OK" size=101 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6"
time="2019-10-29T06:07:42.692947886Z" level=debug msg="diff applied" d=95.607784ms dgst="sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=762728
time="2019-10-29T06:07:42.693049414Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:42.694789151Z" level=debug msg="event published" ns=k8s.io topic=/containers/create type=containerd.events.ContainerCreate
time="2019-10-29T06:07:42.695391486Z" level=debug msg="fetch response received" digest="sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip response.header.accept-ranges=bytes response.header.age=2162 response.header.cache-control="public, max-age=3600" response.header.content-length=699165 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 05:31:40 GMT" response.header.etag="\"4a48ae1e1dbc7424a4eaaba64fa00c6c\"" response.header.expires="Tue, 29 Oct 2019 06:31:40 GMT" response.header.last-modified="Tue, 20 Feb 2018 18:32:28 GMT" response.header.server=UploadServer response.header.x-goog-generation=1519151548075266 response.header.x-goog-hash="crc32c=tNx56g==" response.header.x-goog-hash.1="md5=SkiuHh28dCSk6qumT6AMbA==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=699165 response.header.x-guploader-uploadid=AEnB2Up177FaddDRMwHV4_kELo-MetoWyjvs3_FmTDxu4hzpvpBE6fex7Qu3dAaHDf-Fav1Oevd8DKCZgGdlBvwfb_AOw2uTGg response.status="200 OK" size=699165 url="https://gcr.io/v2/cri-tools/test-image-digest/blobs/sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358"
time="2019-10-29T06:07:42.723732219Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/commit type=containerd.events.SnapshotCommit
time="2019-10-29T06:07:42.748043779Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6 101 [] map[] <nil>}"
time="2019-10-29T06:07:42.750032133Z" level=debug msg="layer unpacked" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.750099855Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443 91 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:5cd4881ed725b8c605a48feff0e2c0105d2fa58b298ed84ebbf82da24e605769 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.752752378Z" level=debug msg="create image" name="gcr.io/cri-tools/test-image-digest@sha256:9179135b4b4cc5a8721e09379244807553c318d92fa3111a65133241551ca343" target="sha256:9179135b4b4cc5a8721e09379244807553c318d92fa3111a65133241551ca343"
time="2019-10-29T06:07:42.753088739Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358 699165 [] map[] <nil>}"
time="2019-10-29T06:07:42.753125516Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358 699165 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:4febd3792a1fb2153108b4fa50161c6ee5e3d16aa483a63215f936a113a88e9a 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.754564197Z" level=debug msg=fetch digest="sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip size=99
time="2019-10-29T06:07:42.755219036Z" level=debug msg=fetch digest="sha256:6e7cd506a324a5bcc6cf92d6e5d902d44b55bf34864eb530ab87468d0941bbdc" mediatype=application/vnd.docker.container.image.v1+json size=1830
time="2019-10-29T06:07:42.755305134Z" level=debug msg=fetch digest="sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip size=762728
time="2019-10-29T06:07:42.755078764Z" level=info msg="starting signal loop" namespace=k8s.io path=/run/containerd/io.containerd.runtime.v2.task/k8s.io/749fad248f71f787e6bc150f9a97ff3838e7c9317d3c3f5370ed593864aab324 pid=17963
time="2019-10-29T06:07:42.767039619Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:42.767393410Z" level=debug msg="diff applied" d="305.615µs" dgst="sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=91
time="2019-10-29T06:07:42.769294615Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:42.769380560Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.76928453 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:42.769423303Z" level=info msg="ImageCreate event &ImageCreate{Name:gcr.io/cri-tools/test-image-digest@sha256:9179135b4b4cc5a8721e09379244807553c318d92fa3111a65133241551ca343,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.773033930Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:42.795246678Z" level=debug msg="do request" digest="sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip request.header.accept="application/vnd.docker.image.rootfs.diff.tar.gzip, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=99 url="https://gcr.io/v2/cri-tools/test-image-1/blobs/sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274"
time="2019-10-29T06:07:42.823442998Z" level=debug msg="do request" digest="sha256:6e7cd506a324a5bcc6cf92d6e5d902d44b55bf34864eb530ab87468d0941bbdc" mediatype=application/vnd.docker.container.image.v1+json request.header.accept="application/vnd.docker.container.image.v1+json, */*" request.header.user-agent=containerd/v1.3.0-71-gc46a0cc request.method=GET size=1830 url="https://gcr.io/v2/cri-tools/test-image-1/blobs/sha256:6e7cd506a324a5bcc6cf92d6e5d902d44b55bf34864eb530ab87468d0941bbdc"
time="2019-10-29T06:07:42.843398152Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/commit type=containerd.events.SnapshotCommit
time="2019-10-29T06:07:42.848766825Z" level=debug msg="layer unpacked" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443 91 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:5cd4881ed725b8c605a48feff0e2c0105d2fa58b298ed84ebbf82da24e605769 0 [] map[] <nil>}"
time="2019-10-29T06:07:42.851344320Z" level=debug msg="image unpacked" chainID="sha256:52e5f8c2ed3df1cd4a08dfb0a9d769356f8c57b01ffa5ab91cadb74d7bee7141" config="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36"
time="2019-10-29T06:07:42.853134433Z" level=debug msg="create image" name="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36" target="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:42.855051684Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:42.855692823Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.855039204 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:42.855740940Z" level=info msg="ImageCreate event &ImageCreate{Name:sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.856023276Z" level=debug msg="create image" name="gcr.io/cri-tools/test-image-tag:all" target="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:42.857535116Z" level=debug msg="event published" ns=k8s.io topic=/images/update type=containerd.services.images.v1.ImageUpdate
time="2019-10-29T06:07:42.859061156Z" level=debug msg="create image" name="gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce" target="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:42.860916122Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:42.862252031Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.857525323 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/update\""
time="2019-10-29T06:07:42.862296084Z" level=info msg="ImageUpdate event &ImageUpdate{Name:gcr.io/cri-tools/test-image-tag:all,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.862998358Z" level=debug msg="Pulled image \"gcr.io/cri-tools/test-image-tag:all\" with image id \"sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36\", repo tag \"gcr.io/cri-tools/test-image-tag:all\", repo digest \"gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce\""
time="2019-10-29T06:07:42.863031315Z" level=info msg="PullImage \"gcr.io/cri-tools/test-image-tag:all\" returns image reference \"sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36\""
time="2019-10-29T06:07:42.863839540Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.86090757 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:42.863879597Z" level=info msg="ImageCreate event &ImageCreate{Name:gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.967833498Z" level=debug msg="fetch response received" digest="sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip response.header.accept-ranges=bytes response.header.age=2142 response.header.cache-control="public, max-age=3600" response.header.content-length=99 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 05:32:00 GMT" response.header.etag="\"7569fb461164a4c35cd4d7e9821be28e\"" response.header.expires="Tue, 29 Oct 2019 06:32:00 GMT" response.header.last-modified="Thu, 08 Aug 2019 21:11:29 GMT" response.header.server=UploadServer response.header.x-goog-generation=1565298689418277 response.header.x-goog-hash="crc32c=eylC4A==" response.header.x-goog-hash.1="md5=dWn7RhFkpMNc1Nfpghvijg==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=99 response.header.x-guploader-uploadid=AEnB2UqLaHVvcp8qOvAGPqIZh18Fx54iT9bd0G7nlwhYodGdRY_yNioIycAeyKt8-rwaG1rib_o9_dEiNlp1mERzhpCmrQ4DrA response.status="200 OK" size=99 url="https://gcr.io/v2/cri-tools/test-image-1/blobs/sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274"
time="2019-10-29T06:07:42.968212845Z" level=debug msg="fetch response received" digest="sha256:6e7cd506a324a5bcc6cf92d6e5d902d44b55bf34864eb530ab87468d0941bbdc" mediatype=application/vnd.docker.container.image.v1+json response.header.accept-ranges=bytes response.header.age=2142 response.header.cache-control="public, max-age=3600" response.header.content-length=1830 response.header.content-type=application/octet-stream response.header.date="Tue, 29 Oct 2019 05:32:00 GMT" response.header.etag="\"d7a10e222ac73b61a2e2475d4d90b649\"" response.header.expires="Tue, 29 Oct 2019 06:32:00 GMT" response.header.last-modified="Thu, 08 Aug 2019 21:11:31 GMT" response.header.server=UploadServer response.header.x-goog-generation=1565298691527073 response.header.x-goog-hash="crc32c=Atv5ig==" response.header.x-goog-hash.1="md5=16EOIirHO2Gi4kddTZC2SQ==" response.header.x-goog-metageneration=1 response.header.x-goog-storage-class=STANDARD response.header.x-goog-stored-content-encoding=identity response.header.x-goog-stored-content-length=1830 response.header.x-guploader-uploadid=AEnB2Uo4YGQdTTD8PeLGjy6f4QDSvC_803ri7QhnVXwkOXWklTZGnnj4FMod4czBF7QUKp5lZ-HlkUORjW3ez31TlAbdXaIYCMyNwjiupAX10BTv_mq0a9o response.status="200 OK" size=1830 url="https://gcr.io/v2/cri-tools/test-image-1/blobs/sha256:6e7cd506a324a5bcc6cf92d6e5d902d44b55bf34864eb530ab87468d0941bbdc"
time="2019-10-29T06:07:42.970413108Z" level=debug msg="diff applied" d=197.328433ms dgst="sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=699165
time="2019-10-29T06:07:42.972617520Z" level=info msg="RemoveImage \"sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36\""
time="2019-10-29T06:07:42.972810387Z" level=debug msg="delete image" name="gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:42.976681461Z" level=debug msg="garbage collected" d=10.831339ms
time="2019-10-29T06:07:42.979596499Z" level=debug msg="event published" ns=k8s.io topic=/images/delete type=containerd.services.images.v1.ImageDelete
time="2019-10-29T06:07:42.979717999Z" level=debug msg="delete image" name="gcr.io/cri-tools/test-image-tag:all"
time="2019-10-29T06:07:42.981297989Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.97958514 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/delete\""
time="2019-10-29T06:07:42.981368431Z" level=info msg="ImageDelete event &ImageDelete{Name:gcr.io/cri-tools/test-image-tag@sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce,XXX_unrecognized:[],}"
time="2019-10-29T06:07:42.982291228Z" level=debug msg="event published" ns=k8s.io topic=/images/delete type=containerd.services.images.v1.ImageDelete
time="2019-10-29T06:07:42.982398740Z" level=debug msg="delete image" name="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36"
time="2019-10-29T06:07:42.982471049Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:42.982281591 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/delete\""
time="2019-10-29T06:07:42.982520696Z" level=info msg="ImageDelete event &ImageDelete{Name:gcr.io/cri-tools/test-image-tag:all,XXX_unrecognized:[],}"
time="2019-10-29T06:07:43.000651765Z" level=debug msg="event forwarded" ns=k8s.io topic=/tasks/create type=containerd.events.TaskCreate
time="2019-10-29T06:07:43.004929112Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/commit type=containerd.events.SnapshotCommit
time="2019-10-29T06:07:43.011203411Z" level=debug msg="event published" ns=k8s.io topic=/images/delete type=containerd.services.images.v1.ImageDelete
time="2019-10-29T06:07:43.011556050Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:43.011192609 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/delete\""
time="2019-10-29T06:07:43.011612771Z" level=info msg="ImageDelete event &ImageDelete{Name:sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36,XXX_unrecognized:[],}"
time="2019-10-29T06:07:43.012855889Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}"
time="2019-10-29T06:07:43.012909744Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea 0 [] map[] <nil>}"
time="2019-10-29T06:07:43.012981336Z" level=debug msg="layer unpacked" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:ee153a04d6837058642958836062f20badf39f558be3e6c7c7773ef7d8301d90 762728 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea 0 [] map[] <nil>}"
time="2019-10-29T06:07:43.014688745Z" level=debug msg="layer unpacked" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:65fc92611f38c5c3e31d5c0faec078c60f41103f2ad4a3700fff122c49aab358 699165 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:4febd3792a1fb2153108b4fa50161c6ee5e3d16aa483a63215f936a113a88e9a 0 [] map[] <nil>}"
time="2019-10-29T06:07:43.014754913Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6 101 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:09e40d6a82d5c36dc1f17c599d2239652094370901c303c07a4f884c791e4720 0 [] map[] <nil>}"
time="2019-10-29T06:07:43.016560858Z" level=debug msg="create image" name="gcr.io/cri-tools/test-image-1:latest" target="sha256:6a6a509f8456dc69d405140ee18c3a615658df08481cf3eaf2b537455523b1b9"
time="2019-10-29T06:07:43.017713261Z" level=debug msg="remove snapshot" key="sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea" snapshotter=overlayfs
time="2019-10-29T06:07:43.017920005Z" level=debug msg="remove snapshot" key="sha256:52e5f8c2ed3df1cd4a08dfb0a9d769356f8c57b01ffa5ab91cadb74d7bee7141" snapshotter=overlayfs
time="2019-10-29T06:07:43.017953847Z" level=debug msg="remove content" key="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36"
time="2019-10-29T06:07:43.017984521Z" level=debug msg="remove content" key="sha256:316111353db37ad8775dcbc95223a962e9f5b75e0353daf3ff47e23327fd478b"
time="2019-10-29T06:07:43.018021027Z" level=debug msg="remove content" key="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:43.018042664Z" level=debug msg="remove content" key="sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443"
time="2019-10-29T06:07:43.018309735Z" level=debug msg="layer downloaded" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274 99 [] map[] <nil>}"
time="2019-10-29T06:07:43.018344826Z" level=debug msg="unpack layer" desc="{application/vnd.docker.image.rootfs.diff.tar.gzip sha256:8f0106107fafe96b051176d19d9ea26b10e86d76c3d2f206096546bcc14ca274 99 [] map[] <nil>}" diff="{application/vnd.oci.image.layer.v1.tar sha256:90c3dbea497c78fcc359a6fa6189b3e6cef91e4e40b53c1c0f056da03d690974 0 [] map[] <nil>}"
time="2019-10-29T06:07:43.021734163Z" level=debug msg="schedule snapshotter cleanup" snapshotter=overlayfs
time="2019-10-29T06:07:43.021764156Z" level=debug msg="schedule content cleanup"
time="2019-10-29T06:07:43.022348779Z" level=debug msg="removed content" digest="sha256:2d4bd5735ff286d2879cfb24a6f284a174c470f10e5d21adc4427c6bbc2c2c36"
time="2019-10-29T06:07:43.022410390Z" level=debug msg="removed content" digest="sha256:316111353db37ad8775dcbc95223a962e9f5b75e0353daf3ff47e23327fd478b"
time="2019-10-29T06:07:43.022760942Z" level=debug msg="removed content" digest="sha256:e10179315117cd3d9ef6902d464b4f3efb3c45f61079e0de81e215ea5ef6e5ce"
time="2019-10-29T06:07:43.022817424Z" level=debug msg="removed content" digest="sha256:e10d880f065491830f2d40963054c7128812a79e5d84dff38be3e69a53647443"
time="2019-10-29T06:07:43.022937554Z" level=debug msg="content garbage collected" d=1.040943ms
time="2019-10-29T06:07:43.026823384Z" level=debug msg="event published" ns=k8s.io topic=/snapshot/prepare type=containerd.events.SnapshotPrepare
time="2019-10-29T06:07:43.027161015Z" level=debug msg="diff applied" d="285.753µs" dgst="sha256:3b1e2811c16d060ba852cd268dc99a8bc4b14498d119e3752729272880db48a6" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=101
time="2019-10-29T06:07:43.028788881Z" level=info msg="TearDown network for sandbox \"98c00e6d21659e7bb6e6d6a93e3fa06d69f4af210b51cdfbd01c3259dd3bf9ba\" successfully"
time="2019-10-29T06:07:43.028817938Z" level=info msg="StopPodSandbox for \"98c00e6d21659e7bb6e6d6a93e3fa06d69f4af210b51cdfbd01c3259dd3bf9ba\" returns successfully"
time="2019-10-29T06:07:43.029300928Z" level=info msg="RemovePodSandbox for \"98c00e6d21659e7bb6e6d6a93e3fa06d69f4af210b51cdfbd01c3259dd3bf9ba\""
time="2019-10-29T06:07:43.029680135Z" level=debug msg="removed snapshot" key="k8s.io/160/sha256:52e5f8c2ed3df1cd4a08dfb0a9d769356f8c57b01ffa5ab91cadb74d7bee7141" snapshotter=overlayfs
time="2019-10-29T06:07:43.029967481Z" level=debug msg="event published" ns=k8s.io topic=/images/create type=containerd.services.images.v1.ImageCreate
time="2019-10-29T06:07:43.030427905Z" level=debug msg="Received containerd event timestamp - 2019-10-29 06:07:43.029959886 +0000 UTC, namespace - \"k8s.io\", topic - \"/images/create\""
time="2019-10-29T06:07:43.030473055Z" level=info msg="ImageCreate event &ImageCreate{Name:gcr.io/cri-tools/test-image-1:latest,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2019-10-29T06:07:43.032014729Z" level=debug msg="removed snapshot" key="k8s.io/157/sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea" snapshotter=overlayfs
time="2019-10-29T06:07:43.036751162Z" level=error msg="PullImage \"gcr.io/cri-tools/test-image-1:latest\" failed" error="rpc error: code = NotFound desc = failed to pull and unpack image \"gcr.io/cri-tools/test-image-1:latest\": unpack: failed to prepare extraction snapshot \"extract-18423921-90IJ sha256:0c162e7d4d073be6be79d5e3235cdb0cb36c23080b9e1704f4536dff37c8feee\": parent snapshot sha256:0d315111b4847e8cd50514ca19657d1e8d827f4e128d172ce8b2f76a04f3faea does not exist: not found"