Skip to content

Logging Retries Usefully

Retries multiply log volume exactly when it hurts: during an outage, every request fails several times, and a warning per attempt turns one incident into a flood that is expensive to ship, slow to search and hides the one line that matters. Measured on Python 3.14 with a service handling 200 requests per second for 10 seconds, each request retrying up to 3 times, while its dependency was down for 4 of those seconds: logging a warning with a traceback for every failed attempt and an error for every give-up produced 3,184 records and 2.24 MB of log output, with the process using 0.48 s of CPU. Logging once per request outcome — an error when it gave up, with the attempts recorded on the exception, and an info line when a retry succeeded — produced 800 records and 0.60 MB at 0.21 s of CPU. Counting every give-up in a metric and logging at most one sampled warning per second produced 4 records at 0.10 s, while the metric still counted all 793 failures. This guide logs retries at the level of the outcome, not the attempt.

Prerequisites

1. Measure what per-attempt logging costs

The usual first version logs inside the loop:

async def per_attempt(op, req):
    for attempt in range(1, 4):
        try:
            return await op()
        except ConnectionError as e:
            log.warning("attempt %d failed for %s: %s", attempt, req, e, exc_info=True)
            if attempt == 3:
                log.error("giving up on %s", req, exc_info=True)
                raise
            await asyncio.sleep(0.01 * attempt)

Measured over the 10-second run: 793 requests failed during the outage, producing 2,391 warnings and 793 errors — 3,184 records and 2.24 MB, most of it repeated tracebacks of the same ConnectionError. The process used 0.48 s of CPU against 0.21 s with outcome logging below, the difference being mostly log formatting. At a real request rate and a longer outage, multiply accordingly; log pipelines often throttle or drop exactly this kind of burst, so the useful lines can be lost with the rest.

Verify: count log records per failing request during an injected outage; more than one is a sign of per-attempt logging.

2,000 requests, 4 s outage, up to 3 attempts each A grid of 3 rows by 5 columns. 2,000 requests, 4 s outage, up to 3 attempts each strategy log records volume process CPU failures visible warning per attempt + error on give-up 3,184 2.24 MB 0.48 s 793 in logs one record per outcome 800 0.60 MB 0.21 s 793 in logs metric per failure + 1 sampled warning/s 4 < 0.01 MB 0.10 s 793 in the metric Python 3.14 logging, formatted but not written to disk.

2. Log once per outcome

Record what happened across attempts and log once when the outcome is known. Attach the attempt history to the exception that is raised, so whoever logs it — your code or a framework's error handler — shows it:

async def call_with_retry(op, req: str, attempts=3):
    errors, start = [], time.perf_counter()
    for attempt in range(1, attempts + 1):
        try:
            result = await op()
            if errors:
                log.info("succeeded after retries",
                         extra={"req": req, "attempts": attempt, "errors": errors})
            return result
        except ConnectionError as e:
            errors.append(type(e).__name__)
            if attempt == attempts:
                e.add_note(f"{attempt} attempts over {time.perf_counter() - start:.2f}s: {errors}")
                raise                                  # logged once, by whoever handles it
            await asyncio.sleep(0.01 * attempt)

Measured: 800 records — one error per failed request and a handful of info lines for requests that succeeded on a retry — and 0.60 MB, a quarter of the per-attempt volume. Each record still says how many attempts were made and how long they took. The info line on success after retries matters: it shows a dependency degrading before it fails outright.

Verify: a request that fails after three attempts produces exactly one log record, which names the attempt count and elapsed time.

3. Count in metrics, sample in logs

During an outage, the 793 error records all say the same thing. A counter answers "how many" more cheaply and more accurately than logs, and a sampled log line answers "what does it look like":

class SampledLogger:
    def __init__(self, every: float = 1.0):
        self.every, self.last, self.suppressed = every, 0.0, 0

    def warning(self, msg, *args):
        now = time.monotonic()
        if now - self.last >= self.every:
            log.warning(msg + " (%d similar suppressed)", *args, self.suppressed)
            self.last, self.suppressed = now, 0
        else:
            self.suppressed += 1

sampled = SampledLogger(every=1.0)

# on give-up:
retry_give_ups.labels(dependency="orders-api").inc()
sampled.warning("gave up on orders-api after %d attempts: %s", attempts, e)

Measured: 4 log records for the 4-second outage — one per second, each stating how many similar ones were suppressed — and 0.10 s of CPU, while the counter recorded all 793 give-ups. Keep a sampler per dependency and error type, so a different failure still gets its own line. Errors that are rare or unexpected — anything not in the retryable list — should not be sampled.

Verify: during an injected outage, log volume stays bounded per second while the failure counter matches the number of failed requests.

Log records during a 4-second outage 3 horizontal bars comparing per attempt with the others. Log records during a 4-second outage per attempt 3,184 per outcome 800 metric + 1 sampled warning/s 4 The metric counted all 793 failed requests in the last case. Same incident, same information, different cost.

4. Put retry facts in structured fields

Whatever is logged, make the retry facts queryable rather than embedded in message text:

log.error("dependency call failed", extra={
    "dependency": "orders-api",
    "attempts": attempt,
    "elapsed_ms": round((time.perf_counter() - start) * 1000),
    "errors": errors,                      # ["ConnectionError", "ConnectionError", "TimeoutError"]
    "request_id": request_id.get(),
}, exc_info=True)

With fields, "how many requests needed more than one attempt in the last hour, by dependency" is a query. Include the request ID, so a retried call can be tied to the request that made it, as in correlating logs and traces with request IDs. Log the traceback once — on the final failure — rather than per attempt; the attempt list says what came before.

Verify: a logging test asserts that the final failure record carries attempts, elapsed_ms and errors fields.

5. Configure library retries the same way

Libraries that retry for you log by their own rules. tenacity, for example, logs only what you ask it to; before_sleep_log writes one record per retry, which reproduces per-attempt logging:

retrying = tenacity.AsyncRetrying(
    retry=tenacity.retry_if_exception_type(ConnectionError),
    stop=tenacity.stop_after_attempt(3),
    wait=tenacity.wait_random_exponential(multiplier=0.01, max=1),
    reraise=True,
    # before_sleep=tenacity.before_sleep_log(log, logging.WARNING),   # one record per attempt
    retry_error_callback=None,
)

async def fetch(req):
    try:
        async for attempt in retrying:
            with attempt:
                return await op()
    except ConnectionError as e:
        e.add_note(f"{retrying.statistics.get('attempt_number')} attempts")
        raise

Turn off per-attempt logging in libraries, keep their statistics, and log the outcome in your own code with the same fields as step 4. For HTTP clients with transport-level retries, check what they log at each retry, as in retrying httpx requests with transport retries.

Verify: no library emits a log record per retry attempt in production configuration.

What to emit for a retried call A flow of 5 stages. What to emit for a retried call Attempts record error types, no logs Success after retries one info line Give-up note on exception, one error record Always counter per dependency Repeated identical errors sample to 1/s Measured: 3,184 records became 800, or 4 with sampling.

Verification

Retries are logged usefully when:

  • Each request logs once, at its outcome, with attempts and elapsed time.
  • Failures are counted in metrics, and repeated identical warnings are sampled.
  • Retry facts are structured fields, with the request ID and one traceback.
  • Library retry logging is turned off in favour of outcome logging.

Diagnostic Hook: when a log pipeline drops data or costs spike during dependency outages, count log records per failed request in the burst. Per-attempt logging produced about four records per failed request here — 3,184 for 793 failures — where outcome logging produced one.

Pitfalls & edge cases

  • A traceback per attempt. Measured: 2.24 MB during a 4-second outage.
  • No record of successful retries. Degradation stays invisible until it becomes failure.
  • Sampling unexpected errors. Sample only known, repeated failures.
  • Retry details in message text. They cannot be queried or aggregated.

Frequently Asked Questions

Should I log every retry attempt?

No. Logging each attempt produced 3,184 records for 793 failed requests; logging once per outcome produced 800 with the same information.

How do I record retry attempts without flooding logs?

Collect error types and timing during the attempts, then add them as a note on the final exception or as structured fields on one record.

How can I see retry problems during an outage without huge logs?

Count give-ups in a metric and sample identical warnings to one per second: 4 records covered a 4-second outage while the counter recorded all 793 failures.

Does tenacity log retries?

Only if configured: before_sleep_log writes one record per retry. Leave it off and log the outcome yourself.