Secret mount in RUN command increases build time

[mforeman19]

(See comment for update)

Contributing guidelines

• I've read the contributing guidelines and wholeheartedly agree

I've found a bug and checked that ...

• ... the documentation does not mention anything about my problem
• ... there are no open or closed issues that are related to my problem

Description

I have several COPY commands in Dockerfile formatted like this:

COPY --chmod=755 some_dir/ .

Where the docker buildx output states some amount of time to complete said COPY, as expected. BUT, the timestamps reported in my CI/CD pipeline indicate some sort of gap in time between that COPY and the following command that's unaccounted for.

Here's an example:

2024-03-27T15:53:44.6746588Z #27 [latest 1/4] COPY --chmod=755 latest/ .
2024-03-27T15:54:00.7298064Z #27 DONE 16.2s
2024-03-27T16:07:01.4238225Z 
2024-03-27T16:07:01.4240554Z #28 [latest 2/4] RUN --mount=type=secret,id=foo,target=bar     : "Latest Build"     ; foo

You can see from the above that the "DONE 16.2" seconds is accurate between the first timestamp and the second. Look at the third timestamp, however. There's a gap there of ~13 minutes. The RUN executed in #28 there completes at:

2024-03-27T16:19:56.3100242Z #28 DONE 774.9s

Which is a fairly accurate time between the fourth timestamp and the above (~13 minutes).

My question is, where does that inconsistency between the second and third timestamp and the above result from? Is there a good way to test that?

Expected behaviour

A COPY that takes x amount of time ought to match up with the timestamp reported logs that are output by the build. If a COPY takes 10 seconds, that should match up with the timestamps showing that 10 second change.

Actual behaviour

The timestamps that my CI/CD pipeline outputs ought to match up with the reported times that Docker buildx build executes commands. The time gap here seems odd, and I'm not sure what the build is doing during that time.

Buildx version

github.com/docker/buildx v0.13.1 7884339

Docker info

No response

Builders list

NAME/NODE     DRIVER/ENDPOINT   STATUS    BUILDKIT   PLATFORMS
default*      docker
 \_ default    \_ default       running   v0.13.1    linux/amd64, linux/amd64/v2, linux/amd64/v3, linux/386

Configuration

FROM foo AS latest

# Latest source COPY
COPY --chmod=755 latest/ .

# Latest build
ENV foo=true
ARG BUILD_COMMAND="foo"
RUN --mount=type=secret,id=foo,target=bar \
    : "Latest Build" \
    ; foo

# Build Isolation
WORKDIR /app

RUN : 'Build Isolation' ; \
    find . -type d \( -name 'foo' -o -name 'foo' -o -name 'foo' \) \
    ! -path '*/node_modules/*' -prune \
    -exec rsync -a --relative {}/ ../foo/ \;

Build logs

No response

Additional info

• The above configuration is a snippet of the larger Dockerfile that we have. That Dockerfile contains more COPYs followed by RUN commands that don't have a time gap.
• These builds are run within a CI/CD pipeline that basically kicks off a docker buildx build inside of a kubernetes container
• Our builds are fairly memory intensive. Something amiss there? I've only observed this weird gap between this COPY and RUN command I highlighted.

[mforeman19]

It turns out the secret mount in the RUN command was causing the issue. I refactored that to a COPY + RUN command and saw my build times decrease incredibly and become accurate once again

From:

RUN --mount=type=secret,id=foo,target=bar \
    : "Latest Build" \
    ; foo

To:

COPY --chmod=444 foo /root/bar
RUN : "Latest Build" \
    ; foo

We had been mounting secrets for a couple months now and not seen this issue. We do run a containerized build setup. Perhaps that mount of a file being transferred between our build agent running in a container to our docker-in-docker container is causing this issue