open-telemetry / open-telemetry/opentelemetry-cpp
[BUG] The curl retry deadline is redrawn on every call rather than decided once per attempt
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 1.4k
- Forks
- 632
- Avg merge
- 1d 13h
- Merged PRs (30d)
- 75
Description
Carved out of #4398. That issue had three separate things on it, I put a Fixes #4398 trailer on #4399 which only covered the first, and the merge closed all three. My mistake. I can't reopen it, so this is item 2 on its own. Item 3 is still to come, after #4391, for the reason I gave over there.
Describe your environment
main at 768d04de, Debian, gcc 14.2.0, libcurl 8.14.1, plain CMake build with the defaults. WITH_OTLP_RETRY_PREVIEW defaults to ON at CMakeLists.txt:158, ci/do_ci.sh passes it explicitly at lines 182 and 407, and ext/src/http/client/curl/BUILD puts ENABLE_OTLP_RETRY_PREVIEW in defines with no select, so this is a default build rather than an opt-in one.
Steps to reproduce
Same setup as the existing ExponentialBackoffRetry, but asking for the deadline more than once after a single attempt. /retry/ answers 429 with no Retry-After, so this goes down the jitter path.
TEST_F(BasicCurlHttpTests, RetryDeadlineIsStable)
{
RetryEventHandler handler;
http_client::HttpSslOptions no_ssl;
http_client::Body body;
http_client::Headers headers;
http_client::Compression compression = http_client::Compression::kNone;
http_client::RetryPolicy retry_policy = {4, std::chrono::duration<float>{1.0f},
std::chrono::duration<float>{5.0f}, 2.0f};
curl::HttpOperation operation(http_client::Method::Post, "http://127.0.0.1:19000/retry/", no_ssl,
&handler, headers, body, compression, false,
curl::kDefaultHttpConnTimeout, false, false, retry_policy);
ASSERT_EQ(CURLE_OK, operation.Send());
ASSERT_TRUE(operation.IsRetryable());
std::set<long long> distinct;
for (int i = 0; i < 8; ++i)
{
distinct.insert(std::chrono::duration_cast<std::chrono::milliseconds>(
operation.NextRetryTime().time_since_epoch())
.count());
}
EXPECT_EQ(static_cast<size_t>(1), distinct.size());
}
What is the expected behavior?
One attempt has one deadline. NextRetryTime() reads like an accessor and doRetrySessions() uses it as one.
What is the actual behavior?
Eight calls, eight different deadlines. Three runs:
distinct=8 spread_ms=322
distinct=8 spread_ms=335
distinct=8 spread_ms=350
That spread is the jitter band doing exactly what it's told: initial_backoff is 1.0s and the draw is U(0.8, 1.2), so the deadline wanders over a 400 ms window and each call lands somewhere new in it.
Additional context
NextRetryTime() computes the value on every call at http_operation_curl.cc:642:
backoff *= dis(gen);
return last_attempt_time_ + std::chrono::duration_cast<std::chrono::milliseconds>(backoff);
and doRetrySessions() asks it once per pass of the background loop, at http_client_curl.cc:860:
else if (operation->NextRetryTime() < now)
So the retry doesn't fire when the drawn backoff elapses. It fires on the first pass where a freshly drawn backoff happens to fall below the elapsed time. The realized delay ends up depending on how often the loop happens to poll rather than on the value the policy asked for, and repeating the draw under a < comparison pulls the answer toward the bottom of the band instead of leaving it uniform across it.
It also undercuts the ordering the queue assumes. pending_to_retry_sessions_ is a deque and the loop breaks at the first session that isn't due, which is only sound if deadlines are ordered:
// Assumptions:
// - This is a FIFO list so older sessions, pushed at the back, always end up at the front
// - Locking not required because only the background thread would be pushing to this container
// - Retry policy is not changed once HTTP client is initialized, so same settings for everyone
@marcalff already flagged that block on #4186 and pointed out the sessions are no longer sorted by retry time: https://github.com/open-telemetry/opentelemetry-cpp/pull/4186#discussion_r3667055153. The redraw is a third way for the key to be out of order, after per request policies and Retry-After, and it's the one that can reorder two entries between one pass and the next without anything else changing.
The Retry-After path is not affected. NextRetryTime() returns retry_after_time_point_ early when it's set, and that one is a stored value.
#4399 is not the cause and doesn't change this. It made the engine thread_local, which fixed the data race and left the redraw where it was.
On the fix, everything needed is already in one place. PerformCurlMessage updates retry_attempts_ at line 1527 and last_attempt_time_ at 1528, and it's on both paths, reached from the sync Send() at line 1423 and from the background loop at http_client_curl.cc:527. Computing the deadline there and having NextRetryTime() return the stored value would make it stable without moving anything else, and it keeps ExponentialBackoffRetry working since that test calls Send() before it reads the deadline. Whether the queue then wants more than a break on the first not due entry is a separate question, and for the number of retries an exporter has in flight a scan is probably enough. Say the word and I'll send that shape.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start in http_operation_curl.cc at PerformCurlMessage and NextRetryTime(), then inspect the retry check in http_client_curl.cc. Reproduce the behavior with BasicCurlHttpTests.RetryDeadlineIsStable and compare it with ExponentialBackoffRetry. Done means repeated deadline reads for one attempt are identical while the Retry-After path remains unchanged.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp
- Domain
- networking
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 84/100