buildkit
buildkit copied to clipboard
Published
20 hours ago •
moby
moby
ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
Sorry for the vague error message.
We have a docker image that runs some things. Most times, it runs fine. Occasionally, it errors at the very end with a vague error message that is not from the yml file but I think is from the docker image exiting/ending. (All our commands run fine in the container. It is failing after the last one completes).
We run the image from a github action, if that matter.
The question is:
- What is not being solved?
- What deadline is exceeded?
- Can it be increased?
- Is there some way of running the container in debug mode for more information?
Thanks in advanced.
2023-10-04T20:39:13.3582748Z #24 exporting to client directory
2023-10-04T20:39:14.5610603Z #24 copying files 28B
2023-10-04T20:39:19.7302573Z #24 copying files 1.75GB 5.2s
2023-10-04T20:39:24.6910750Z #24 copying files 3.81GB 10.2s
2023-10-04T20:39:29.7983597Z #24 copying files 5.89GB 15.3s
2023-10-04T20:39:35.6174985Z #24 copying files 7.41GB 21.1s
2023-10-04T20:39:49.8824772Z #24 copying files 7.69GB 35.4s
2023-10-04T20:39:54.8880765Z #24 copying files 10.02GB 40.4s
2023-10-04T20:40:04.0740589Z #24 copying files 10.52GB 49.4s done
2023-10-04T20:40:04.0741210Z #24 DONE 50.7s
2023-10-04T20:41:33.3139725Z ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
2023-10-04T20:41:33.3615053Z ##[error]Process completed with exit code 1.
2023-10-04T20:41:33.4182323Z Cleaning up orphan processes
[epasveer@ws7-01 ~]$ docker --version
Docker version 20.10.8, build 3967b7d
[epasveer@ws7-01 ~]$
@crazy-max I remember you made some fixes in this area, does this look related? Although I think your fixes were for local images copy while this looks like files copy.
@epasveer Is there a reason you are exporting 10+GB with local exporter? The size itself shouldn't be limited but maybe there is a better solution for what you are doing. We have seen issues with grpc streams locking https://github.com/grpc/grpc-go/issues/4722 on big local exports but that looks to be a different case.
What deadline is exceeded?
This name comes from Go stdlib from a context created with context.WithTimeout reaching its maximum time. It is not clear where this timeout is coming from as we don't set time-based limits for the build or export. If there is a way we can reproduce this to debug further then let us know.
--debug should show a stacktrace although these context timeout errors are notoriously hard to debug because the stacktrace shows the function that got canceled, instead of what triggered the cancellation. It should still show if something got canceled in the middle of exporting or somewhere else.
@crazy-max I remember you made some fixes in this area, does this look related? Although I think your fixes were for local images copy while this looks like files copy.
You recall right, the fix was in filsync.DiffCopy: https://github.com/moby/buildkit/pull/4117/files#diff-7078d905e2386549f621b6a42a2be0947615d2b0d51b1c0acb5f13caaf126ac6R280 which is called when exporting to local client in https://github.com/moby/buildkit/blob/4c93208b9db9f8936b17c33bc93d19fc1bbf5266/exporter/local/export.go#L150 so maybe this kind of errors start to surface since that fix.
@crazy-max iiuc that function isn't really called in local export as that would call NewFSSyncTargetDir
@epasveer could you share your buildkitd logs? There might be something relevant in there (e.g. some errors get full stack traces, which could be quite useful if that's the case here).
First, let me thank everyone for replying. (I'm a "docker build" newbie).
could you share your buildkitd logs?
To be honest, I don't we are running that daemon anywhere. We are enabling buildkit when we run "docker build".
The first "build" builds the base image. The second build uses that and compiles/builds our code base. I'll include the 2 dockerfiles in the following comments.
- name: refresh docker base image
run: DOCKER_BUILDKIT=1 docker build --tag c7build:base --secret id=github,src=github_in.txt --file ${{env.basedockerfile}} .
- name: run the build
run: >
DOCKER_BUILDKIT=1 docker build
--build-arg branch2build=${{env.BRANCH_NAME}}
--build-arg bfbranch=${{ github.event.inputs.bluefin_branch }}
--build-arg swbranch=${{ github.event.inputs.sw_branch }}
--build-arg mtcbranch=${{ github.event.inputs.mtc_branch }}
--build-arg ptbbranch=${{ github.event.inputs.ptb_branch }}
--build-arg bassbranch=${{ github.event.inputs.bass_branch }}
--force-rm
--secret id=github,src=github_in.txt
-o ${{env.outputdir}}${{github.actor}}/${{ env.BRANCH_NAME }}
--no-cache -f ${{env.dockerfile}} .
BASE docker file.
[epasveer@ws7-02 build-docker]$ cat ./c7-build-base.docker
# trial centos7 build docker
#FROM docker.io/centos:7
FROM quay.io/centos/centos:centos7
ENV container docker
LABEL description="c7 build server base" \
version="0.08"
# install build reqs
# TODO minimize this list
RUN yum update -y \
&& yum install -y centos-release-scl epel-release \
&& yum install -y \
binutils-devel \
bison \
bzip2 \
bzip2-devel \
ccache \
cmake3 \
cmake \
cvs \
devtoolset-8 \
flex \
freetype-devel \
gcc-c++ \
gcc-gfortran \
ghostscript \
git \
git-lfs \
gtk2 \
ImageMagick \
libffi-devel \
libnl3-devel \
libudev-devel \
libX11-devel \
libXext-devel \
libXtst \
make \
mesa-libGLU-devel \
mpich \
patch \
poppler-utils \
python-backports-lzma \
subversion \
svn \
texinfo \
texlive-comment \
texlive-latex \
texlive-subfigure \
texlive-wrapfig \
texlive \
unzip \
wget \
which \
zlib \
&& yum clean all
# add a nice build user
RUN useradd -ms /bin/bash build
USER build
WORKDIR /home/build
# java complains about ASCII if you don't have this
ENV LC_ALL en_US.UTF-8
# intelmkl sucks and needs these
ENV USER build
ENV LOGNAME build
# avoid "host key verification failed." error accessing git repo
RUN mkdir -p -m u=rwx,go= .ssh \
&& ssh-keyscan github.com >> /home/build/.ssh/known_hosts
# This is a kludge to fix OPENCPS-3335.
# The solution in OPENCPS-3238 has not worked. BuildKit has more aggressive
# caching than plain docker making it near impossible to invalidate the cache
# for only one RUN step.
# See those two tickets and OPENCPS-3329 for further details.
RUN true
# Optimisation: clone the thirdparty packages folder into the base image
RUN --mount=type=secret,id=github,dst=/home/build/.gitconfig,uid=1000 \
mkdir -p builds/trunk/downloads \
&& pushd builds/trunk/downloads \
&& git clone [email protected]:<XXXXXXX>>/thirdpartysource.git packages \
&& popd
# The checkout/build instructions follow from here
[epasveer@ws7-02 build-docker]$
COMPILE code base docker file.
Running this image with "docker build" fails sometimes afer exectuing the last COPY.
[epasveer@ws7-02 build-docker]$ cat ./c7-build-a-branch.docker
# syntax=docker/dockerfile:experimental
# centos7 build from git
FROM c7build:base as builder
ENV container docker
ARG branch2build
ARG bfbranch
ARG swbranch
ARG mtcbranch
ARG ptbbranch
ARG bassbranch
LABEL description="c7 build via git" \
version="0.9"
# checkout using secret gitconfig, download_build has git needs
RUN \
echo "Building for XXXX branch: $branch2build" \
&& echo "Building for XXXX branch: $bfbranch" \
&& echo "Building for XXXXX branch: $swbranch" \
&& echo "Building for XXXXX branch: $mtcbranch" \
&& echo "Building for XXXXX branch: $ptbbranch" \
&& echo "Building for XXXXX branch: $bassbranch" \
&& echo "Building for thirdpartysource branch: main"
RUN --mount=type=secret,id=github,dst=/home/build/.gitconfig,uid=1000 \
mkdir -p builds/trunk/download_build_logs_build \
&& pushd builds/trunk/ \
&& source scl_source enable devtoolset-8 \
&& git clone [email protected]:XXXXXX/xxxxx.git -b $branch2build opencps \
&& git clone [email protected]:XXXXXX/xxxxx.git -b $bfbranch bluefin \
&& git clone [email protected]:XXXXXX/xxxxx-sw.git -b $swbranch opencps_sw \
&& git clone [email protected]:XXXXXX/xxxxx-mtc.git -b $mtcbranch opencp_mtc \
&& git clone [email protected]:XXXXXX/xxxxx-ptb.git -b $ptbbranch opencp_ptb \
&& git clone [email protected]:XXXXXX/xxxxx-bass.git -b $bassbranch opencp_bass \
&& pushd downloads/packages && git pull && popd \
&& ./xxxxx/src/build/download_build.py \
&& popd
# link nightly build scripts
RUN ln -s builds/trunk/xxxxx/src/build/build_xxxxx_nightly.py \
&& ln -s builds/trunk/xxxxx/src/build/build_xxxxxx_sw_nightly.py \
&& ln -s builds/trunk/xxxxx/src/build/build_xxxxx_mtc_nightly.py \
&& ln -s builds/trunk/xxxxx/src/build/build_xxxxx_ptb_nightly.py \
&& ln -s builds/trunk/xxxxx/src/build/build_xxxxx_bass_nightly.py
# add MTC
ADD --chown=build mtc.tgz /home/build/CONFIDENTIAL
# use --noredirect when things get tough
RUN cp /tmp/download_build_logs_build/* /home/build/builds/trunk/download_build_logs_build
RUN source scl_source enable devtoolset-8 && ./build_xxxxx_nightly.py --noredirect --notests && cp /tmp/download_build_logs_build/* /home/build/builds/trunk/download_build_logs_build
# build_xxxxx_*_nightly.py succeeds even if the archive isn't produced. Do additional check if all the archives are there
RUN ls /home/build/builds/trunk/archives/xxxxx-{bass,mtc,ptb,sw,time}-*.tar.gz
# copy via custom build outputs `-o outpath`
FROM scratch as export
COPY --from=builder /home/build/builds/trunk/archives/xxxxx-time*gz /archives/
COPY --from=builder /home/build/builds/trunk/archives/xxxxx-mtc*gz /archives/
COPY --from=builder /home/build/builds/trunk/archives/xxxxx-ptb*gz /archives/
COPY --from=builder /home/build/builds/trunk/archives/xxxxx-sw*gz /archives/
COPY --from=builder /home/build/builds/trunk/archives/xxxxx-bass*gz /archives/
COPY --from=builder /home/build/builds/trunk/logs/* /logs/
COPY --from=builder /home/build/builds/trunk/download_build_logs_build/* /download_build_logs/
Is there a reason you are exporting 10+GB with local exporter?
It's likely the result of the codebase compile/build that we are doing inside the docker.
Hey there, we started hitting this error irregularly over the last few months, im actually happy to see that there is now a new issue opened here. This is a stacktrace of when it happened in our CI build:
[12:49:07] #171 [test] exporting to image
[12:49:50] #171 pushing layers 95.8s done
[12:49:50] #171 CANCELED
[12:49:50]
[12:49:50] #173 [app] exporting to image
[12:49:50] #173 pushing layers 95.4s done
[12:49:50] #173 CANCELED
[12:49:50]
[12:49:50] #97 [venv] exporting cache to registry
[12:49:53] WARNING: No output specified for base, venv, build, build-frontend target(s) with docker-container driver. Build result will only remain in the build cache. To push result image into registry use --push or to load image into docker use --load
[12:49:53] ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
[12:49:53] 141 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
[12:49:53] google.golang.org/grpc.getChainUnaryInvoker.func1
[12:49:53] google.golang.org/[email protected]/clientconn.go:361
[12:49:53] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
[12:49:53] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
[12:49:53] github.com/moby/buildkit/client.filterInterceptor.func1
[12:49:53] github.com/moby/[email protected]/client/client.go:384
[12:49:53] google.golang.org/grpc.chainUnaryClientInterceptors.func1
[12:49:53] google.golang.org/[email protected]/clientconn.go:349
[12:49:53] google.golang.org/grpc.(*ClientConn).Invoke
[12:49:53] google.golang.org/[email protected]/call.go:35
[12:49:53] github.com/moby/buildkit/api/services/control.(*controlClient).Solve
[12:49:53] github.com/moby/[email protected]/api/services/control/control.pb.go:2208
[12:49:53] github.com/moby/buildkit/client.(*Client).solve.func2
[12:49:53] github.com/moby/[email protected]/client/solve.go:258
[12:49:53] golang.org/x/sync/errgroup.(*Group).Go.func1
[12:49:53] golang.org/x/[email protected]/errgroup/errgroup.go:75
[12:49:53] runtime.goexit
[12:49:53] runtime/asm_amd64.s:1598
[12:49:53]
[12:49:53] 141 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
[12:49:53] github.com/moby/buildkit/client.(*Client).solve.func2
[12:49:53] github.com/moby/[email protected]/client/solve.go:273
[12:49:53] golang.org/x/sync/errgroup.(*Group).Go.func1
[12:49:53] golang.org/x/[email protected]/errgroup/errgroup.go:75
[12:49:53] runtime.goexit
[12:49:53] runtime/asm_amd64.s:1598
we run dind, we have images with pretty large layers building and pushing in parallel. it happens sporadically, but mostly on the servers where the disks are sluggish.
Hi. I'm happy (maybe not) to see some others having the same problem.
@mzihlmann , what did you do to enable the stacktrace?
We have one of our gihub runners using a newer version of docker. Same occasional error.
[epasveer@ws7-02 ~]$ docker --version
Docker version 24.0.6, build ed223bc
[epasveer@ws7-02 ~]$ ~/Development/neofetch/neofetch/neofetch
.. [email protected]
.PLTJ. -------------------------------------------
<><><><> OS: CentOS Linux release 7.5.1804 (Core) x86_64
KKSSV' 4KKK LJ KKKL.'VSSKK Host: Dell Inc. 09N44V
KKV' 4KKKKK LJ KKKKAL 'VKK Kernel: 3.10.0-957.27.2.el7.x86_64
V' ' 'VKKKK LJ KKKKV' ' 'V Uptime: 22 hours, 24 mins
.4MA.' 'VKK LJ KKV' '.4Mb. Packages: 2640 (rpm)
. KKKKKA.' 'V LJ V' '.4KKKKK . Shell: bash 4.2.46
.4D KKKKKKKA.'' LJ ''.4KKKKKKK FA. Resolution: 1024x768
<QDD ++++++++++++ ++++++++++++ GFD> Terminal: /dev/pts/1
'VD KKKKKKKK'.. LJ ..'KKKKKKKK FV CPU: Intel Xeon E5-2690 v2 (40) @ 3.600GHz
' VKKKKK'. .4 LJ K. .'KKKKKV ' GPU: ASPEED Technology, Inc. ASPEED Graphics Family
'VK'. .4KK LJ KKA. .'KV' Memory: 33821MiB / 128875MiB
A. . .4KKKK LJ KKKKA. . .4
KKA. 'KKKKK LJ KKKKK' .4KK
KKSSA. VKKK LJ KKKV .4SSKK
<><><><>
'MKKM'
''
[epasveer@ws7-02 ~]$ findmnt /scratch/
TARGET SOURCE FSTYPE OPTIONS
/scratch /dev/sdb1 ext4 rw,relatime,data=ordered
[epasveer@ws7-02 ~]$
We are using an older version of centos, with an older kernel. I'm told we are still using VFS because of this. Not sure if that matters.
i saw @tonistiigi suggesting it before, simple as that:
- docker buildx bake -f docker-bake.hcl
+ docker --debug buildx bake -f docker-bake.hcl
Hi @tonistiigi ,
Does the below suggest the docker is contacting external sites? Or am I misinterpreting them?
Thanks.
[12:49:50] #97 [venv] exporting cache to registry
[12:49:53] WARNING: No output specified for base, venv, build, build-frontend target(s) with docker-container driver. Build result will only remain in the build cache. To push result image into registry use --push or to load image into docker use --load
[12:49:53] ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
[12:49:53] 141 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
[12:49:53] google.golang.org/grpc.getChainUnaryInvoker.func1
[12:49:53] google.golang.org/[email protected]/clientconn.go:361
[12:49:53] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
[12:49:53] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
[12:49:53] github.com/moby/buildkit/client.filterInterceptor.func1
[12:49:53] github.com/moby/[email protected]/client/client.go:384
[12:49:53] google.golang.org/grpc.chainUnaryClientInterceptors.func1
[12:49:53] google.golang.org/[email protected]/clientconn.go:349
[12:49:53] google.golang.org/grpc.(*ClientConn).Invoke
[12:49:53] google.golang.org/[email protected]/call.go:35
[12:49:53] github.com/moby/buildkit/api/services/control.(*controlClient).Solve
[12:49:53] github.com/moby/[email protected]/api/services/control/control.pb.go:2208
[12:49:53] github.com/moby/buildkit/client.(*Client).solve.func2
[12:49:53] github.com/moby/[email protected]/client/solve.go:258
[12:49:53] golang.org/x/sync/errgroup.(*Group).Go.func1
[12:49:53] golang.org/x/[email protected]/errgroup/errgroup.go:75
[12:49:53] runtime.goexit
its trying to upload the image/cache to the registry. telemetry is probably just a hook not really used. i think i made some progress today investigating. i stumbled over this https://github.com/docker/buildx/issues/456
basically their gist is that (filesystem) garbage-collector kicks in at a certain point, which makes everything come to crawl, leading to timeouts like the above.
one option to overcome it is to disable garbage collector in the builder (--buildkitd-flags '--oci-worker-gc=false' ) and instead perform some manual clean up from time to time (docker buildx prune --filter="until=1h" --force). in our gitlab-ci.yml:
before_script:
- docker context create <name>
- docker buildx create --use --name <name> <name>
- docker buildx create --buildkitd-flags '--oci-worker-gc=false' --use --name <name> <name>
script:
- docker buildx bake -f docker-bake.hcl
after_script:
- docker buildx prune --filter="until=1h" --force
still need to verify whether the issue is now gone for good though, i can tell you after a few days.
I am facing a similar issue, the build fails intermitently with context deadline exceeded. Please let me know if these tweaks are solving the issue for y'all. Thanks.
@epasveer Is this the only stacktrace you see with this error? This is the client side trace but "failed to solve" errors should usually include the daemon-side stacktrace as well.
If this is GC related like @mzihlmann suggests then GC invocations are logged to the daemon log when --buildkitd-flags '--debug' is set.
Hi @tonistiigi
The stack was included by @mzihlmann . I only included it as a reference.
We've added the '--debug' flag this past Friday. Hopefully we'll see some results tomorrow, which I will post.
So, with the --debug flag, we did encounter a "deadline exceeded".
#24 DONE 165.7s
ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
3843 v0.11.2 /usr/libexec/docker/cli-plugins/docker-buildx --debug buildx build --build-arg branch2build=OPENCPS-4320-implement-csi-continuous-record-processing-workflow --build-arg bfbranch=dev --build-arg swbranch=master --build-arg mtcbranch=master --build-arg ptbbranch=master --build-arg bassbranch=master --force-rm --secret id=github,src=github_in.txt -o /scratch/test_builds/suzanc/OPENCPS-4320-implement-csi-continuous-record-processing-workflow --no-cache -f ./c7-build-a-branch.docker .
google.golang.org/grpc.getChainUnaryInvoker.func1
google.golang.org/[email protected]/clientconn.go:361
go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
github.com/moby/buildkit/client.filterInterceptor.func1
github.com/moby/[email protected]/client/client.go:384
google.golang.org/grpc.chainUnaryClientInterceptors.func1
google.golang.org/[email protected]/clientconn.go:349
google.golang.org/grpc.(*ClientConn).Invoke
google.golang.org/[email protected]/call.go:35
github.com/moby/buildkit/api/services/control.(*controlClient).Solve
github.com/moby/[email protected]/api/services/control/control.pb.go:2208
github.com/moby/buildkit/client.(*Client).solve.func2
github.com/moby/[email protected]/client/solve.go:258
golang.org/x/sync/errgroup.(*Group).Go.func1
golang.org/x/[email protected]/errgroup/errgroup.go:75
runtime.goexit
runtime/asm_amd64.s:1598
daemon-side stacktrace as well.
To confirm, you mean the dockerd log files?
The errors would be in dockerd log if --buildkitd-flags '--debug', but should also be in the build output if docker --debug buildx build. Eg. https://gist.github.com/tonistiigi/5c81491e5f2174bb5493f20fe2461897#file-gistfile1-txt-L30-L68 for the latter. The GC trace log would only be in the dockerd log.
it still seems to run garbage collection somehow? i was not yet able to get a stacktrace from the dockerd sidecar. here is a log of the combined dockerd sidecar and the docker client. sidecar logs have a different format so you can distinguish them in raw text too.
2023-10-25T11:15:51+01:00 [10:15:51] #68 [static internal] load build context
2023-10-25T11:15:51+01:00 [10:15:51] #68 transferring context: 590.20MB 17.5s done
2023-10-25T11:15:57+01:00 [10:15:57] #68 ...
2023-10-25T11:15:57+01:00 [10:15:57]
2023-10-25T11:15:57+01:00 [10:15:57] #85 [app build 4/6] COPY shelf ./shelf
2023-10-25T11:16:20+01:00 time="2023-10-25T10:16:20.871393843Z" level=debug msg="garbage collected" d=4.887757851s
2023-10-25T11:16:22+01:00 [10:16:22] #85 ...
2023-10-25T11:16:22+01:00 [10:16:22]
2023-10-25T11:16:22+01:00 [10:16:22] #66 [test internal] load build context
2023-10-25T11:16:22+01:00 [10:16:22] #66 DONE 51.8s
2023-10-25T11:16:22+01:00 [10:16:22]
2023-10-25T11:16:22+01:00 [10:16:22] #85 [app build 4/6] COPY shelf ./shelf
2023-10-25T11:16:22+01:00 [10:16:22] #85 DONE 35.5s
2023-10-25T11:16:22+01:00 [10:16:22]
2023-10-25T11:16:22+01:00 [10:16:22] #68 [static internal] load build context
2023-10-25T11:16:25+01:00 [10:16:25] #68 DONE 54.5s
2023-10-25T11:16:25+01:00 [10:16:25]
2023-10-25T11:16:25+01:00 [10:16:25] #65 [build internal] load build context
2023-10-25T11:16:25+01:00 [10:16:25] #65 DONE 54.8s
2023-10-25T11:16:25+01:00 [10:16:25]
2023-10-25T11:16:25+01:00 [10:16:25] #86 [app build 5/6] RUN /app/manage.py collectstatic --no-input && mkdir -p /usr/share/nginx/html/static && cp -r static/* /usr/share/nginx/html/static/ && rm -rf static/* shelf/dashboard/frontend/*
2023-10-25T11:16:38+01:00 [10:16:38] WARNING: No output specified for base, venv, build, build-frontend target(s) with docker-container driver. Build result will only remain in the build cache. To push result image into registry use --push or to load image into docker use --load
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.909897858Z" level=debug msg="Closing buffered stdin pipe"
2023-10-25T11:16:38+01:00 [10:16:38] ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.909976541Z" level=debug msg="attach: stdin: end"
2023-10-25T11:16:38+01:00 [10:16:38] 123 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/grpc.getChainUnaryInvoker.func1
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/[email protected]/clientconn.go:361
2023-10-25T11:16:38+01:00 [10:16:38] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
2023-10-25T11:16:38+01:00 [10:16:38] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/buildkit/client.filterInterceptor.func1
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/[email protected]/client/client.go:384
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/grpc.chainUnaryClientInterceptors.func1
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/[email protected]/clientconn.go:349
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/grpc.(*ClientConn).Invoke
2023-10-25T11:16:38+01:00 [10:16:38] google.golang.org/[email protected]/call.go:35
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/buildkit/api/services/control.(*controlClient).Solve
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/[email protected]/api/services/control/control.pb.go:2208
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/buildkit/client.(*Client).solve.func2
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/[email protected]/client/solve.go:258
2023-10-25T11:16:38+01:00 [10:16:38] golang.org/x/sync/errgroup.(*Group).Go.func1
2023-10-25T11:16:38+01:00 [10:16:38] golang.org/x/[email protected]/errgroup/errgroup.go:75
2023-10-25T11:16:38+01:00 [10:16:38] runtime.goexit
2023-10-25T11:16:38+01:00 [10:16:38] runtime/asm_amd64.s:1598
2023-10-25T11:16:38+01:00 [10:16:38]
2023-10-25T11:16:38+01:00 [10:16:38] 123 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/buildkit/client.(*Client).solve.func2
2023-10-25T11:16:38+01:00 [10:16:38] github.com/moby/[email protected]/client/solve.go:273
2023-10-25T11:16:38+01:00 [10:16:38] golang.org/x/sync/errgroup.(*Group).Go.func1
2023-10-25T11:16:38+01:00 [10:16:38] golang.org/x/[email protected]/errgroup/errgroup.go:75
2023-10-25T11:16:38+01:00 [10:16:38] runtime.goexit
2023-10-25T11:16:38+01:00 [10:16:38] runtime/asm_amd64.s:1598
2023-10-25T11:16:38+01:00 [10:16:38]
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.913060685Z" level=debug msg="event forwarded" ns=moby topic=/tasks/exit type=containerd.events.TaskExit
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.913337717Z" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/exit
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.913492774Z" level=debug msg="attach: stdout: end"
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.913518235Z" level=debug msg="attach: stderr: end"
2023-10-25T11:16:38+01:00 time="2023-10-25T10:16:38.913607579Z" level=debug msg="attach done"
i also saw this issue hinting at a kernel bug https://github.com/moby/buildkit/issues/1459#issuecomment-1197430137. we are running debian11 with kernel 5.10.0-26-amd64 so potentially affected, but i couldn't find any associated logs on the host.
here is another log with a different error message
2023-10-25T11:52:20+01:00 [10:52:20] #6 [venv] resolve image config for docker.io/docker/dockerfile:1
2023-10-25T11:52:25+01:00 [10:52:25] #6 DONE 6.6s
2023-10-25T11:52:25+01:00 [10:52:25]
2023-10-25T11:52:25+01:00 [10:52:25] #11 [build] docker-image://docker.io/docker/dockerfile:1@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021
2023-10-25T11:52:25+01:00 [10:52:25] #11 resolve docker.io/docker/dockerfile:1@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021
2023-10-25T11:52:26+01:00 [10:52:26] #11 resolve docker.io/docker/dockerfile:1@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021 1.0s done
2023-10-25T11:52:26+01:00 [10:52:26] #11 resolve docker.io/docker/dockerfile:1@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021 1.0s done
2023-10-25T11:52:27+01:00 [10:52:27] #11 sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 0B / 11.80MB 0.2s
2023-10-25T11:52:28+01:00 [10:52:28] #11 sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 2.10MB / 11.80MB 0.5s
2023-10-25T11:52:28+01:00 [10:52:28] #11 sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 11.80MB / 11.80MB 0.8s
2023-10-25T11:52:28+01:00 [10:52:28] #11 sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 11.80MB / 11.80MB 0.8s done
2023-10-25T11:52:28+01:00 [10:52:28] #11 sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 11.80MB / 11.80MB 0.8s done
2023-10-25T11:52:28+01:00 [10:52:28] #11 extracting sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232
2023-10-25T11:52:29+01:00 [10:52:29] #11 extracting sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232 1.1s done
2023-10-25T11:52:29+01:00 [10:52:29] #11 DONE 5.1s
2023-10-25T11:52:31+01:00 time="2023-10-25T10:52:31.351870333Z" level=debug msg="garbage collected" d=436.163779ms
2023-10-25T11:55:39+01:00 [10:55:39] WARNING: No output specified for base, venv, build, build-frontend target(s) with docker-container driver. Build result will only remain in the build cache. To push result image into registry use --push or to load image into docker use --load
2023-10-25T11:55:39+01:00 [10:55:39] Dockerfile:1
2023-10-25T11:55:39+01:00 [10:55:39] --------------------
2023-10-25T11:55:39+01:00 [10:55:39] 1 | >>> # syntax = docker/dockerfile:1
2023-10-25T11:55:39+01:00 [10:55:39] 2 |
2023-10-25T11:55:39+01:00 [10:55:39] 3 | FROM python:3.11.4-slim-bullseye AS base
2023-10-25T11:55:39+01:00 [10:55:39] --------------------
2023-10-25T11:55:39+01:00 [10:55:39] ERROR: failed to run Build function: frontend grpc server closed unexpectedly
2023-10-25T11:55:39+01:00 [10:55:39] 7 v0.12.3 buildkitd --debug --containerd-worker-gc=false --oci-worker-gc=false
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/gateway.go:311
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/solver/llbsolver.(*provenanceBridge).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/solver/llbsolver/provenance.go:168
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/forwarder.(*BridgeClient).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/forwarder/forward.go:58
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/dockerfile/builder.forwardGateway
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/dockerfile/builder/build.go:226
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/dockerfile/builder.Build
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/dockerfile/builder/build.go:58
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/forwarder.(*GatewayForwarder).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/forwarder/frontend.go:35
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/solver/llbsolver.(*provenanceBridge).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/solver/llbsolver/provenance.go:168
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway.(*llbBridgeForwarder).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/gateway.go:656
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/control/gateway.(*GatewayForwarder).Solve
2023-10-25T11:55:39+01:00 [10:55:39] /src/control/gateway/gateway.go:103
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/pb._LLBBridge_Solve_Handler.func1
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/pb/gateway.pb.go:3108
2023-10-25T11:55:39+01:00 [10:55:39] github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/github.com/grpc-ecosystem/go-grpc-middleware/chain.go:25
2023-10-25T11:55:39+01:00 [10:55:39] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryServerInterceptor.func1
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc/interceptor.go:342
2023-10-25T11:55:39+01:00 [10:55:39] main.unaryInterceptor.func1
2023-10-25T11:55:39+01:00 [10:55:39] /src/cmd/buildkitd/main.go:603
2023-10-25T11:55:39+01:00 [10:55:39] github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/github.com/grpc-ecosystem/go-grpc-middleware/chain.go:25
2023-10-25T11:55:39+01:00 [10:55:39] github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/github.com/grpc-ecosystem/go-grpc-middleware/chain.go:34
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/pb._LLBBridge_Solve_Handler
2023-10-25T11:55:39+01:00 [10:55:39] /src/frontend/gateway/pb/gateway.pb.go:3110
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.(*Server).processUnaryRPC
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/google.golang.org/grpc/server.go:1336
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.(*Server).handleStream
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/google.golang.org/grpc/server.go:1704
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.(*Server).serveStreams.func1.2
2023-10-25T11:55:39+01:00 [10:55:39] /src/vendor/google.golang.org/grpc/server.go:965
2023-10-25T11:55:39+01:00 [10:55:39] runtime.goexit
2023-10-25T11:55:39+01:00 [10:55:39] /usr/local/go/src/runtime/asm_amd64.s:1598
2023-10-25T11:55:39+01:00 [10:55:39]
2023-10-25T11:55:39+01:00 [10:55:39] 140 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.getChainUnaryInvoker.func1
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/[email protected]/clientconn.go:361
2023-10-25T11:55:39+01:00 [10:55:39] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
2023-10-25T11:55:39+01:00 [10:55:39] go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.filterInterceptor.func1
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/client.go:384
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.chainUnaryClientInterceptors.func1
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/[email protected]/clientconn.go:349
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/grpc.(*ClientConn).Invoke
2023-10-25T11:55:39+01:00 [10:55:39] google.golang.org/[email protected]/call.go:35
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/pb.(*lLBBridgeClient).Solve
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/frontend/gateway/pb/gateway.pb.go:2876
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.(*gatewayClientForBuild).Solve
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/build.go:89
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/grpcclient.(*grpcClient).Solve
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/frontend/gateway/grpcclient/client.go:411
2023-10-25T11:55:39+01:00 [10:55:39] github.com/docker/buildx/build.BuildWithResultHandler.func3.1.2
2023-10-25T11:55:39+01:00 [10:55:39] github.com/docker/buildx/build/build.go:906
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/frontend/gateway/grpcclient.(*grpcClient).Run
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/frontend/gateway/grpcclient/client.go:214
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.(*Client).Build.func2
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/build.go:59
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.(*Client).solve.func3
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/solve.go:283
2023-10-25T11:55:39+01:00 [10:55:39] golang.org/x/sync/errgroup.(*Group).Go.func1
2023-10-25T11:55:39+01:00 [10:55:39] golang.org/x/[email protected]/errgroup/errgroup.go:75
2023-10-25T11:55:39+01:00 [10:55:39] runtime.goexit
2023-10-25T11:55:39+01:00 [10:55:39] runtime/asm_amd64.s:1598
2023-10-25T11:55:39+01:00 [10:55:39]
2023-10-25T11:55:39+01:00 [10:55:39] 140 v0.11.2 /usr/local/libexec/docker/cli-plugins/docker-buildx --debug buildx bake -f docker-bake.hcl
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.(*Client).Build.func2
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/build.go:60
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/buildkit/client.(*Client).solve.func3
2023-10-25T11:55:39+01:00 [10:55:39] github.com/moby/[email protected]/client/solve.go:283
2023-10-25T11:55:39+01:00 [10:55:39] golang.org/x/sync/errgroup.(*Group).Go.func1
2023-10-25T11:55:39+01:00 [10:55:39] golang.org/x/[email protected]/errgroup/errgroup.go:75
2023-10-25T11:55:39+01:00 [10:55:39] runtime.goexit
2023-10-25T11:55:39+01:00 [10:55:39] runtime/asm_amd64.s:1598
2023-10-25T11:55:39+01:00 [10:55:39]
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.188249471Z" level=debug msg="Closing buffered stdin pipe"
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.188386717Z" level=debug msg="attach: stdin: end"
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.212687457Z" level=debug msg="event forwarded" ns=moby topic=/tasks/exit type=containerd.events.TaskExit
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.213802939Z" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/exit
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.214323623Z" level=debug msg="attach: stdout: end"
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.214383066Z" level=debug msg="attach: stderr: end"
2023-10-25T11:55:39+01:00 time="2023-10-25T10:55:39.214422048Z" level=debug msg="attach done"
This is really annoying: buildkitd logs says:
time="2023-12-11T09:56:00Z" level=error msg="failed to kill process in container id omkv6ahdy0g1y2dx66ktjtnpx: buildkit-runc did not terminate successfully: exit status 1: container not running\n"
x 1000
time="2023-12-11T09:57:15Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: rpc error: code = Canceled desc = context canceled"
docker bake logs says: ERROR: failed to solve: DeadlineExceeded: context deadline exceeded
both are utterly useless error messages
While the underlying cause of this error still isn't known, we're making progress to investigating it in https://github.com/moby/buildkit/pull/4457 - at least with that merged, the error messages from the logs should be more helpful.
Super! :) I'm getting rather annoyed having to restart 50% of the builds manually.
I'm facing a similar issue on my Ubuntu 20.04.6 LTS servers. My os and docker/builkdit config:
# uname -r
5.4.0-167-generic
# docker version
Client: Docker Engine - Community
Version: 24.0.7
API version: 1.43
Go version: go1.20.10
Git commit: afdd53b
Built: Thu Oct 26 09:08:01 2023
OS/Arch: linux/amd64
Context: default
Server: Docker Engine - Community
Engine:
Version: 24.0.7
API version: 1.43 (minimum version 1.12)
Go version: go1.20.10
Git commit: 311b9ff
Built: Thu Oct 26 09:08:01 2023
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.6.25
GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
runc:
Version: 1.1.10
GitCommit: v1.1.10-0-g18a0cb0
docker-init:
Version: 0.19.0
GitCommit: de40ad0
# docker buildx ls
NAME/NODE DRIVER/ENDPOINT STATUS BUILDKIT PLATFORMS
buildx-docker-container-nodejs * docker-container
buildx-docker-container-nodejs0 unix:///var/run/docker.sock running f84cfe3 linux/amd64, linux/amd64/v2, linux/amd64/v3, linux/amd64/v4, linux/386
# docker buildx inspect buildx-docker-container-nodejs
Name: buildx-docker-container-nodejs
Driver: docker-container
Last Activity: 2023-12-14 15:15:07 +0000 UTC
Nodes:
Name: buildx-docker-container-nodejs0
Endpoint: unix:///var/run/docker.sock
Driver Options: image="moby/buildkit:nightly"
Status: running
Flags: --debug --oci-worker-gc=false
Buildkit: f84cfe3
Platforms: linux/amd64, linux/amd64/v2, linux/amd64/v3, linux/amd64/v4, linux/386
Labels:
org.mobyproject.buildkit.worker.executor: oci
org.mobyproject.buildkit.worker.hostname: 277c9036902a
org.mobyproject.buildkit.worker.network: host
org.mobyproject.buildkit.worker.oci.process-mode: sandbox
org.mobyproject.buildkit.worker.selinux.enabled: false
org.mobyproject.buildkit.worker.snapshotter: overlayfs
I disabled garbage collection and enabled debug on buildkit level. My Dockerfile:
# syntax=docker/dockerfile:1.6
ARG NODE_VERSION=18.18.2
FROM bitnami/node:${NODE_VERSION} as base
FROM base as npm-packages
WORKDIR /src
COPY npm-packages/package.json npm-packages/package-lock.json npm-packages/.npmrc npm-packages/
COPY npm-packages/utils/package.json npm-packages/utils/package-lock.json npm-packages/utils/.npmrc npm-packages/utils/
WORKDIR /src/npm-packages
RUN npm ci --progress=false --no-audit
WORKDIR /src/npm-packages/utils
RUN npm ci --progress=false --no-audit
# Common builder - ensure same RUN / COPY is included in other Web builds
FROM npm-packages as builder
WORKDIR /src
COPY Some.Application/package.json Some.Application/package-lock.json Some.Application/
WORKDIR /src/Some.Application
RUN npm ci --progress=false --no-audit --ignore-scripts
FROM builder as build
WORKDIR /src/npm-packages
COPY npm-packages/ ./
WORKDIR /src/Some.Application
COPY Some.Application/ ./
RUN npm run build
WORKDIR /src/npm-packages/utils
RUN npm prune --production
FROM scratch as publishresults
COPY --from=build /src/Some.Application/package.json /output/
COPY --from=build /src/Some.Application/node_modules/ /output/node_modules/
COPY --from=build /src/Some.Application/target/Some.Application/ /output/target/
COPY --from=build /src/Some.Application/target/npm-packages/ /output/npm-packages/
COPY --from=build /src/npm-packages/utils/node_modules/ /output/npm-packages/utils/node_modules/
FROM base as final
WORKDIR /app
VOLUME /var/log/someapplication/chat
COPY --from=publishresults --link=true /output/ /app/
CMD [ "node", "target/index.js" ]
I use below command to build it:
docker --debug buildx build --progress=plain --builder buildx-docker-container-nodejs --target publishresults --output type=local,dest=/var/lib/Some.Application_release_1.2 --cache-from type=registry,ref=registry.gitlab.com/someapplication/buildkit-cache:tag --file Some.Application/Dockerfile .
Stack trace/error:
16:15:08 #0 building with "buildx-docker-container-nodejs" instance using docker-container driver
16:15:08
16:15:08 #1 [internal] load build definition from Dockerfile 16:15:08 #1 transferring dockerfile: 1.64kB done
16:15:08 #1 DONE 0.0s
16:15:08
16:15:08 #2 resolve image config for docker.io/docker/dockerfile:1.6
16:15:08 #2 DONE 0.2s
16:15:08
16:15:08 #3 docker-image://docker.io/docker/dockerfile:1.6@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021
16:15:08 #3 resolve docker.io/docker/dockerfile:1.6@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021 done
16:15:08 #3 CACHED
16:15:08
16:15:08 #4 [internal] load metadata for docker.io/bitnami/node:18.18.2
16:15:08 #4 DONE 0.2s
16:15:08
16:15:08 #5 [internal] load .dockerignore
16:15:08 #5 transferring context: 832B done
16:15:08 #5 DONE 0.0s
16:15:08
16:15:08 #6 [internal] load build context
16:15:08 #6 DONE 0.0s
16:15:08
16:15:08 #7 importing cache manifest from registry.gitlab.com/someapplicationco/someapplication/buildkit-cache:tag
16:15:08 #7 ...
16:15:08
16:15:08 #8 [auth] someapplicationco/someapplication/buildkit-cache:pull token for registry.gitlab.com
16:15:08 #8 DONE 0.0s
16:15:09
16:15:09 #7 importing cache manifest from registry.gitlab.com/someapplicationco/someapplication/buildkit-cache:tag
16:15:09 #7 inferred cache manifest type: application/vnd.oci.image.index.v1+json done
16:15:09 #7 DONE 0.9s
16:15:09
16:15:09 #9 [base 1/1] FROM docker.io/bitnami/node:18.18.2@sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de
16:15:09 #9 resolve docker.io/bitnami/node:18.18.2@sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de done
16:15:09 #9 DONE 0.0s
16:15:09
16:15:09 #6 [internal] load build context
16:15:09 #6 transferring context: 14.38kB 0.0s done
16:15:09 #6 DONE 0.0s
16:15:09
16:15:09 #10 [build 3/5] WORKDIR /src/Some.Application
16:15:09 #10 CACHED
16:15:09
16:15:09 #11 [npm-packages 1/7] WORKDIR /src
16:15:09 #11 CACHED
16:15:09
16:15:09 #12 [publishresults 2/6] COPY --from=build /src/Some.Application/node_modules/ /output/node_modules/
16:15:09 #12 CACHED
16:15:09
16:15:09 #13 [npm-packages 3/7] COPY npm-packages/utils/package.json npm-packages/utils/package-lock.json npm-packages/utils/.npmrc npm-packages/utils/
16:15:09 #13 CACHED
16:15:09
16:15:09 #14 [build 1/5] WORKDIR /src/npm-packages
16:15:09 #14 CACHED
16:15:09
16:15:09 #15 [publishresults 1/6] COPY --from=build /src/Some.Application/package.json /output/
16:15:09 #15 CACHED
16:15:09
16:15:09 #16 [publishresults 5/6] COPY --from=build /src/npm-packages/node_modules/ /output/npm-packages/node_modules/
16:15:09 #16 CACHED
16:15:09
16:15:09 #17 [npm-packages 7/7] RUN npm ci --progress=false --no-audit
16:15:09 #17 CACHED
16:15:09
16:15:09 #18 [npm-packages 5/7] RUN npm ci --progress=false --no-audit
16:15:09 #18 CACHED
16:15:09
16:15:09 #19 [build 4/5] COPY Some.Application/ ./
16:15:09 #19 CACHED
16:15:09
16:15:09 #20 [builder 1/4] WORKDIR /src
16:15:09 #20 CACHED
16:15:09
16:15:09 #21 [build 5/5] RUN npm run build
16:15:09 #21 CACHED
16:15:09
16:15:09 #22 [builder 3/4] WORKDIR /src/Some.Application
16:15:09 #22 CACHED
16:15:09
16:15:09 #23 [builder 4/4] RUN npm ci --progress=false --no-audit --ignore-scripts
16:15:09 #23 CACHED
16:15:09
16:15:09 #24 [builder 2/4] COPY Some.Application/package.json Some.Application/package-lock.json Some.Application/
16:15:09 #24 CACHED
16:15:09
16:15:09 #25 [publishresults 3/6] COPY --from=build /src/Some.Application/target/Some.Application/ /output/target/
16:15:09 #25 CACHED
16:15:09
16:15:09 #26 [npm-packages 4/7] WORKDIR /src/npm-packages
16:15:09 #26 CACHED
16:15:09
16:15:09 #27 [build 2/5] COPY npm-packages/ ./
16:15:09 #27 CACHED
16:15:09
16:15:09 #28 [npm-packages 6/7] WORKDIR /src/npm-packages/utils
16:15:09 #28 CACHED
16:15:09
16:15:09 #29 [publishresults 4/6] COPY --from=build /src/Some.Application/target/npm-packages/ /output/npm-packages/
16:15:09 #29 CACHED
16:15:09
16:15:09 #30 [npm-packages 2/7] COPY npm-packages/package.json npm-packages/package-lock.json npm-packages/.npmrc npm-packages/
16:15:09 #30 CACHED
16:15:09
16:15:09 #31 [publishresults 6/6] COPY --from=build /src/npm-packages/utils/node_modules/ /output/npm-packages/utils/node_modules/
16:15:09 #31 CACHED
16:15:09
16:15:09 #32 exporting to client directory
16:15:09 #32 copying files 26B
16:16:48 Cancelling nested steps due to timeout
16:16:48 Sending interrupt signal to process
16:17:00 DEBUG: using config store "/home/jenkins/.docker/buildx" based in "$BUILDX_CONFIG" environment variable
16:17:00 DEBUG: using config store "/home/jenkins/.docker/buildx" based in "$BUILDX_CONFIG" environment variable
16:17:00 DEBUG: using config store "/home/jenkins/.docker/buildx" based in "$BUILDX_CONFIG" environment variable
16:17:00 ERROR: failed to solve: Canceled: context canceled
16:17:00 12809 v0.11.2 /usr/libexec/docker/cli-plugins/docker-buildx --debug buildx build --progress=plain --builder buildx-docker-container-nodejs --target publishresults --output type=>
16:17:00 google.golang.org/grpc.getChainUnaryInvoker.func1
16:17:00 google.golang.org/[email protected]/clientconn.go:361
16:17:00 go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1
16:17:00 go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:99
16:17:00 github.com/moby/buildkit/client.filterInterceptor.func1
16:17:00 github.com/moby/[email protected]/client/client.go:384
16:17:00 google.golang.org/grpc.chainUnaryClientInterceptors.func1
16:17:00 google.golang.org/[email protected]/clientconn.go:349
16:17:00 google.golang.org/grpc.(*ClientConn).Invoke
16:17:00 google.golang.org/[email protected]/call.go:35
16:17:00 github.com/moby/buildkit/api/services/control.(*controlClient).Solve
16:17:00 github.com/moby/[email protected]/api/services/control/control.pb.go:2208
16:17:00 github.com/moby/buildkit/client.(*Client).solve.func2
16:17:00 github.com/moby/[email protected]/client/solve.go:258
16:17:00 golang.org/x/sync/errgroup.(*Group).Go.func1
16:17:00 golang.org/x/[email protected]/errgroup/errgroup.go:75
16:17:00 runtime.goexit
16:17:00 runtime/asm_amd64.s:1598
16:17:00
16:17:00 12809 v0.11.2 /usr/libexec/docker/cli-plugins/docker-buildx --debug buildx build --progress=plain --builder buildx-docker-container-nodejs --target publishresults --output type=>
16:17:00 github.com/moby/buildkit/client.(*Client).solve.func2
16:17:00 github.com/moby/[email protected]/client/solve.go:273
16:17:00 golang.org/x/sync/errgroup.(*Group).Go.func1
16:17:00 golang.org/x/[email protected]/errgroup/errgroup.go:75
16:17:00 runtime.goexit
16:17:00 runtime/asm_amd64.s:1598
On buildkit container level I get:
1 time="2023-12-14T15:15:03Z" level=info msg="auto snapshotter: using overlayfs"
2 time="2023-12-14T15:15:03Z" level=warning msg="using host network as the default"
3 time="2023-12-14T15:15:03Z" level=info msg="found worker \"j15zbih8yphnky0k6rxkrt7y1\", labels=map[org.mobyproject.buildkit.worker.executor:oci org.mobyproject.buildkit.worker.hostname:277c9036902a org.mobyproject.buildkit.worker.network:host org.mobyproject.buildkit.worker.oci.process-mode:sandbox org.mobyproject.buildkit.worker.selinux.enabled:false org.mobyproject.buil dkit.worker.snapshotter:overlayfs], platforms=[linux/amd64 linux/amd64/v2 linux/amd64/v3 linux/amd64/v4 linux/386]"
4 time="2023-12-14T15:15:03Z" level=warning msg="skipping containerd worker, as \"/run/containerd/containerd.sock\" does not exist"
5 time="2023-12-14T15:15:03Z" level=info msg="found 1 workers, default=\"j15zbih8yphnky0k6rxkrt7y1\""
6 time="2023-12-14T15:15:03Z" level=warning msg="currently, only the default worker can be used."
7 time="2023-12-14T15:15:03Z" level=info msg="running server on /run/buildkit/buildkitd.sock"
8 time="2023-12-14T15:15:03Z" level=debug msg="session started" spanID=ae2c1997099d20cd traceID=91f68e5bdcd180ee13f0079e4900519c
9 time="2023-12-14T15:15:03Z" level=debug msg="session finished: <nil>" spanID=ae2c1997099d20cd traceID=91f68e5bdcd180ee13f0079e4900519c
10 time="2023-12-14T15:15:03Z" level=debug msg="session started" spanID=24f672a9b7c04609 traceID=91f68e5bdcd180ee13f0079e4900519c
11 time="2023-12-14T15:15:03Z" level=debug msg="reusing ref for local: djdi820tpz8jd0decn318qbgi" span="[internal] load build definition from Dockerfile" spanID=9696eba11e679f6c traceID=91f68e5bdcd180ee13f0079e4900519c
12 time="2023-12-14T15:15:03Z" level=debug msg="diffcopy took: 3.428898ms" span="[internal] load build definition from Dockerfile" spanID=fcda1758417b0573 traceID=91f68e5bdcd180ee13f0079e4900519c
13 time="2023-12-14T15:15:03Z" level=debug msg=resolving host=registry-1.docker.io
14 time="2023-12-14T15:15:03Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
15 time="2023-12-14T15:15:03Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=160 response.header.content-type=application/json response.header.date="Thu, 14 Dec 2023 15:15:03 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.strict-tran sport-security="max-age=31536000" response.header.www-authenticate="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:docker/dockerfile:pull\"" response.status="401 Unauthorized" url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
16 time="2023-12-14T15:15:03Z" level=debug msg=Unauthorized header="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:docker/dockerfile:pull\"" host=registry-1.docker.io
17 time="2023-12-14T15:15:03Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
18 time="2023-12-14T15:15:04Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=8404 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:04 GMT" response.header.docker-content-digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" response .header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.etag="\"sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
19 time="2023-12-14T15:15:04Z" level=debug msg=resolved desc.digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" host=registry-1.docker.io
20 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404
21 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482
22 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271
23 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404
24 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482
25 time="2023-12-14T15:15:04Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271
26 time="2023-12-14T15:15:04Z" level=debug msg="load cache for docker-image://docker.io/docker/dockerfile:1.6@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021 with j15zbih8yphnky0k6rxkrt7y1::rfmjjkt9dppczm0jyqyq65s8e"
27 time="2023-12-14T15:15:04Z" level=debug msg="serving grpc connection" spanID=edda0dcd5efce83e traceID=91f68e5bdcd180ee13f0079e4900519c
28 time="2023-12-14T15:15:04Z" level=debug msg="> creating yxvjg8oqtn6db6o3u3jkd42e1 [/bin/dockerfile-frontend]" spanID=edda0dcd5efce83e traceID=91f68e5bdcd180ee13f0079e4900519c
29 time="2023-12-14T15:15:04Z" level=debug msg=resolving host=registry-1.docker.io
30 time="2023-12-14T15:15:04Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/bitnami/node/manifests/18.18.2"
31 time="2023-12-14T15:15:04Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=155 response.header.content-type=application/json response.header.date="Thu, 14 Dec 2023 15:15:04 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.strict-tran sport-security="max-age=31536000" response.header.www-authenticate="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:bitnami/node:pull\"" response.status="401 Unauthorized" url="https://registry-1.docker.io/v2/bitnami/node/manifests/18.18.2"
32 time="2023-12-14T15:15:04Z" level=debug msg=Unauthorized header="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:bitnami/node:pull\"" host=registry-1.docker.io
33 time="2023-12-14T15:15:04Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/bitnami/node/manifests/18.18.2"
34 time="2023-12-14T15:15:05Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=529 response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Thu, 14 Dec 2023 15:15:05 GMT" response.header.docker-content-digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaaba ae9d0de" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.etag="\"sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/bitnami/node/manifests/18. 18.2"
35 time="2023-12-14T15:15:05Z" level=debug msg=resolved desc.digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" host=registry-1.docker.io
36 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=529
37 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:11f03f5ed59b289b810a81c6950b28befcc3b8a3bab5696f4d69c4c9a173a15b" mediatype=application/vnd.docker.distribution.manifest.v2+json size=430
38 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:ea8e91735c2ee3f817e14eda616abf114bd43c1cce28fe6f3df2f51688825413" mediatype=application/vnd.docker.container.image.v1+json size=5785
39 time="2023-12-14T15:15:05Z" level=debug msg="reusing ref for local: d7v9tu0oqeis7nq9o2x2jc44t" span="[internal] load .dockerignore" spanID=d51631720eb41f9f traceID=91f68e5bdcd180ee13f0079e4900519c
40 time="2023-12-14T15:15:05Z" level=debug msg="diffcopy took: 3.040671ms" span="[internal] load .dockerignore" spanID=6b782e1e27b8b480 traceID=91f68e5bdcd180ee13f0079e4900519c
41 time="2023-12-14T15:15:05Z" level=debug msg=resolving host=registry.gitlab.com
42 time="2023-12-14T15:15:05Z" level=debug msg="do request" host=registry.gitlab.com 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=buildkit/v0.0.0+unknown request.method=H EAD url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/tag"
43 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=529
44 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:11f03f5ed59b289b810a81c6950b28befcc3b8a3bab5696f4d69c4c9a173a15b" mediatype=application/vnd.docker.distribution.manifest.v2+json size=430
45 time="2023-12-14T15:15:05Z" level=debug msg=fetch digest="sha256:ea8e91735c2ee3f817e14eda616abf114bd43c1cce28fe6f3df2f51688825413" mediatype=application/vnd.docker.container.image.v1+json size=5785
46 time="2023-12-14T15:15:05Z" level=debug msg="fetch response received" host=registry.gitlab.com response.header.content-length=200 response.header.content-type=application/json response.header.date="Thu, 14 Dec 2023 15:15:05 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=regi stry-us-east1-c response.header.www-authenticate="Bearer realm=\"https://gitlab.com/jwt/auth\",service=\"container_registry\",scope=\"repository:someapplication/someapplication/buildkit-cache:pull\"" response.header.x-content-type-options=nosniff response.status="401 Unauthorized" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests /tag"
47 time="2023-12-14T15:15:05Z" level=debug msg=Unauthorized header="Bearer realm=\"https://gitlab.com/jwt/auth\",service=\"container_registry\",scope=\"repository:someapplication/someapplication/buildkit-cache:pull\"" host=registry.gitlab.com
48 time="2023-12-14T15:15:05Z" level=debug msg="do request" host=registry.gitlab.com 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=buildkit/v0.0.0+unknown request.method=H EAD url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/tag"
49 time="2023-12-14T15:15:05Z" level=debug msg="fetch response received" host=registry.gitlab.com response.header.content-length=7021 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:05 GMT" response.header.docker-content-digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response. header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da\"" response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=gke-cny-registry response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication/so meapplication/buildkit-cache/manifests/tag"
50 time="2023-12-14T15:15:05Z" level=debug msg=resolved desc.digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" host=registry.gitlab.com
51 time="2023-12-14T15:15:05Z" level=debug msg="do request" digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" request.header.accept="application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.0.0+unknown request.method=GET url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/sha25 6:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da"
52 time="2023-12-14T15:15:06Z" level=debug msg="fetch response received" digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response.header.content-length=7021 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:06 GMT" response.header.docker-content-digest="sha256:0545f1602be83f3b14e f30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da\"" response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=registry-us-east1-c response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da"
53 time="2023-12-14T15:15:06Z" level=debug msg="do request" digest="sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1" request.header.accept="application/vnd.buildkit.cacheconfig.v0, */*" request.header.user-agent=buildkit/v0.0.0+unknown request.method=GET url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/blobs/sha256:7b 9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1"
54 time="2023-12-14T15:15:06Z" level=debug msg="fetch response received" digest="sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1" response.header.accept-ranges=bytes response.header.age=2540 response.header.alt-svc="h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000" response.header.cache-control="public,private,max-age=0" response.header.content-leng th=4038 response.header.content-type=application/octet-stream response.header.date="Thu, 14 Dec 2023 14:32:46 GMT" response.header.etag="\"963f709af13c33eef316f80032de0274\"" response.header.last-modified="Tue, 12 Dec 2023 14:15:17 GMT" response.header.server=UploadServer response.header.x-goog-generation=1702390517080746 response.header.x-goog-hash="crc32c=3nGTiQ==" resp onse.header.x-goog-hash.1="md5=lj9wmvE8M+7zFvgAMt4CdA==" 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=4038 response.header.x-guploader-uploadid=ABPtcPrWm1Id1vk4wATvUMPPAlZiMIohDJSY4WywuUOxNmQzQ_JubzmKcCoWmk4tL_xn-pqimGzf4rGZKK1UBvOM Gr0qdw response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/blobs/sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1"
55 time="2023-12-14T15:15:06Z" level=debug msg="reusing ref for local: n627qinty2c0vgjq94ry42agc" span="[internal] load build context" spanID=119634fce9f7b9f7 traceID=91f68e5bdcd180ee13f0079e4900519c
56 time="2023-12-14T15:15:06Z" level=debug msg="diffcopy took: 56.040159ms" span="[internal] load build context" spanID=41b1f7a8d4105b3a traceID=91f68e5bdcd180ee13f0079e4900519c
57 time="2023-12-14T15:15:06Z" level=debug msg="load cache for [build 5/5] RUN npm run build with j15zbih8yphnky0k6rxkrt7y1::p1kw9x7wdk3509e9yvrq5svdo"
58 time="2023-12-14T15:15:06Z" level=debug msg="session finished: <nil>" spanID=24f672a9b7c04609 traceID=91f68e5bdcd180ee13f0079e4900519c
59 time="2023-12-14T15:15:07Z" level=debug msg="session started" spanID=431f901070ee549a traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
60 time="2023-12-14T15:15:07Z" level=debug msg="session finished: <nil>" spanID=431f901070ee549a traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
61 time="2023-12-14T15:15:07Z" level=debug msg="session started" spanID=81692ce987c201fa traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
62 time="2023-12-14T15:15:07Z" level=debug msg="reusing ref for local: djdi820tpz8jd0decn318qbgi" span="[internal] load build definition from Dockerfile" spanID=695e084810c43aeb traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
63 time="2023-12-14T15:15:07Z" level=debug msg="diffcopy took: 2.894857ms" span="[internal] load build definition from Dockerfile" spanID=876690d4c3ca1c78 traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
64 time="2023-12-14T15:15:07Z" level=debug msg=resolving host=registry-1.docker.io
65 time="2023-12-14T15:15:07Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
66 time="2023-12-14T15:15:08Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=8404 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:08 GMT" response.header.docker-content-digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" response .header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.etag="\"sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1.6"
67 time="2023-12-14T15:15:08Z" level=debug msg=resolved desc.digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" host=registry-1.docker.io
68 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404
69 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482
70 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271
71 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404
72 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482
73 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271
74 time="2023-12-14T15:15:08Z" level=debug msg="load cache for docker-image://docker.io/docker/dockerfile:1.6@sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021 with j15zbih8yphnky0k6rxkrt7y1::rfmjjkt9dppczm0jyqyq65s8e"
75 time="2023-12-14T15:15:08Z" level=debug msg="serving grpc connection" spanID=e35d2912927b989a traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
76 time="2023-12-14T15:15:08Z" level=debug msg="> creating pllajphfqkt3j8pzknmm879xz [/bin/dockerfile-frontend]" spanID=e35d2912927b989a traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
77 time="2023-12-14T15:15:08Z" level=debug msg=resolving host=registry-1.docker.io
78 time="2023-12-14T15:15:08Z" level=debug msg="do request" host=registry-1.docker.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=buildkit/v0.0.0+unknown request.method= HEAD url="https://registry-1.docker.io/v2/bitnami/node/manifests/18.18.2"
79 time="2023-12-14T15:15:08Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=529 response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Thu, 14 Dec 2023 15:15:08 GMT" response.header.docker-content-digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaaba ae9d0de" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=159.100.245.171 response.header.etag="\"sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/bitnami/node/manifests/18. 18.2"
80 time="2023-12-14T15:15:08Z" level=debug msg=resolved desc.digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" host=registry-1.docker.io
81 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=529
82 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:11f03f5ed59b289b810a81c6950b28befcc3b8a3bab5696f4d69c4c9a173a15b" mediatype=application/vnd.docker.distribution.manifest.v2+json size=430
83 time="2023-12-14T15:15:08Z" level=debug msg=fetch digest="sha256:ea8e91735c2ee3f817e14eda616abf114bd43c1cce28fe6f3df2f51688825413" mediatype=application/vnd.docker.container.image.v1+json size=5785
84 time="2023-12-14T15:15:08Z" level=debug msg="reusing ref for local: d7v9tu0oqeis7nq9o2x2jc44t" span="[internal] load .dockerignore" spanID=242db7e332b717ee traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
85 time="2023-12-14T15:15:08Z" level=debug msg="diffcopy took: 3.75032ms" span="[internal] load .dockerignore" spanID=46bfdf9dfe6dd8cc traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
86 time="2023-12-14T15:15:08Z" level=debug msg=resolving host=registry.gitlab.com
87 time="2023-12-14T15:15:08Z" level=debug msg="do request" host=registry.gitlab.com 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=buildkit/v0.0.0+unknown request.method=H EAD url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/tag"
88 time="2023-12-14T15:15:08Z" level=debug msg="fetch response received" host=registry.gitlab.com response.header.content-length=200 response.header.content-type=application/json response.header.date="Thu, 14 Dec 2023 15:15:08 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=regi stry-us-east1-c response.header.www-authenticate="Bearer realm=\"https://gitlab.com/jwt/auth\",service=\"container_registry\",scope=\"repository:someapplication/someapplication/buildkit-cache:pull\"" response.header.x-content-type-options=nosniff response.status="401 Unauthorized" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests /tag"
89 time="2023-12-14T15:15:08Z" level=debug msg=Unauthorized header="Bearer realm=\"https://gitlab.com/jwt/auth\",service=\"container_registry\",scope=\"repository:someapplication/someapplication/buildkit-cache:pull\"" host=registry.gitlab.com
90 time="2023-12-14T15:15:08Z" level=debug msg="do request" host=registry.gitlab.com 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=buildkit/v0.0.0+unknown request.method=H EAD url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/tag"
91 time="2023-12-14T15:15:09Z" level=debug msg="fetch response received" host=registry.gitlab.com response.header.content-length=7021 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:09 GMT" response.header.docker-content-digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response. header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da\"" response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=registry-us-east1-c response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication /someapplication/buildkit-cache/manifests/tag"
92 time="2023-12-14T15:15:09Z" level=debug msg=resolved desc.digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" host=registry.gitlab.com
93 time="2023-12-14T15:15:09Z" level=debug msg="do request" digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" request.header.accept="application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.0.0+unknown request.method=GET url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/sha25 6:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da"
94 time="2023-12-14T15:15:09Z" level=debug msg="fetch response received" digest="sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response.header.content-length=7021 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Thu, 14 Dec 2023 15:15:09 GMT" response.header.docker-content-digest="sha256:0545f1602be83f3b14e f30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da\"" response.header.gitlab-lb=haproxy-registry-04-lb-gprd response.header.gitlab-sv=registry-us-east1-c response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/manifests/sha256:0545f1602be83f3b14ef30e35f9512e408ac873e9ba7d00d2c9571c73f9e74da"
95 time="2023-12-14T15:15:09Z" level=debug msg="do request" digest="sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1" request.header.accept="application/vnd.buildkit.cacheconfig.v0, */*" request.header.user-agent=buildkit/v0.0.0+unknown request.method=GET url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/blobs/sha256:7b 9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1"
96 time="2023-12-14T15:15:09Z" level=debug msg="fetch response received" digest="sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1" response.header.accept-ranges=bytes response.header.age=2543 response.header.alt-svc="h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000" response.header.cache-control="public,private,max-age=0" response.header.content-leng th=4038 response.header.content-type=application/octet-stream response.header.date="Thu, 14 Dec 2023 14:32:46 GMT" response.header.etag="\"963f709af13c33eef316f80032de0274\"" response.header.last-modified="Tue, 12 Dec 2023 14:15:17 GMT" response.header.server=UploadServer response.header.x-goog-generation=1702390517080746 response.header.x-goog-hash="crc32c=3nGTiQ==" resp onse.header.x-goog-hash.1="md5=lj9wmvE8M+7zFvgAMt4CdA==" 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=4038 response.header.x-guploader-uploadid=ABPtcPrWm1Id1vk4wATvUMPPAlZiMIohDJSY4WywuUOxNmQzQ_JubzmKcCoWmk4tL_xn-pqimGzf4rGZKK1UBvOM Gr0qdw response.status="200 OK" url="https://registry.gitlab.com/v2/someapplication/someapplication/buildkit-cache/blobs/sha256:7b9724a054658bddaf641b36db0724e9794282f9ffec133d8cd2044e5427ecb1"
97 time="2023-12-14T15:15:09Z" level=debug msg=fetch digest="sha256:479f965ef6bca556db4dcf8cd25a0408a11788c305a149f21f6eaaabaae9d0de" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=529
98 time="2023-12-14T15:15:09Z" level=debug msg=fetch digest="sha256:11f03f5ed59b289b810a81c6950b28befcc3b8a3bab5696f4d69c4c9a173a15b" mediatype=application/vnd.docker.distribution.manifest.v2+json size=430
99 time="2023-12-14T15:15:09Z" level=debug msg=fetch digest="sha256:ea8e91735c2ee3f817e14eda616abf114bd43c1cce28fe6f3df2f51688825413" mediatype=application/vnd.docker.container.image.v1+json size=5785
100 time="2023-12-14T15:15:09Z" level=debug msg="reusing ref for local: n627qinty2c0vgjq94ry42agc" span="[internal] load build context" spanID=ebde5e6ebf0404fe traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
101 time="2023-12-14T15:15:09Z" level=debug msg="diffcopy took: 22.524741ms" span="[internal] load build context" spanID=349c7bde32668714 traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
102 time="2023-12-14T15:15:09Z" level=debug msg="load cache for [publishresults 6/6] COPY --from=build /src/npm-packages/utils/node_modules/ /output/npm-packages/utils/node_modules/ with j15zbih8yphnky0k6rxkrt7y1::gtbkcolmncytff7u6be9wgxz7"
103 time="2023-12-14T15:16:48Z" level=debug msg="session finished: <nil>" spanID=81692ce987c201fa traceID=0f0c5a1bf5592b6438e1e71b7fe6b2f2
I tried quite a lot of things already:
- checked different versions of moby/buildkit image including nightly (due to this comment)
- checked different versions of docker daemon
- disabled apparmor for docker/whole system
- disabled concurrency for buildkit
- disabled cache entirely for buildkit
For us the problem happens when as a result of publishresults step we have > 450MB of data to copy/send, it happens in 98% of such cases. For other apps when we have ~100-200MB of data to transfer this problem on same os/docker/buildkit configuration happens very rarely, for ~2% of cases.
Any hints will be really appreciated! :)
does this relate? just found it when scanning through the other issues. https://github.com/moby/buildkit/issues/3966
any progress with how to track down these problems? 50% of my builds require a manual restart and then succeed on the 2nd try... it is VERY annoying