Skip to content

Observable retries via an on_retry callback - #71

Open
snackycracky wants to merge 1 commit into
safwank:masterfrom
snackycracky:feature/on_retry_callback
Open

Observable retries via an on_retry callback#71
snackycracky wants to merge 1 commit into
safwank:masterfrom
snackycracky:feature/on_retry_callback

Conversation

@snackycracky

Copy link
Copy Markdown

Observable retries via an on_retry callback

Context

Retry.retry/2 performs its attempts silently. The core loop is nothing more
than a Enum.reduce_while/3 over the delay stream that sleeps and re-invokes the
block:

unquote(delays_from(stream_builder))
|> Enum.reduce_while(nil, fn delay, _last_result ->
  :timer.sleep(delay)
  fun.()
end)

There is no Logger call, no :telemetry event, and no user-facing hook
anywhere in the library. (Retry.Annotation does require Logger, but never
actually logs — it is an unused import.)

This became a problem for a caller that wraps :erpc.call/5 behind a retry:

retry with: constant_backoff(retry[:after]) |> expiry(retry[:limit]),
      atoms: &retry?/1 do
  do_call(node, module, function_name, function_args, opts)
end

With a budget such as limit: 600_000 (10 minutes) a lost node causes up to ten
minutes of retries that produce no log line, no metric, and no trace — the
caller only sees the final {:error, ...} after the budget is exhausted. That
silent window is operationally dangerous: an outage looks like a hang.

The alternatives available to callers today are unsatisfying:

  • Log inside the do block. Works, but conflates the "did it fail" decision
    with the "should I log" concern, and every call site has to reimplement it.
  • Switch to retry_while/2. Gives per-iteration control, but forces callers
    to hand-write the continue/halt logic and the value matching they get for free
    from atoms:/rescue_only:.

Decision

Add an optional on_retry option to Retry.retry/2. It is a one-arity function
invoked with the retriable value (or the rescued exception) immediately before
each actual retry.

Semantics were chosen deliberately by driving the callback from the previously
ignored reduce_while accumulator (last_result) rather than from
block_runner:

  • It is not called for the first attempt.
  • It is not called for the final, given-up attempt (the stream is exhausted
    before the loop runs again). That value/exception is already returned or
    re-raised, so notifying about it would be redundant.
  • It therefore fires exactly once per real retry — i.e. attempts - 1 times.
retry with: constant_backoff(1_000) |> expiry(10_000),
      on_retry: fn
        {:error, reason} -> Logger.warning("retrying, last error: #{inspect(reason)}")
        exception -> Logger.warning("retrying, last exception: #{inspect(exception)}")
      end do
  # interact with external service
end

The callback runs in the loop, outside the block's own try/rescue, so it is
never misinterpreted as a block failure. It is a fire-and-forget observability
hook, so any exception, throw, or exit it produces is isolated — a broken
logging call must never abort an in-progress retry. Rather than swallow that
error silently (which would hide a genuinely broken callback), it is reported
via Logger
and then execution continues. Logger ships with Elixir, so this
adds no dependency. When on_retry is absent the behaviour is byte-for-byte
unchanged.

Scope decisions:

  • Only retry/2 gets the option. retry_while/2 already hands the caller full
    control of each iteration, so they can log inline without a new hook.
  • The callback receives just the retriable value/exception (arity 1). It carries
    the failure reason, and callers can capture any additional context (target
    node, attempt counter, …) from their own closure. We kept the signature
    minimal rather than inventing a context struct we would have to version.
  • We did not add a :telemetry dependency. A plain callback keeps the
    library dependency-free; a caller who wants telemetry writes
    on_retry: &:telemetry.execute(...).

Consequences

  • Retries are observable without changing the value-matching ergonomics of
    retry/2. The motivating :erpc wrapper can log every retriable failure:

    retry with: constant_backoff(retry[:after]) |> expiry(retry[:limit]),
          atoms: &retry?/1,
          on_retry: fn {:error, %RPCError{reason: reason}} ->
            Logger.warning("RPC to #{inspect(node)} retrying after #{inspect(reason)}")
          end do
      do_call(node, module, function_name, function_args, opts)
    end
  • Backwards compatible: existing call sites and the default behaviour are
    untouched; on_retry defaults to nil.

  • The callback runs synchronously in the retrying process and its runtime counts
    against any expiry/2 budget. Callers must keep it cheap and non-blocking.

  • Errors raised, thrown, or exited from the callback do not affect the retry;
    they are caught and logged via Logger.error/1 (with the original stacktrace
    via Exception.format/3). A broken callback is therefore visible in the logs
    instead of failing silently, but callers should still handle their own errors
    inside it.

  • Because the final give-up value is not delivered through on_retry, callers
    that also want to log the terminal failure should do so from the return
    value / else clause, not the callback.

  • This does not address the separate hazard that surfaced the issue —
    timeout: :infinity on the underlying :erpc.call/5 means a single hung
    attempt never returns, so the expiry/2 budget never fires and no retry (and
    thus no on_retry) ever happens. Observability of retries is orthogonal to
    bounding a single attempt; a finite per-attempt timeout is still required.

`Retry.retry/2` performs its attempts silently. The core loop is nothing more
than a `Enum.reduce_while/3` over the delay stream that sleeps and re-invokes the
block:

```elixir
unquote(delays_from(stream_builder))
|> Enum.reduce_while(nil, fn delay, _last_result ->
  :timer.sleep(delay)
  fun.()
end)
```

There is no `Logger` call, no `:telemetry` event, and no user-facing hook
anywhere in the library. (`Retry.Annotation` does `require Logger`, but never
actually logs — it is an unused import.)

This became a problem for a caller that wraps `:erpc.call/5` behind a retry:

```elixir
retry with: constant_backoff(retry[:after]) |> expiry(retry[:limit]),
      atoms: &retry?/1 do
  do_call(node, module, function_name, function_args, opts)
end
```

With a budget such as `limit: 600_000` (10 minutes) a lost node causes up to ten
minutes of retries that produce **no log line, no metric, and no trace** — the
caller only sees the final `{:error, ...}` after the budget is exhausted. That
silent window is operationally dangerous: an outage looks like a hang.

The alternatives available to callers today are unsatisfying:

- **Log inside the `do` block.** Works, but conflates the "did it fail" decision
  with the "should I log" concern, and every call site has to reimplement it.
- **Switch to `retry_while/2`.** Gives per-iteration control, but forces callers
  to hand-write the continue/halt logic and the value matching they get for free
  from `atoms:`/`rescue_only:`.

Add an optional `on_retry` option to `Retry.retry/2`. It is a one-arity function
invoked with the retriable value (or the rescued exception) immediately before
each **actual** retry.

Semantics were chosen deliberately by driving the callback from the previously
ignored `reduce_while` accumulator (`last_result`) rather than from
`block_runner`:

- It is **not** called for the first attempt.
- It is **not** called for the final, given-up attempt (the stream is exhausted
  before the loop runs again). That value/exception is already returned or
  re-raised, so notifying about it would be redundant.
- It therefore fires exactly once per real retry — i.e. `attempts - 1` times.

```elixir
retry with: constant_backoff(1_000) |> expiry(10_000),
      on_retry: fn
        {:error, reason} -> Logger.warning("retrying, last error: #{inspect(reason)}")
        exception -> Logger.warning("retrying, last exception: #{inspect(exception)}")
      end do
  # interact with external service
end
```

The callback runs in the loop, outside the block's own `try/rescue`, so it is
never misinterpreted as a block failure. It is a fire-and-forget observability
hook, so any exception, throw, or exit it produces is **isolated** — a broken
logging call must never abort an in-progress retry. Rather than swallow that
error silently (which would hide a genuinely broken callback), it is **reported
via `Logger`** and then execution continues. `Logger` ships with Elixir, so this
adds no dependency. When `on_retry` is absent the behaviour is byte-for-byte
unchanged.

Scope decisions:

- Only `retry/2` gets the option. `retry_while/2` already hands the caller full
  control of each iteration, so they can log inline without a new hook.
- The callback receives just the retriable value/exception (arity 1). It carries
  the failure reason, and callers can capture any additional context (target
  node, attempt counter, …) from their own closure. We kept the signature
  minimal rather than inventing a context struct we would have to version.
- We did **not** add a `:telemetry` dependency. A plain callback keeps the
  library dependency-free; a caller who wants telemetry writes
  `on_retry: &:telemetry.execute(...)`.

- Retries are observable without changing the value-matching ergonomics of
  `retry/2`. The motivating `:erpc` wrapper can log every retriable failure:

  ```elixir
  retry with: constant_backoff(retry[:after]) |> expiry(retry[:limit]),
        atoms: &retry?/1,
        on_retry: fn {:error, %RPCError{reason: reason}} ->
          Logger.warning("RPC to #{inspect(node)} retrying after #{inspect(reason)}")
        end do
    do_call(node, module, function_name, function_args, opts)
  end
  ```

- Backwards compatible: existing call sites and the default behaviour are
  untouched; `on_retry` defaults to `nil`.
- The callback runs synchronously in the retrying process and its runtime counts
  against any `expiry/2` budget. Callers must keep it cheap and non-blocking.
- Errors raised, thrown, or exited from the callback do not affect the retry;
  they are caught and logged via `Logger.error/1` (with the original stacktrace
  via `Exception.format/3`). A broken callback is therefore visible in the logs
  instead of failing silently, but callers should still handle their own errors
  inside it.
- Because the final give-up value is not delivered through `on_retry`, callers
  that also want to log the terminal failure should do so from the return
  value / `else` clause, not the callback.
- This does not address the separate hazard that surfaced the issue —
  `timeout: :infinity` on the underlying `:erpc.call/5` means a single hung
  attempt never returns, so the `expiry/2` budget never fires and no retry (and
  thus no `on_retry`) ever happens. Observability of retries is orthogonal to
  bounding a single attempt; a finite per-attempt timeout is still required.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant