Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Buildah failing to pull large docker images with error storing to blob file #2224

Closed
smothiki opened this issue Mar 13, 2020 · 49 comments
Closed

Comments

@smothiki
Copy link

smothiki commented Mar 13, 2020

(Edited by @TomSweeneyRedHat just to make the post more readable in GitHub. No content changes)

I'm running buildah in a privileged pod. Trying to pull a docker image of size 10GB and constantly failing.

Steps to reproduce the issue:

  1. buildah pull a really large image with multiple layers.

Describe the results you received:

failed with the below error

DEBU error copying src image ["docker://docker-registry.infra.cloudera.com/cdsw/engine:11"] to dest image ["docker-registry.infra.cloudera.com/cdsw/engine:11"] err: Error writing blob: error storing blob to file "/var/tmp/storage105374735/10": unexpected EOF 
DEBU error pulling image "docker://docker-registry.infra.cloudera.com/cdsw/engine:11": Error writing blob: error storing blob to file "/var/tmp/storage105374735/10": unexpected EOF 
DEBU unable to pull and read image "docker-registry.infra.cloudera.com/cdsw/engine:11": Error writing blob: error storing blob to file "/var/tmp/storage105374735/10": unexpected EOF 
Error writing blob: error storing blob to file "/var/tmp/storage105374735/10": unexpected EOF

Describe the results you expected:

Should be able to pull the image successfully

Output of rpm -q buildah or apt list buildah:

(paste your output here)

Output of buildah version:

Version:         1.12.0-dev
Go Version:      go1.13.5
Image Spec:      1.0.1-dev
Runtime Spec:    1.0.1-dev
CNI Spec:        0.4.0
libcni Version:  v0.7.1
image Version:   5.0.0
Git Commit:      8d6869bc
Built:           Tue Dec 10 18:02:04 2019
OS/Arch:         linux/amd64

Output of podman version if reporting a podman build issue:

(paste your output here)

Output of cat /etc/*release:

NAME=Fedora
VERSION="31 (Container Image)"
ID=fedora
VERSION_ID=31
VERSION_CODENAME=""
PLATFORM_ID="platform:f31"
PRETTY_NAME="Fedora 31 (Container Image)"
ANSI_COLOR="0;34"
LOGO=fedora-logo-icon
CPE_NAME="cpe:/o:fedoraproject:fedora:31"
HOME_URL="https://fedoraproject.org/"
DOCUMENTATION_URL="https://docs.fedoraproject.org/en-US/fedora/f31/system-administrators-guide/"
SUPPORT_URL="https://fedoraproject.org/wiki/Communicating_and_getting_help"
BUG_REPORT_URL="https://bugzilla.redhat.com/"
REDHAT_BUGZILLA_PRODUCT="Fedora"
REDHAT_BUGZILLA_PRODUCT_VERSION=31
REDHAT_SUPPORT_PRODUCT="Fedora"
REDHAT_SUPPORT_PRODUCT_VERSION=31
PRIVACY_POLICY_URL="https://fedoraproject.org/wiki/Legal:PrivacyPolicy"
VARIANT="Container Image"
VARIANT_ID=container
Fedora release 31 (Thirty One)
Fedora release 31 (Thirty One)

Output of uname -a:

Linux s2i-builder-54889679f5-5hh9s 4.18.0-147.0.3.el8_1.x86_64 #1 SMP Mon Nov 11 12:58:36 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Output of cat /etc/containers/storage.conf:

[storage]

driver = "overlay"

runroot = "/var/run/containers/storage"

graphroot = "/var/lib/containers/storage"

[storage.options]
additionalimagestores = [
]
size = ""
mount_program = "/usr/bin/fuse-overlayfs"

override_kernel_check = "true"
mountopt = "nodev,metacopy=on"
[storage.options.thinpool]

   ostree_repo = ""

   skip_mount_home = "false"
@TomSweeneyRedHat
Copy link
Member

TomSweeneyRedHat commented Mar 14, 2020

@smothiki thanks for the issue report. It looks like you're running out of TMPDIR space in /var/tmp. Can you set the environment variable TMPDIR to a bigger filesystem? aka export TMPDIR=/var/realybigdir

@smothiki
Copy link
Author

TMPDIR is large and didnt work

# df -h  /var/tmp/storage673617673/
Filesystem      Size  Used Avail Use% Mounted on
/dev/rbd11       98G  2.3G   96G   3% /var/tmp

I think this issue is also related #1092

@TomSweeneyRedHat
Copy link
Member

@smothiki well darn, was hoping moving the TMPDIR would solve this for you. At first glance, I don't think this is related to #1092. That one was running into a "no such file or directory" error, while yours is running into an "unexpected EOF".

@smothiki
Copy link
Author

@TomSweeneyRedHat what else.I can try. We are stuck on migrating to openshift because of this error. Shall I try giving different temp dir?. Could you point me to the code where it might be happening?

@TomSweeneyRedHat
Copy link
Member

@smothiki It's happening somewhere deep in the parsing of the layer by the storage code. I suspect in the UnmarshalText() function, but I can't pinpoint it.

Couple of questions. Can you pull the image using Docker? Please do try another tmpdir, it won't hurt, but at this point I'm not as optimistic.

Can you share the image you're trying to pull and/or the exact command and Dockerfiles (if any) that you're using?

@nalind @rhatdan thoughts?

@smothiki
Copy link
Author

smothiki commented Mar 15, 2020

@TomSweeneyRedHat I executed this command TMPDIR=/tmp buildah pull docker-registry.infra.cloudera.com/cdsw/engine:11 but still getting this error Error writing blob: error storing blob to file "/var/tmp/storage713093592/10": unexpected EOF. is TMPDIR being considered?

I can't share the image, unfortunately.

@rhatdan
Copy link
Member

rhatdan commented Mar 16, 2020

@mtrmac @vrothberg WDYT?

@mtrmac
Copy link
Contributor

mtrmac commented Mar 16, 2020

@smothiki thanks for the issue report. It looks like you're running out of TMPDIR space in /var/tmp.

Is there anything in particular to point at that?


My best guess is that the error is actually when reading the image (perhaps the server is failing the read, or the compressed file is corrupt, possibly at https://github.com/klauspost/pgzip/blob/3286875a1223e4bd304d6bcc4bb2c463fae762f2/gunzip.go#L543 .

@smothiki Could you please try the following, to separate the read from the write paths?

  • skopeo copy docker://docker-registry.infra.cloudera.com/cdsw/engine:11 dir:/some/tmp/directory/that/is/big/enough (should verify whether the image is readable at all)
  • skopeo copy docker://docker-registry.infra.cloudera.com/cdsw/engine:11 docker-archive:/some/tmp/directory/that/is/big/enough:test (should verify whether the image can be decompressed)
  • buildah pull docker-archive:/some/tmp/directory/that/is/big/enough:test (should whether the decompressed image can be pulled)

Also, the debug log of the original buildah pull, and of any of the commands above that fail, could be useful.

@mtrmac
Copy link
Contributor

mtrmac commented Mar 16, 2020

Oh, the /some/tmp/directory should be different for the dir: and docker-archive: tests (but the output of the copy to docker-archive should be used for the buildah pull input).

@smothiki
Copy link
Author

@mtrmac I did the three steps with skopeo as mentioned

skopeo copy docker://docker-registry.infra.cloudera.com/cdsw/engine:11 dir://home/some/engine/test2
skopeo copy docker://docker-registry.infra.cloudera.com/cdsw/engine:11 docker-archive:/home/some/engine/test:test worked

du -sh /home/smothiki/engine/test2
2.9G	/home/smothiki/engine/test2
 du -sh /home/some/engine/test
7.1G	/home/some/engine/test

buildah pull docker-archive:/home/some/engine/test:test failed with below error

DEBU[0000] cached value indicated that overlay is supported 
DEBU[0000] cached value indicated that metacopy is not being used 
DEBU[0000] cached value indicated that native-diff is usable 
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=true, usingMetacopy=false 

error computing local image name for "docker-archive:/home/some/engine/test:docker.io/library/test:latest": error opening tarfile "/home/some/engine/test:docker.io/library/test:latest" as a source image: error opening file "/home/some/engine/test:docker.io/library/test:latest": open /home/some/engine/test:docker.io/library/test:latest: no such file or directory

@smothiki
Copy link
Author

The weird part is we have the same image in a different registry and buildah pull was working with that image and skopeo inspect of two images have the same layers

@mtrmac
Copy link
Contributor

mtrmac commented Mar 18, 2020

I apologize, my mistake; docker-archive: uses a different decompression code than buildah pull. So, that one is not representative.

As for the buildah pull, maybe just buildah pull docker-archive:/home/some/engine/test.

Anyway, @nalind, any idea how to separately test/invoke the c/storage/pkg/archive decompression path?

@nalind
Copy link
Member

nalind commented Mar 18, 2020

Outside of writing code to call it directly, there isn't really a "decompress this" path from the CLI, though I suppose using skopeo copy with a destination that looks something like "containers-storage:[vfs@/tmp/root+/tmp/runroot]${imagename}" (quotes included) will add the minimal amount of processing (decompressing plus extracting archives) beyond just copying ${imagename}'s layers as-is.

This particular error message looks like it's coming from storageImageDestination.PutBlob(), which attempts to decompress a blob to determine what the corresponding diffID would be, but which doesn't attempt to extract the layer's contents. This suggests to me that the "unexpected EOF" error is occurring during decompression and not while extracting layer contents from the decompressed archive.

If you've got the image in a directory, I'd be curious if switching to the directory and running jq -r '.layers[].digest[7:]' manifest.json | xargs -t gzip -t produces any errors from gzip. It's a different code base than we use for decompression, but that should let us at least be reasonably sure that the layers weren't compressed incorrectly. (If the source image is not in v2s2 or OCI format, you may need to skopeo copy with --format v2s2 or --format oci for that jq command to work.)

@rexagod
Copy link

rexagod commented Jun 2, 2020

sudo rm -rf /var/tmp/storage* fixed it for me.

@Asisranjan
Copy link

I am also facing same issue. I tried the approach suggested above
a) setting TMPDIR b) rm -rf /var/tmp/storage*
none of them working.

The strange part is, i was able to build image using buildah just 1 day before in same setup, however same is not working now,

I am able to pull image using docker but not using buildah, buildah pull is throwing error "Error writing blob: error storing blob to file "/var/tmp/storage951065376/3": unexpected EOF"

Do we have solution for this issue. Could anyone please help.

Thanks
Asisranjan Nayak

@doc-olliday
Copy link

Hi,
obviously we discover the same problem when using podman pull

...
[2020-07-29T11:49:19.617Z] Error: unable to pull <someinternalregistry>/platform/core/api:201907_bn718: Error writing blob: error storing blob to file "/var/tmp/storage034983138/32": unexpected EOF
...

The image is hosted on an internal registry, therefore we assume no network issues.
TMP-dir has sufficient space:

/dev/mapper/centos-var                       17G  1.8G   16G  11% /var

The problem doesn't occur always with the same image and same worker node, but rather occasionally with different images and worker nodes.

$ podman version
Version:      2.0.1
API Version:  1
Go Version:   go1.13.4
Built:        Thu Jan  1 01:00:00 1970
OS/Arch:      linux/amd64
 buildah version
Version:         1.15.0
Go Version:      go1.13.4
Image Spec:      1.0.1-dev
Runtime Spec:    1.0.2-dev
CNI Spec:        0.4.0
libcni Version:  
image Version:   5.5.1
Git Commit:      
Built:           Thu Jan  1 01:00:00 1970
OS/Arch:         linux/amd64

Might there be the same root cause or should we file an issue against podman?

@rhatdan
Copy link
Member

rhatdan commented Jul 30, 2020

Podman and Buildah use the same underlying library containers/image and the issue could very well be in there.

@mtrmac
Copy link
Contributor

mtrmac commented Aug 1, 2020

The problem doesn't occur always with the same image and same worker node, but rather occasionally with different images and worker nodes.

Hum, that’s concerning. Can you narrow it down to a set of images, or possibly a probability? Tracking down a concurrency bug in decompression is going to be ugly, especially without a reproducer.

If you do get a reproducer (even if only statistical, i.e. “this fails in 10% of cases” implies 1000 tries is probably enough to validate), it would be interesting to try replacing the use of pgzip with the standard Go gzip.

@doc-olliday
Copy link

O.k. it's weird.
We've analyzed it and 90% of this error occurred on one worker node with one kind of image. To see, if the worker node is responsible for the problem, we disabled this node. Now, the problem occurs on another node with other image types (?!)
So, we're going on to investigate our infrastructure and image builds.

@mtrmac When you say replacing pgzip with gzip, can we do that on our own by configuration or would this be done programmatically?

@mtrmac
Copy link
Contributor

mtrmac commented Aug 5, 2020

That would be a change in the Go code + recompile.

BTW we have now seen a report of an “unexpected EOF” when copying large images where no compression is involved; that well might be an entirely different bug (initial data seems to suggest so), or it might mean that the focus on compression is misguided.

@mtrmac
Copy link
Contributor

mtrmac commented Aug 5, 2020

That would be a change in the Go code + recompile.

Basically find all lines like

and replace them with pgzip "compress/gzip" … though it might require a few more changes or similar changes to not-100%-the-same lines.

@doc-olliday
Copy link

We give up, for now. Due to too many problems we've migrated back to docker-ce.
Thank you for your help.

@rhatdan rhatdan closed this as completed Oct 7, 2020
@inidona
Copy link

inidona commented Mar 25, 2021

i have the problem also in a big layer. it comes from ibm/webshere and it would be very nice to fix it.
Do you need any more informations ?

thanks

@rhatdan
Copy link
Member

rhatdan commented Mar 25, 2021

I am not sure this can be fixed. Basically we pull down the image blob to disk, then we explode the image blob into containers/storage. Worse case we end up with 2X Size.

@inidona
Copy link

inidona commented Mar 26, 2021

but what can we do to solve this ? maybe some debug logging ? Maybe the hint above about replacing pgzip with gzip ?
The TMPDIR hat 300 GB available, so i think it is no problem with storage itselves.
We running the buildah image in an Kubernetes Cluster, maybe a hint ?
thanks

@rhatdan
Copy link
Member

rhatdan commented Mar 26, 2021

@nalind Ideas?

@inidona
Copy link

inidona commented Apr 15, 2021

@rhatdan @nalind ideas ? can i do something ?

@rhatdan
Copy link
Member

rhatdan commented Apr 15, 2021

We have a pull request to update the compression libraries for containers/storage. But this would make the image non standard and would not be usable via other container engines.

containers/storage#775

@giuseppe PTAL

Bottom line right now, I believe you need up to 2x size to store the image.

@inidona
Copy link

inidona commented Apr 16, 2021

@rhatdan i have no problem with the storage, the file system is big enough. but it doesn´t work on pulling the layer from the docker registry.
If i build the same Dockerfile with docker it works fine

17:58:05 level=debug msg="error copying src image ["docker://was-traditional-base:9.0.5.4"] to dest image ["was-traditional-base:9.0.5.4"] err: Error writing blob: error storing blob to file "/buildah/storage927894400/9": error happened during read: unexpected EOF"
17:58:05 level=debug msg="error pulling image "docker://was-traditional-base:9.0.5.4": Error writing blob: error storing blob to file "/buildah/storage927894400/9": error happened during read: unexpected EOF"
17:58:05 level=debug msg="unable to pull and read image "was-traditional-base:9.0.5.4": Error writing blob: error storing blob to file "/buildah/storage927894400/9": error happened during read: unexpected EOF"
17:58:05 error creating build container: Error writing blob: error storing blob to file "/buildah/storage927894400/9": error happened during read: unexpected EOF

@rhatdan
Copy link
Member

rhatdan commented Apr 16, 2021

@mtrmac @vrothberg WDYT?

@rhatdan rhatdan reopened this Apr 16, 2021
@nalind
Copy link
Member

nalind commented Apr 16, 2021

Do we have the full log for this? I'm wondering if we're hitting a timeout.

@inidona
Copy link

inidona commented Apr 20, 2021

@nalind

here the full log, last night i saw the job was one time running, maybe there is a download issue and buildah needed to retry the download, i saw in dockerbuild sometimes retries of layer downloads ?

Myabe there was on option to make this
const (
maxPullPushRetries = 3
pullPushRetryDelay = 2 * time.Second
)

configurable ?

buildah bud --debug --pull --build-arg PORT_PREFIX=21 --build-arg SERVER_FILE=ai-db2 --build-arg SERVER_DEBUG=false --build-arg SERVER_REBEL=false --build-arg SERVER_JACOCO=true -t myregistry.com/v2/orga/xx--was-traditional-ai:db2-compose-9.0.5.4 -t mrs-nexus.salt-solutions.de:5003/mrs/mrs-was-traditional-ai:db2-compose-9.0.5.4 . level=debug msg="Pull Policy for pull [PullIfNewer]" level=debug msg="[graphdriver] trying provided driver \"overlay\"" level=debug msg="overlay: imagestore=/var/lib/shared" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" level=debug msg="backingFs=overlayfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false" level=debug msg="reading local Dockerfile \"/home/jenkins/agent/workspace/build-docker-was_feature_buildah/Dockerfile\"" level=debug msg="base: \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="FROM \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" STEP 1: FROM myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4 level=debug msg="Loading registries configuration \"/etc/containers/registries.conf\"" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf.d/000-shortnames.conf\"" level=debug msg="registry \"myregistry.com\" is not listed in registries configuration \"/etc/containers/registries.conf\", assuming it's not blocked" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/run/containers/storage:overlay.imagestore=/var/lib/shared,overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mountopt=nodev,fsync=0]myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/run/containers/storage:overlay.imagestore=/var/lib/shared,overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mountopt=nodev,fsync=0]myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="copying \"docker://myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\" to \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="Trying to access \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="Trying to access \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"" level=debug msg="Returning credentials from /run/containers/0/auth.json" level=debug msg="Using registries.d directory /etc/containers/registries.d for sigstore configuration" level=debug msg=" Using \"default-docker\" configuration" level=debug msg=" No signature storage configuration found for myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4, using built-in default file:///var/lib/containers/sigstore" level=debug msg="Looking for TLS certificates and private keys in /etc/docker/certs.d/myregistry.com" level=debug msg="GET https://myregistry.com/v2/" level=debug msg="Ping https://myregistry.com/v2/ status 401" level=debug msg="GET https://myregistry.com/service/token?account=robot%24mrs-write&scope=repository%3Amrs%2Fmrs-was-traditional-base%3Apull&service=harbor-registry" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/manifests/9.0.5.4" level=debug msg="Content-Type from manifest GET is \"application/vnd.docker.distribution.manifest.v2+json\"" level=debug msg="Using blob info cache at /var/lib/containers/cache/blob-info-cache-v1.boltdb" level=debug msg="IsRunningImageAllowed for image docker:myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4" level=debug msg=" Using default policy section" level=debug msg=" Requirement 0: allowed" level=debug msg="Overall: allowed" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:5580e6375c85bba631ef3d197da94ac6b78405f928ec247166d7e31b59662891" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:5580e6375c85bba631ef3d197da94ac6b78405f928ec247166d7e31b59662891" Getting image source signatures level=debug msg="Reading /var/lib/containers/sigstore/mrs/mrs-was-traditional-base@sha256=d5c05f3d7d1f0d006381ad2b0187df6607f29a9c61d59583c54bd73c404b9292/signature-1" level=debug msg="Manifest has MIME type application/vnd.docker.distribution.manifest.v2+json, ordered candidate list [application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.v1+prettyjws, application/vnd.oci.image.manifest.v1+json, application/vnd.docker.distribution.manifest.v1+json]" level=debug msg="... will first try using the original manifest unmodified" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" Copying blob sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6" Copying blob sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937" Copying blob sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606" Copying blob sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c" Copying blob sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566" Copying blob sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73" Copying blob sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb" Copying blob sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e" Copying blob sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0" Copying blob sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432" Copying blob sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9" Copying blob sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de" Copying blob sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11" Copying blob sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0" Copying blob sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9" Copying blob sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1" Copying blob sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f" Copying blob sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c" Copying blob sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b" Copying blob sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" Copying blob sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a" Copying blob sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c" Copying blob sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307" Copying blob sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73" Copying blob sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332" Copying blob sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf" Copying blob sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff" Copying blob sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5" Copying blob sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4" Copying blob sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13" Copying blob sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef" Copying blob sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="Downloading /v2/orga/xx-traditional-base/blobs/sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7" level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7" Copying blob sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7 level=debug msg="Detected compression format gzip" level=debug msg="Using original blob without modification" level=debug msg="error copying src image [\"docker://myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"] to dest image [\"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\"] err: Error writing blob: error storing blob to file \"/buildah/storage728878093/9\": error happened during read: unexpected EOF" level=debug msg="error pulling image \"docker://myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\": Error writing blob: error storing blob to file \"/buildah/storage728878093/9\": error happened during read: unexpected EOF" level=debug msg="unable to pull and read image \"myregistry.com/v2/orga/xx--was-traditional-base:9.0.5.4\": Error writing blob: error storing blob to file \"/buildah/storage728878093/9\": error happened during read: unexpected EOF" error creating build container: Error writing blob: error storing blob to file "/buildah/storage728878093/9": error happened during read: unexpected EOF level=debug msg="shutting down the store"

@nalind
Copy link
Member

nalind commented Apr 20, 2021

Hmm, unfortunately we're not logging relative timestamps in those messages, so I don't have a way of knowing how much time passed between the point when the client requested the layers and the point when it got those EOFs (have opened #3168 to restore them). If it was a consistent amount of time for each layer, that would lend some support to the idea that the registry is cutting the client off after a certain amount of time. If you're running the job directly or via a script, can you run it under /usr/bin/time? That might provide enough information for us to either confirm or rule out that failures are related to the time that elapses.

@inidona
Copy link

inidona commented Apr 21, 2021

@nalind here the log with timestamps included. Our jenkins was building the images last night every hour, two times it works fine, the other tries it was broken. Maybe the download takes to much time ?

06:11:53 + buildah bud --debug --pull-always . 06:11:53 level=debug msg="Pull Policy for pull [PullAlways]" 06:11:53 level=debug msg="[graphdriver] trying provided driver \"overlay\"" 06:11:53 level=debug msg="overlay: imagestore=/var/lib/shared" 06:11:53 level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" 06:11:53 level=debug msg="backingFs=overlayfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false" 06:11:53 level=debug msg="reading local Dockerfile \"/home/jenkins/agent/workspace/build-docker-was_feature_buildah/Dockerfile\"" 06:11:53 level=debug msg="base: \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="FROM \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 STEP 1: FROM myregistry.com/orga/xx-was-traditional-base:9.0.5.4 06:11:53 level=debug msg="Loading registries configuration \"/etc/containers/registries.conf\"" 06:11:53 level=debug msg="Loading registries configuration \"/etc/containers/registries.conf.d/000-shortnames.conf\"" 06:11:53 level=debug msg="registry \"myregistry.com\" is not listed in registries configuration \"/etc/containers/registries.conf\", assuming it's not blocked" 06:11:53 level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/run/containers/storage:overlay.imagestore=/var/lib/shared,overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mountopt=nodev,fsync=0]myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/run/containers/storage:overlay.imagestore=/var/lib/shared,overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mountopt=nodev,fsync=0]myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="copying \"docker://myregistry.com/orga/xx-was-traditional-base:9.0.5.4\" to \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="Trying to access \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="Trying to access \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"" 06:11:53 level=debug msg="Returning credentials from /run/containers/0/auth.json" 06:11:53 level=debug msg="Using registries.d directory /etc/containers/registries.d for sigstore configuration" 06:11:53 level=debug msg=" Using \"default-docker\" configuration" 06:11:53 level=debug msg=" No signature storage configuration found for myregistry.com/orga/xx-was-traditional-base:9.0.5.4, using built-in default file:///var/lib/containers/sigstore" 06:11:53 level=debug msg="Looking for TLS certificates and private keys in /etc/docker/certs.d/myregistry.com" 06:11:53 level=debug msg="GET https://myregistry.com/v2/" 06:11:53 level=debug msg="Ping https://myregistry.com/v2/ status 401" 06:11:53 level=debug msg="GET https://myregistry.com/service/token?account=robot%24mrs-write&scope=repository%3Amrs%2Fmrs-was-traditional-base%3Apull&service=harbor-registry" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/manifests/9.0.5.4" 06:11:54 level=debug msg="Content-Type from manifest GET is \"application/vnd.docker.distribution.manifest.v2+json\"" 06:11:54 level=debug msg="Using blob info cache at /var/lib/containers/cache/blob-info-cache-v1.boltdb" 06:11:54 level=debug msg="IsRunningImageAllowed for image docker:myregistry.com/orga/xx-was-traditional-base:9.0.5.4" 06:11:54 level=debug msg=" Using default policy section" 06:11:54 level=debug msg=" Requirement 0: allowed" 06:11:54 level=debug msg="Overall: allowed" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:5580e6375c85bba631ef3d197da94ac6b78405f928ec247166d7e31b59662891" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:5580e6375c85bba631ef3d197da94ac6b78405f928ec247166d7e31b59662891" 06:11:54 Getting image source signatures 06:11:54 level=debug msg="Reading /var/lib/containers/sigstore/orga/xx-was-traditional-base@sha256=d5c05f3d7d1f0d006381ad2b0187df6607f29a9c61d59583c54bd73c404b9292/signature-1" 06:11:54 level=debug msg="Manifest has MIME type application/vnd.docker.distribution.manifest.v2+json, ordered candidate list [application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.v1+prettyjws, application/vnd.oci.image.manifest.v1+json, application/vnd.docker.distribution.manifest.v1+json]" 06:11:54 level=debug msg="... will first try using the original manifest unmodified" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" 06:11:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" 06:11:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" 06:11:55 Copying blob sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 Copying blob sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 Copying blob sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937" 06:11:55 Copying blob sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606" 06:11:55 Copying blob sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 Copying blob sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 Copying blob sha256:9ccdec6426bd5201cbd7cbb64e6a7096739b66208338b566ea44ff4cb5329606 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c" 06:11:55 Copying blob sha256:67a55e029d09669deb303298afb00c21969c6914a5e26553ae0c9e6a41ce6937 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 Copying blob sha256:a1901c4497fbbba20008e2b1d25c4c43ff669f3525c5839d9daf32b069e90cd6 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566" 06:11:55 Copying blob sha256:ea1582c38d7ee74c67702142793a89b82d2b22b21ba49ce53d6521ca91e2651c 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73" 06:11:55 Copying blob sha256:2d06ce8b0f7dfd15705504da107a33440aceb88b9ecacac488e15ed3b0a4f566 06:11:55 level=debug msg="Detected compression format gzip" 06:11:55 level=debug msg="Using original blob without modification" 06:11:55 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb" 06:11:55 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb" 06:11:56 Copying blob sha256:0461731cbae0136f91a1fb598c0782e3d1962f19029af950796fe87c7e869a73 06:11:56 level=debug msg="Detected compression format gzip" 06:11:56 level=debug msg="Using original blob without modification" 06:11:56 Copying blob sha256:0111a8615ff3c59fdce3b132f5e8e10a183d8dca38b654e7b1d765fe2cafeffb 06:11:56 level=debug msg="Detected compression format gzip" 06:11:56 level=debug msg="Using original blob without modification" 06:11:56 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e" 06:11:56 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e" 06:11:56 Copying blob sha256:c76f916dc60404702963ef705aff41b5a8b545a52e870a5201fcc081aed4813e 06:11:56 level=debug msg="Detected compression format gzip" 06:11:56 level=debug msg="Using original blob without modification" 06:11:57 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0" 06:11:57 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0" 06:11:57 Copying blob sha256:120a32d95996389bf322e1f28aafe220935d35dfe1f0bd142f016b852a8ac2e0 06:11:57 level=debug msg="Detected compression format gzip" 06:11:57 level=debug msg="Using original blob without modification" 06:11:57 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432" 06:11:57 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432" 06:11:57 Copying blob sha256:de9441917255ad7f8a212bd80def63524fb7a0a310293f48e68e39646e9ea432 06:11:57 level=debug msg="Detected compression format gzip" 06:11:57 level=debug msg="Using original blob without modification" 06:11:57 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9" 06:11:57 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9" 06:11:57 Copying blob sha256:06c535fc54fcc71ae5f58164548b08b6a14273339a178276eae4b77de53604f9 06:11:57 level=debug msg="Detected compression format gzip" 06:11:57 level=debug msg="Using original blob without modification" 06:11:58 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de" 06:11:58 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de" 06:11:59 Copying blob sha256:5d77d68929c9851d450f4b059ec7e2653d5966e1fcc168644d744dc3c9ecf1de 06:11:59 level=debug msg="Detected compression format gzip" 06:11:59 level=debug msg="Using original blob without modification" 06:11:59 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11" 06:11:59 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11" 06:11:59 Copying blob sha256:41eb2b813f815b210396b1bd885e371df41e70d52a932ad0fab2150ab2867d11 06:11:59 level=debug msg="Detected compression format gzip" 06:11:59 level=debug msg="Using original blob without modification" 06:11:59 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0" 06:11:59 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0" 06:11:59 Copying blob sha256:0a9a61da7f2131567f1920a067d4ea7b1d5ab6f76e78d3c656c3d3e2f6a859c0 06:11:59 level=debug msg="Detected compression format gzip" 06:11:59 level=debug msg="Using original blob without modification" 06:11:59 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9" 06:11:59 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9" 06:11:59 Copying blob sha256:7268c212ab836cdb72ab3548bbf7c6e7e8ad16a9f6da5257217feb2524d6bdf9 06:11:59 level=debug msg="Detected compression format gzip" 06:11:59 level=debug msg="Using original blob without modification" 06:11:59 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1" 06:11:59 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1" 06:12:00 Copying blob sha256:3fae37946b0144f389bc57a426f3a77cc06827edf8865b9945645051977720b1 06:12:00 level=debug msg="Detected compression format gzip" 06:12:00 level=debug msg="Using original blob without modification" 06:12:00 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f" 06:12:00 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f" 06:12:00 Copying blob sha256:27dbad622150f508bb5b797cbdde158c62e372ecb7e0bc7551ef1fce9770b02f 06:12:00 level=debug msg="Detected compression format gzip" 06:12:00 level=debug msg="Using original blob without modification" 06:12:00 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c" 06:12:00 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c" 06:12:00 Copying blob sha256:1be9d68d0a21251fd394e461b71ad45da2bf4da922411acb6ff02121091c165c 06:12:00 level=debug msg="Detected compression format gzip" 06:12:00 level=debug msg="Using original blob without modification" 06:12:00 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba" 06:12:00 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba" 06:12:00 Copying blob sha256:59c27c2928cbc141088c5f330f996996eacc3a7e1ea7ca2f25386db554088fba 06:12:00 level=debug msg="Detected compression format gzip" 06:12:00 level=debug msg="Using original blob without modification" 06:12:02 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b" 06:12:02 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b" 06:12:02 Copying blob sha256:894d30cbeaf2a5f3b795e2475fff06289dc3b03c84edd345d78d10e35817f02b 06:12:02 level=debug msg="Detected compression format gzip" 06:12:02 level=debug msg="Detected compression format gzip" 06:12:02 level=debug msg="Using original blob without modification" 06:12:15 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a" 06:12:15 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a" 06:12:15 Copying blob sha256:95953104ff0587289f925eb1d78bea005dee297dd5201d3e52c295b275f27f4a 06:12:15 level=debug msg="Detected compression format gzip" 06:12:15 level=debug msg="Using original blob without modification" 06:12:19 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c" 06:12:19 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c" 06:12:19 Copying blob sha256:dfa55444e4ea773501e40ca33030b5fcf1ac6ef7e813780409e9fcd0a12f2f5c 06:12:19 level=debug msg="Detected compression format gzip" 06:12:19 level=debug msg="Using original blob without modification" 06:12:20 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307" 06:12:20 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307" 06:12:20 Copying blob sha256:d98b7a60de24f31f83769b31b5b0d3b70b2c60ad62842b9d1f0013abd7509307 06:12:20 level=debug msg="Detected compression format gzip" 06:12:20 level=debug msg="Using original blob without modification" 06:12:23 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73" 06:12:23 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73" 06:12:23 Copying blob sha256:1caf62ca185bfac15d6b6a0bf3557f5dedf57e1fac2d2915f603eee8c20a5b73 06:12:23 level=debug msg="Detected compression format gzip" 06:12:23 level=debug msg="Using original blob without modification" 06:12:52 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332" 06:12:52 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332" 06:12:52 Copying blob sha256:c8b3dd2b980801bdf4420f1d7f61fdfb3b409e018be44f3e23c24dae9bf6b332 06:12:52 level=debug msg="Detected compression format gzip" 06:12:52 level=debug msg="Using original blob without modification" 06:12:52 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf" 06:12:52 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf" 06:12:52 Copying blob sha256:da27c306392518dd066ee9be8e9b5343eb2bfc77c437b3a2ae2536e81c8acacf 06:12:52 level=debug msg="Detected compression format gzip" 06:12:52 level=debug msg="Using original blob without modification" 06:12:52 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff" 06:12:52 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff" 06:12:52 Copying blob sha256:014cdb38aa453e8d1c63e7f70bd3b8d9a4b43626128d8814e93869dcdb59a6ff 06:12:52 level=debug msg="Detected compression format gzip" 06:12:52 level=debug msg="Using original blob without modification" 06:12:52 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5" 06:12:52 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5" 06:12:52 Copying blob sha256:95bf28b959e78ea12a4aeefdb7619f82c9da2f8221c4c6aeb9c5a98988f7dbc5 06:12:52 level=debug msg="Detected compression format gzip" 06:12:52 level=debug msg="Using original blob without modification" 06:12:52 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4" 06:12:52 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4" 06:12:52 Copying blob sha256:f46d998defa914ba2ba4d5233b7c92cfce582ef255f3f0440512fe3ab73486f4 06:12:52 level=debug msg="Detected compression format gzip" 06:12:52 level=debug msg="Using original blob without modification" 06:12:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13" 06:12:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13" 06:12:54 Copying blob sha256:fe8d71e685d17badfe9d634864dc2ff4d7167fb76d6eb055fae4a4872b83ae13 06:12:54 level=debug msg="Detected compression format gzip" 06:12:54 level=debug msg="Using original blob without modification" 06:12:54 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef" 06:12:54 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef" 06:12:55 Copying blob sha256:28ac212d695654f5b3114996a7e462d63d7f44b6f70bc34569c7d2bad0c995ef 06:12:55 level=debug msg="Detected compression format gzip" 06:12:55 level=debug msg="Using original blob without modification" 06:14:33 level=debug msg="Downloading /v2/orga/xx-was-traditional-base/blobs/sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7" 06:14:33 level=debug msg="GET https://myregistry.com/v2/orga/xx-was-traditional-base/blobs/sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7" 06:14:33 Copying blob sha256:8ff280503f5fe58840a2071379bc984b062632646cb0e942778dc822975ec6d7 06:14:33 level=debug msg="Detected compression format gzip" 06:14:33 level=debug msg="Using original blob without modification" 06:19:29 level=debug msg="error copying src image [\"docker://myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"] to dest image [\"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\"] err: Error writing blob: error storing blob to file \"/buildah/storage131025225/9\": error happened during read: unexpected EOF" 06:19:29 level=debug msg="error pulling image \"docker://myregistry.com/orga/xx-was-traditional-base:9.0.5.4\": Error writing blob: error storing blob to file \"/buildah/storage131025225/9\": error happened during read: unexpected EOF" 06:19:29 level=debug msg="unable to pull and read image \"myregistry.com/orga/xx-was-traditional-base:9.0.5.4\": Error writing blob: error storing blob to file \"/buildah/storage131025225/9\": error happened during read: unexpected EOF" 06:19:29 error creating build container: Error writing blob: error storing blob to file "/buildah/storage131025225/9": error happened during read: unexpected EOF 06:19:29 level=debug msg="shutting down the store"

@nalind
Copy link
Member

nalind commented Apr 21, 2021

Wow, that's about five minutes with no messages between the last "copying blob / detected compression / using blob without modification" and the first "unexpected EOF" log message. That sure looks like a timeout to me. I don't see one being set in the client-side logic, but I wouldn't be that surprised if the server was giving up on clients after some amount of time to protect itself from potential denial-of-service attacks.
If this is happening because bandwidth is limited, trying to pull multiple layers simultaneously could be hurting us here. There's an API setting to control that, but I don't think we've been exposing it at the CLI level anywhere.

@rhatdan
Copy link
Member

rhatdan commented Apr 21, 2021

[engine]

Maximum number of image layers to be copied (pulled/pushed) simultaneously.

Not setting this field, or setting it to zero, will fall back to containers/image defaults.

image_parallel_copies=0

Containers.conf has the following, I think we default to 6.

@vrothberg
Copy link
Member

vrothberg commented Apr 21, 2021 via email

@inidona
Copy link

inidona commented Apr 21, 2021

@nalind you are right, the bandwith is limited because of an company vpn and the layers could be very big. in normal case the complete build of this images takes 12 mins. I looks like docker has bigger timeouts and more retries.
I used the original buildah docker images to run this build.

@rhatdan
Copy link
Member

rhatdan commented Apr 21, 2021

I thought I did wire it up. in podmna.

@inidona
Copy link

inidona commented Apr 22, 2021

hi tested containers.conf
11:05:42 + cat /etc/containers/containers.conf
11:05:42 [engine]
11:05:42 cgroup_manager = "cgroupfs"
11:05:42 image_parallel_copies=1

looks like the default of six downloads is used
11:05:45 level=debug msg="... will first try using the original manifest unmodified" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:90bbf62744b0ac03c4b56a24b15ff71d931c10a26582a34360fe3417846a4385" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:f528dedf0cd135ed3082b51d0b62c5abb9e86249f3edc884f5157137d507f241" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:ec1681b6a383e4ecedbeddd5abc596f3de835aed6db39a735f62395c8edbff30" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:73065c3381e910a5d140132655f7651235f9bbb6343773107676ce268df49e68" 11:05:45 level=debug msg="Downloading /v2/mrs/mrs-was-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" 11:05:45 level=debug msg="GET https://registry.app.corpintra.net/v2/mrs/mrs-was-traditional-base/blobs/sha256:c4d668e229cd131e0a8e4f8218dca628d9cf9697572875e355fe4b247b6aa9f0" 11:05:45 Copying blob sha256:ab00306bf8f3916ecbf6477950aaed93ad99fc0dc615e1b932319c6200021d6c 11:05:45 level=debug msg="Detected compression format gzip" 11:05:45 level=debug msg="Using original blob without modification"

@inidona
Copy link

inidona commented Apr 22, 2021

another update, i testet with a local fast connected registry the same build and everything works fine. Looks like a problem with slow connected registries.

rhatdan added a commit to rhatdan/buildah that referenced this issue Apr 22, 2021
Adding this feature to allow people with little band with to adjust the
ammount of threads pulling an image.

I don't have an easy way to test this other then manually.

[NO TESTS NEEDED]

Helps Fix: containers#2224

Signed-off-by: Daniel J Walsh <[email protected]>
@rhatdan
Copy link
Member

rhatdan commented Apr 22, 2021

@inidona PTAL a look at #3176, Sadly I did the grunt work in containers/image to hook this up, and then got distracted and never completed the wiring into Buildah.

@github-actions
Copy link

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented May 24, 2021

I believe with the parallel fixes this should be a fixed issue.

@rhatdan rhatdan closed this as completed May 24, 2021
@vyom-soft
Copy link

Hello,
I faced the issue today. Here is the log

STEP-GEN-ENV-FILE

Generated Env file

MAVEN_CLEAR_REPO=false

STEP-GENERATE

Application dockerfile generated in /gen-source/Dockerfile.gen
STEP-BUILD

STEP 1: FROM image-registry.openshift-image-registry.svc:5000/openshift/java:openjdk-11-ubi8
Getting image source signatures
Copying blob sha256:65c0f2178ac8a3c28f48efd26ccf16bd6f344fa88d1aa20efd3a25d5f99587c0
Copying blob sha256:8f403cb21126270e2d1551022b82c77c695ce40c9812795daf7ad77a05c2b9f6
Copying blob sha256:08506ddf42e87973062272df927a2cffa6476b7572b552d3ec2cf905c8b0ff3f
error creating build container: Error writing blob: error storing blob to file "/var/tmp/storage740391338/3": unexpected EOF
level=error msg="exit status 125"

what could be done to overcome this issue. Thank you.

@rhatdan
Copy link
Member

rhatdan commented Jun 23, 2021

Could you use TMPDIR to set the temporary storage to point to a bigger location?

TMPDIR=$HOME/tmp buildah bud ...

@vyom-soft
Copy link

The error is no longer seen. After I added Persistence volume claim, storage with increased size.
Thank you.

@saraswat
Copy link

saraswat commented Nov 28, 2021

Faced this issue (I think) in downloading a container with a 2GB layer and a 3.2GB layer. All the other (smaller) layers would get pull'ed fine, but with these two as soon as the 1GB mark is reached, I get an "Error writing blob ... Unexpected EOF".

Fortunately the following work-around (implicitly suggested above -- nalind, 3/18/2020) worked:

skopeo copy docker://<remote image in registry> containers-storage:my-local-bits
podman pull containers-storage:my-local-bits

@hakanai
Copy link

hakanai commented Aug 11, 2022

I tried the workaround using skopeo copy, and the copy worked fine, but then podman pull failed with:

Error: unsupported transport containers-storage in "containers-storage:my-local-bits": only docker transport is supported

This is on macOS, which might be a factor.

I did see skopeo copy temporarily stop downloading a couple times, which suggests it maybe did get disconnected, but unlike podman/buildah, it properly retried/resumed the download and managed to get through.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Aug 31, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.