client: Increase the min connect timeout from 1s to 3s (otherwise connecting to distant Engines fails)

[neutronth]

• The MinConnectTimeout was set to 1s which is good for a fast recovering from the situation that the engine is not ready to accept connections, while at the same time, it's too aggressive for a remote engine, eg. Dagger Engine on a Kubernetes [1], the engine may not complete the connect phase within the deadline and always failed in the connection checking loop [2].

  Until the buildkit implements the better way of client creation [3], increase the timeout with a less aggressive 3s could mitigate this issue.

  [1] https://docs.dagger.io/integrations/kubernetes
  [2] https://github.com/dagger/dagger/blob/main/engine/client/buildkit.go#L45
  [3] https://github.com/grpc/grpc-go/blob/master/Documentation/anti-patterns.md

[jedevc]

This was originally lowered from the default 20s in #7612 (cc @marcosnils).

I'm a bit worried now if 3s is enough, but bringing it up too high negatively effects retry rates.

Genuinely such a pain to manage this, see a previous case of trying to resolve this in buildkit: moby/buildkit#4200.

Until the buildkit implements the better way of client creation [3], increase the timeout with a less aggressive 3s could mitigate this issue.

That's definitely something we could do (not right now, but sometime).

[gerhard]

Not being able to establish a connection within 1s does seem problematic. What makes the delay so high @neutronth in your environment?

Before this change, we had:

• 1s (MinConnectTimeout)
• 1.2s
• 2.4s
• 4.8s
• 9.6s
• 19.2s
• 30s (capped by MaxDelay)
• 30s (subsequent attempts)

After this change as it stands, the reconnect attempts will become:

• 3s (MinConnectTimeout)
• 3s (MinConnectTimeout)
• 3s (MinConnectTimeout)
• 4.8s
• 9.6s
• 19.2s
• 30s (capped by MaxDelay)
• 30s (subsequent attempts)

More frequent initial attempts - i.e. 2s - seems like a good compromise:

• 2s (MinConnectTimeout)
• 2s (MinConnectTimeout)
• 2.4s
• 4.8s
• 9.6s
• 19.2s
• 30s (capped by MaxDelay)
• 30s (subsequent attempts)

The above makes me wonder if we should set the MaxDelay to 10s, so that we would end with:

• 2s (MinConnectTimeout)
• 2s (MinConnectTimeout)
• 2.4s
• 4.8s
• 9.6s
• 10s (capped by MaxDelay)
• 10s (subsequent attempts)

Would the above work for your environment @neutronth? WDYT @jedevc @marcosnils?

As a different approach, I quiet like the idea of picking a default of 2s & 10s max, and also allowing this to be configurable.

[wingyplus]

also allowing this to be configurable.

I’m interesting to tackle on this one if you all are ok. Currently @neutronth and I need to adjust in Dagger source and rebuild the cli manually. :(

[neutronth]

@gerhard my environment is a development one that Dagger CLI connects to remote engine hosted in remote cloud Kubernetes cluster (oversea network), more latency added, I guess.

The Dagger CLI established the buildkit client over the kubepod [1] connection helper, it's been established properly.
However, it could not connect to the engine.

First of all, I was also wondering why it behaves like that as I saw the back-off configuration and it should be tackled properly.
From the debug log, I found that the client try to get the engine information with INFO call as shown in the log below:

09:45:43 DBG recording span span="dagger --progress=plain --debug core container" id=63d7cb911591c282                       09:46:06 [117/41903]
09:45:43 DBG recording span span=connect id=8057150ed7455027
09:45:43 DBG recording span child span=connect parent=63d7cb911591c282 child=8057150ed7455027
09:45:43 DBG recording span span="starting engine" id=b375c496da631526
09:45:43 DBG recording span child span="starting engine" parent=8057150ed7455027 child=b375c496da631526
09:45:43 DBG new end old="1754-08-31 05:25:45.128654848 +0642 LMT" new="2024-09-05 09:45:43.143629417 +0700 +07"
09:45:43 DBG recording span span="starting engine" id=b375c496da631526
09:45:43 DBG recording span child span="starting engine" parent=8057150ed7455027 child=b375c496da631526
09:45:43 DBG recording span span="connecting to engine" id=4c17aba9b59f85d2
09:45:43 DBG recording span child span="connecting to engine" parent=8057150ed7455027 child=4c17aba9b59f85d2
...
...
09:45:43 DBG recording span span=moby.buildkit.v1.Control/Info id=6a01b9c33e282582
...
09:45:44 DBG recording span span=moby.buildkit.v1.Control/Info id=6a01b9c33e282582
...
09:45:45 DBG recording span span=moby.buildkit.v1.Control/Info id=958aba786e46f9d9
...
09:45:46 DBG recording span span=moby.buildkit.v1.Control/Info id=09502a0e524f6ad3
...
09:45:47 DBG recording span span=moby.buildkit.v1.Control/Info id=f91f898b1622f66b
...
...
...

The spans have been splited with 1s and not looked like a back-off retrying.
Refers to @jedevc mentioned PR [2], it clearly explains why this behavior occured,
the client.Wait() overrides the back-off setting of gRPC connection option and retry every 1s instead.
Therefore, the expected back-off never applied to this case.

• 1s (MinConnectTimeout) -> no response -> wait for 1s
• 1s (MinConnectTimeout) -> no response -> wait for 1s
• 1s (MinConnectTimeout) -> no response -> wait for 1s
• ...
• ...
• Until 10mins deadline wihtout success

Hence, this PR try to mitigate this issue by give the client more chance to succeed (in my case, 3s does)

---

[1] https://github.com/moby/buildkit/blob/master/client/connhelper/kubepod/kubepod.go
[2] moby/buildkit#4200

[jedevc]

Yeah, the reason for this logic in buildkit is because we want a fast response for if the server is still in the starting state - the client should not back off, because it's a server side failure. This logic still applies for our use case.

However, yeah, this isn't great. But I've never been able to work out a good compromise that works well both for local (low-latency, so this kind of waiting is alright) and remote (higher-latency, so backoff is needed).

• Perhaps we actually want to have two different behaviors for those two cases?
• Potentially, we can just call grpc's WaitForReady option? The issue is, because that does exponential backoff, we can get poor performance with the common local case.
• Potentially we should implement a separate side-channel of health checks into the docker driver? So we can see when the engine comes up, then using WaitForReady should be fine?
  • Something like checking to see if /run/buildkit/buildkitd.sock exists could work.

All of those feel like better long-term solutions to me, but I'm potentially still alright with this as a short term solution.

[gerhard]

@neutronth that makes sense. Happy to go ahead with this as a short-term solution, and follow-up with a more robust implementation, as @jedevc mentioned.

Getting this approved & merged so that it can be released in the upcoming v0.13.0. Would you be OK to follow-up a more robust implementation that would work longer-term @neutronth?

Looking forward to your configurable follow-up @wingyplus 💪

[gerhard]

Going to add a relese notes fragment before approving & merging. FTR: https://docs.dagger.io/contributing/#3-add-release-notes-fragment

[gerhard]

LGTM 💪 🚀

[wingyplus]

Thank you @gerhard.

Looking forward to your configurable follow-up @wingyplus 💪

I will submit a PR in 2-3 days. 💪