Skip to content

[BUG] The curl retry deadline is redrawn on every call rather than decided once per attempt #4403

Description

@thc1006

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: #4186 (comment). 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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    needs-triageIndicates an issue or PR lacks a `triage/foo` label and requires one.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions