Repository navigation
[BUG] Delays in build time when environment files have OTEL-related values and built with bake #13157
Description
Activity
I would not expect an environment file to influence the build when it's not used/applicable to the build.
It looks like anything passed via an environment file is added to the environment of compose itselfexact. This is how you can tweak compose and compose.yaml parser for custom needs. This is by design in compose and exists since day 1.
IIUC you have a
.envfile used by your application that compose will also load as this is the default file name it relies on
If you can't use a distinct file name for your application, you can either run compose with--env-fileto a specific file (can also be/dev/null) or pass explicit variableOTEL_SDK_DISABLED=true(to be tested)update: unfortunately opentelemtry-go rejected having support for
OTEL_SDK_DISABLED(open-telemetry/opentelemetry-go#3559)You can limit impact of this .env file access conflict by setting
OTEL_EXPORTER_OTLP_TIMEOUT=1IIUC you have a .env file used by your application that compose will also load as this is the default file name it relies on
If you can't use a distinct file name for your application, you can either run compose with --env-file to a specific fileYes, you do understand correctly. Perhaps my minimal example was too minimal. Those environment variables were 100% intended to be used by my compose containers when started. I have many projects that do this, and have been doing this fine for a long time. My report is about building of the images.
Prior to a few weeks ago, the images used in my compose files were built externally (for reasons not relevant to this report). Everything was working just fine. It is only after allowing compose to build those images that this became an issue and only when using bake for building.
or pass explicit variable OTEL_SDK_DISABLED=true (to be tested)
[...] rejected having support for OTEL_SDK_DISABLEDEven if that existed and was an option, it might 'fix' the issue in build times being artificially high, but would then break the actual intended usage (since I actually want my containers to send telemetry to the collector running in the compose setup).
Let me know if that makes more sense and/or if posting an example closer to my actual setup would help.
You can limit impact of this .env file access conflict by setting OTEL_EXPORTER_OTLP_TIMEOUT=1
I see a PR was created for this and saw your comment, so I think you get what I was trying to say (the mechanics at least). My current workaround is simply doing the build prior to setting my
COMPOSE_ENV_FILESvalue, but your workaround is actually good too, since it would be equally valid/useful in my runtime setup. Ultimately, I see the issue as conflating the environment within which compose runs with the environment intended for compose services, dumping the latter into the former, which usually doesn't matter.Arguably, this is also a flaw in bake itself as well (with environment variables being the way to set bake variables), since an OTEL variable actually intended to be used at build time would inadvertently break buildx telemetry (only the user would know the intent). But I figured I'd wait to see what you guys thought on the compose side before bringing that up with the buildx folks (esp. since it's more theoretical).
@ndeloof @maxproske I did end up creating docker/buildx#3381 on the buildx side to see what thoughts they might have.
@rrjjvv I don't think there's anything to be addressed on buildx side about this.
docker compose builddoes setOTEL_*after values were read from.envfile and pass them to buildx, which does what one would expect regarding env var and opentelemetry configurationI proposed a fix to stop passing all variables declared in .env file to bake.
Can you give it a try ? You can download compose binary from https://github.com/docker/compose/actions/runs/17230627216?pr=13180 (Artifacts section)Sorry I wasn't able to clearly enunciate the problem (as I saw it) earlier on... the description of your PR describes it perfectly!
When I wrote the report I thought the fix would be earlier so never visited the code you changed, but it certainly makes sense.
I intended to at least give you a "I can give it a try tonight" reply... but it's now the next day 😄; the day got a way from me. I was hoping for the best and plugged it right into my project, but... no luck. Relevant (but very truncated) output below.
Release version of compose (takes one second to build three fully-cached images with no
.envfiles in use, but thirty seconds to build those same three fully-cached images where an.envcontaining OTEL variables is in use):echo "clean env" clean env docker compose version Docker Compose version v2.39.1 time -p docker compose --progress plain --profile=it build <snip> #43 DONE 0.0s gizmo-otel-collector Built gizmo-gizmo Built gizmo-otel-verifier Built real 1.25 user 0.15 sys 0.10 <snip> echo "OTEL in env" OTEL in env docker compose version Docker Compose version v2.39.1 time -p docker compose --progress plain --profile=it build <snip> #43 DONE 0.0s gizmo-otel-collector Built gizmo-otel-verifier Built gizmo-gizmo Built real 30.25 user 0.19 sys 0.11And same scenario, but with the exact artifact you had me download:
echo "clean env" clean env ./docker-compose-linux-x86_64 version Docker Compose version bd15f7b time -p ./docker-compose-linux-x86_64 --progress plain --profile=it build <snip> #43 DONE 0.0s gizmo-otel-collector Built gizmo-gizmo Built gizmo-otel-verifier Built real 1.23 user 0.14 sys 0.07 <snip> echo "OTEL in env" OTEL in env ./docker-compose-linux-x86_64 version Docker Compose version bd15f7b time -p ./docker-compose-linux-x86_64 --progress plain --profile=it build <snip> #43 DONE 0.0s gizmo-otel-collector Built gizmo-otel-verifier Built gizmo-gizmo Built real 30.18 user 0.16 sys 0.10and here "clean env" means nothing in the process environment:
$ env | grep -i '^otel' | wc -l 0
and "OTEL in env" means
COMPOSE_ENV_FILES=".env.it"where:$ grep -i '^otel' .env.it OTEL_METRICS_EXPORTER=otlp OTEL_TRACES_EXPORTER=otlp OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector:4318 OTEL_METRIC_EXPORT_INTERVAL=100 OTEL_BSP_SCHEDULE_DELAY=100Tomorrow (later today) I should have some more time to 1) to verify against my original reproduction and 2) build it with some debug logging to help identify why your proposed fix doesn't work (if you don't identify it first).
Ugh, after looking at it with fresh eyes, it's actually obvious why the patch doesn't work. I mentioned it in the original report, but duplicating here for convenience:
compose/cmd/compose/compose.go
Lines 687 to 693 in f266715
Very early during startup, the
.envfiles are added directly to the environment of the compose process itself (which is what I originally thought of as the bug/culprit). Conceptually, "adding the OS environment instead of project environment" was the right thing to do, but the OS environment has already been modified with the project environment (or more accurately, the potential overrides available to the project environment).If that code is actually correct/intentional, I imagine the fix would be "undoing" those modifications before handing off to bake. Or probably simpler, taking a snapshot of the environment before that modification, and handing that snapshot to the bake shell-out.
indeed, need to double check why we do so (aka git archeology)
If that code is actually correct/intentional
Looking at the blame, I see that it's intentional and some of your earlier comments make more sense. A classic case of "one person's bug is another person's feature". I guess another solution might be adding only
COMPOSE_*variables to the environment, since that appears to be the primary purpose.Or... it's probably overkill, but an explicit setting that controls propagation/usage (e.g.,
--env-for-project-containers-only)? The fact that there's not an obvious name probably hints it's the wrong approach, but it's very explicit.(your comment came across just as I was writing this... #11967 is what you were fixing, if it saves you time)
indeed, I added an extra commit to only inject
COMPOSE_*variables toos.Envafter those were read from$PWD/.env. I can guess this will trigger some issues for a few users who started relying on this behavior (while not documented). Letting.envfile setCOMPOSE_*vars is a terrible mistake we made in the past considering the huge amount of issues this triggered 😢Letting .env file set COMPOSE_* vars is a terrible mistake we made in the past considering the huge amount of issues this triggered
I was secretly wondering if that was truly an intended/desirable feature or a mistake that can no longer be fixed... now I know!
I downloaded the exact binary produced by your new build and it behaves exactly as desired/expected (three fully cached images take about one second to build, not thirty seconds as before):
echo "OTEL in env" OTEL in env ./docker-compose-linux-x86_64 version Docker Compose version 90296f3 <snip> #43 DONE 0.0s gizmo-otel-verifier Built gizmo-gizmo Built gizmo-otel-collector Built real 1.22 user 0.14 sys 0.06
Description
When building an image via compose on its own, a fully cached build takes about one second, as expected. When built in the context of a test automation, the same fully cached build was consistently taking about thirty seconds (all expected output was displayed within a second, but just 'hung' after that). I finally determined the difference was an environment variable file.
export COMPOSE_ENV_FILES=.env.it docker compose build // now very slow, despite being fully cached docker compose up --wait -d // intended usage of the environment file // a bunch of other up/run executions, which is why COMPOSE_ENV_FILES is used // rather than having --env-file all over the placeI would not expect an environment file to influence the build when it's not used/applicable to the build.
Steps To Reproduce
This is a simple reproduction, though convoluted. My actual scenario entails an app with a number of instrumentation services (including an OTEL collector).
Compose file (
compose.yml):Environment file (
.env2):JSON format makes it easier to see where the delay is; the standalone build (no environment file) takes about one second:
Specifying an environment file containing an OTEL-related value (intended for containers) takes ten seconds (.3 seconds to actually build, the remainder spent being 'stuck'):
In my summary I said I was witnessing delays around thirty seconds; I suspect
OTEL_EXPORTER_OTLP_ENDPOINTwas largely responsible, but the lag was not consistent (I'm sure related to whether that endpoint is active). But the one I used above was very consistent, no doubt due to a ten second timeout somewhere.Also, this used a non-standard file to make it easier to demonstrate (and also reflects my actual scenario), but the behavior is the same whether it's the default
.envor custom (like my example) or if it's specified via--env-fileorCOMPOSE_ENV_FILES.Compose Version
Docker Environment
Anything else?
This has similarities to #12998 (but may be just that... similar).
This is specific to bake (i.e., this does not happen with
COMPOSE_BAKE=false), but I don't think it is bake's fault. I'm pretty sure I know where the problem is so I didn't try older versions, but I did try with main with the same results.It looks like anything passed via an environment file is added to the environment of compose itself
compose/cmd/compose/compose.go
Lines 687 to 693 in f266715
and though some additions and removals are done, it's more-or-less kept intact
compose/pkg/compose/shellout.go
Lines 33 to 59 in f266715
before passing it to the buildx plugin/process.
To complicate things, that near-verbatim passing of environment file to buildx (in #11974) was intentional:
which I assume means the overriding of bake variables, not configuring buildx behavior itself.
This seems more like an oversight or unintended consequence rather than a true bug. But it goes against expectations... I wouldn't expect an environment variable intended to control how my OTEL container is used to be (indirectly) used to build the images itself.
Note: if the environment itself had those OTEL values, I would expect (or at least not be surprised) if they trickled down to buildx. But they are not in my environment, but in a file that the docs say are used only to replace values in a compose file or other environment files.