Ktor plugin order is not style — it decides what gets retried

TL;DR#

• A token refresh endpoint receiving 4× the expected traffic, traced to two lines in a Ktor client config being in the wrong order — Auth installed after HttpRequestRetry instead of before.
• Ktor plugins are interceptors on a pipeline, and install order determines nesting. Retry outside auth means each retry attempt runs the auth phase again; auth outside retry means one refresh covers all attempts.
• Neither order is an error. Both configurations are valid, both work, and the difference is a request-count multiplier on a shared dependency.
• What reading on buys: the nesting rule, the one measurement that reveals it, and the two plugin pairs where the order is a correctness question rather than a cost one.

The case this post is about#

A client with retry and auth, written the way the examples are ordered:

// commonMain/kotlin/network/Client.kt
fun httpClient(engine: HttpClientEngine, tokens: TokenStore) = HttpClient(engine) {

    install(HttpRequestRetry) {
        // Deliberately broad, and that is half the story: retrying any non-2xx means a 401
        // is retried too, and a 401 is what makes the auth phase refresh.
        retryIf(maxRetries = 3) { _, response -> !response.status.isSuccess() }
        exponentialDelay()
    }

    install(Auth) {
        bearer {
            loadTokens { tokens.current()?.let { BearerTokens(it.access, it.refresh) } }
            refreshTokens {
                // called when a 401 comes back
                tokens.refresh(oldTokens?.refreshToken ?: return@refreshTokens null)
                    ?.let { BearerTokens(it.access, it.refresh) }
            }
        }
    }

    install(ContentNegotiation) { json() }
}

Retry first, auth second. Everything works: requests succeed, expired tokens refresh, 5xx responses retry.

The symptom#

An alert from the auth service, which is a separate team's:

POST /oauth/token  —  request rate 4.1× the 30-day baseline
                      95% of requests carry a refresh_token that was already rotated

Refresh tokens are single-use and rotated on each refresh, so a request carrying an already-rotated token is a request that should not have been made. The auth service was rejecting them correctly and the volume was the problem — plus a race in which two near-simultaneous refreshes with the same token meant one of them rotated the token out from under the other, logging users out.

# our side, per user session, during a window where the API returned 401
  POST /oauth/token        4
  expected                 1

Four refreshes for one expired token, and only during windows when the API was answering 401 — which it did for about twenty minutes while its own token-validation dependency was degraded.

Why the obvious fix failed#

The first fix was single-flighting the refresh, which is a real improvement and did not address the cause:

private val refreshMutex = Mutex()
refreshTokens {
    refreshMutex.withLock { /* refresh, or return the token someone else just fetched */ }
}

Refresh requests fell from 4.1× to 1.3× and the logout race stopped. Which looked like the fix, and the residual 1.3× is the interesting part — a mutex serialises concurrent refreshes within one client and does nothing about sequential ones, which is what this was.

The second guess was token expiry skew — that we were refreshing early and unnecessarily:

if (token.expiresAt - clock.now() < 60.seconds) refresh()

We were not: the logs showed the refreshes clustered in bursts of four, seconds apart, all for the same originally-expired token. Not an early-refresh pattern; a repeated one.

The third attempt was to disable retry for the auth-bearing endpoints, which works and gives up retry on exactly the requests that most benefit from it.

What actually located it was counting phases rather than requests:

install(createClientPlugin("PhaseCounter") { /* … */ })

# one request, API returning 401 three times then 200
  Auth phase entered         4
  Retry attempts             4
  loadTokens invoked         4
  refreshTokens invoked      4       ← one per attempt, each a network call

The auth phase ran once per retry attempt. Which is not a bug in either plugin.

The actual mechanism#

A Ktor client is a pipeline of phases, and install adds interceptors. Install order determines the nesting, and the nesting determines what is inside what.

install order is outer-to-inner for the request path. The first-installed plugin's interceptor is outermost, so it wraps everything installed after it. Retry installed first means the retry loop wraps the auth interceptor:

  retry installed FIRST
    retry {
      attempt 1 → auth { load token, send, 401 → refresh } → 503
      attempt 2 → auth { load token, send }                 → 503
      attempt 3 → auth { load token, send }                 → 503
      attempt 4 → auth { load token, send }                 → 200
    }
    → the auth phase runs 4 times

  auth installed FIRST
    auth {
      load token
      retry { attempt 1 → 503, 2 → 503, 3 → 503, 4 → 200 }
      (a 401 anywhere → refresh once, then the retry loop runs again)
    }
    → the auth phase runs 1 time

Both are correct behaviours of both plugins. Retry is doing what it says: re-running the request, which includes everything nested inside it. Auth is doing what it says: supplying credentials for the request it wraps.

And the cost is not symmetrical. Retry-outside-auth re-runs a local token load every attempt, which is cheap — and invokes refreshTokens whenever an attempt returns 401, which is a network call to a service with rate limits and single-use tokens. Auth-outside-retry runs the retry loop inside one authenticated context, so one refresh covers every attempt.

Which is also why this took so long to find. In a pure 5xx storm the two orderings produce identical refresh traffic, because a 5xx never reaches the auth phase's 401 handler. We had been correlating against 503 windows and the signal is only in 401 windows — and 401s are not what anyone graphs when the complaint is "the API is failing".

The residual 1.3× the mutex did not fix was the sequential case: four attempts, each a separate pass through auth, none concurrent. A mutex has nothing to serialise.

And there are two pairs where the order is a correctness question rather than a cost one:

  Logging outside / inside Auth       inside logs the Authorization header. Outside does not.
  ContentNegotiation outside / inside  outside serialises before retry, so a retried request
    HttpRequestRetry                   re-sends the same bytes; inside re-serialises each time —
                                       which matters if the body contains a timestamp or a nonce.

The logging one is a secret-exposure question and the content-negotiation one is an idempotency question, and neither is a performance trade.

The fix#

Order the installs deliberately, with the reason on each, and assert the nesting rather than trusting the file to stay in order.

// commonMain/kotlin/network/Client.kt
//
// INSTALL ORDER IS BEHAVIOUR, not style. First-installed is OUTERMOST, so each plugin wraps
// everything below it. The comments are the reason each one is where it is; a reorder that
// does not update them is a reorder that has not been thought about.
fun httpClient(
    engine: HttpClientEngine,
    tokens: TokenStore,
    log: Logger = Logger.DEFAULT,      // injectable so the ordering can be asserted in a test
) = HttpClient(engine) {

    // 1. OUTERMOST — and deliberately outside Auth, so it never sees an Authorization header.
    //    Installed inside Auth it would log the bearer token on every request, which is a
    //    secret in a log file and a rotation.
    install(Logging) {
        logger = log
        level = LogLevel.INFO
        sanitizeHeader { it == HttpHeaders.Authorization }
    }

    // 2. Auth OUTSIDE retry. One authenticated context wraps the whole retry loop, so a 5xx
    //    storm costs retries and not token refreshes. Installed after retry, each attempt
    //    re-enters this phase — measured at 4.1× the refresh traffic on a shared service
    //    with single-use tokens.
    install(Auth) {
        bearer {
            loadTokens { tokens.current()?.let { BearerTokens(it.access, it.refresh) } }
            refreshTokens {
                tokens.refresh(oldTokens?.refreshToken ?: return@refreshTokens null)
                    ?.let { BearerTokens(it.access, it.refresh) }
            }
            // Only our own host. Without this, a redirect to a third party carries the
            // bearer token to it — which is the other way this plugin leaks a secret.
            sendWithoutRequest { it.url.host == API_HOST }
        }
    }

    // 3. ContentNegotiation OUTSIDE retry, so the body is serialised ONCE and every attempt
    //    re-sends identical bytes. Inside retry it re-serialises per attempt, and a body
    //    containing a client timestamp or an idempotency key would differ between attempts —
    //    which turns a retry into a second distinct request.
    install(ContentNegotiation) { json() }

    // 4. INNERMOST. Wraps only the transport, which is what should be retried.
    install(HttpRequestRetry) {
        // Server errors ONLY. A 401 is not a transport failure — it is a credential problem
        // that the Auth plugin above already handles, exactly once. Retrying it here is what
        // multiplied the refresh traffic even before the ordering made each retry re-auth.
        retryOnServerErrors(maxRetries = 3)
        // Full jitter, not plain exponential: every client that hit the same 503 computes
        // the same delay otherwise, and they return as a synchronised wave.
        delayMillis { attempt -> Random.nextLong(0, 1000L shl attempt) }
    }
}

And the assertion, because install order is four lines that any future edit can reorder with no test failing:

// commonTest/kotlin/network/PluginOrderTest.kt
//
// Asserts the NESTING by counting phase entries, which is the only observable consequence.
// A test that asserted "Auth is installed before HttpRequestRetry" by reading the source
// would be checking the file rather than the behaviour.
class PluginOrderTest {

    @Test
    fun aRetryStormCostsRetriesAndNotRefreshes() = runTest {
        var refreshes = 0
        var feedAttempts = 0

        // The two counters are SEPARATE on purpose. An earlier version counted every request
        // in one variable and gated the 401s on it, so the refresh request consumed one of
        // the three failures and the feed was only attempted three times — the assertion
        // below failed against a client that was behaving correctly.
        val engine = MockEngine { request ->
            if (request.url.encodedPath == "/oauth/token") {
                refreshes++
                respondOk(TOKEN_JSON)
            } else {
                feedAttempts++
                if (feedAttempts <= 3) respondError(HttpStatusCode.Unauthorized)
                else respondOk("""{"ok":true}""")
            }
        }

        httpClient(engine, FakeTokenStore(expired = true)).get("https://api.example.com/feed")

        // 4 transport attempts is correct and expected — that is what retry is for.
        assertEquals(4, feedAttempts, "expected 4 transport attempts")

        // ONE refresh. If Auth is installed after HttpRequestRetry this is 4, and the only
        // symptom is traffic on someone else's service.
        assertEquals(1, refreshes,
            "expected 1 token refresh across a 3-retry 401 storm, got $refreshes — " +
            "Auth is almost certainly installed AFTER HttpRequestRetry, so each retry " +
            "attempt re-enters the auth phase")
    }

    @Test
    fun theAuthorizationHeaderIsNeverLogged() = runTest {
        val sink = RecordingLogger()
        httpClient(MockEngine { respondOk() }, FakeTokenStore(), log = sink)
            .get("https://api.example.com/feed")

        assertTrue(sink.lines.none { it.contains("Bearer", ignoreCase = true) },
            "a bearer token reached the log — Logging is installed INSIDE Auth")
    }
}

And the output it produced, with the original order restored to check the test earns its place:

$ ./gradlew :core:network:allTests

PluginOrderTest > aRetryStormCostsRetriesAndNotRefreshes FAILED
    expected 1 token refresh across a 3-retry 401 storm, got 4 — Auth is almost certainly
    installed AFTER HttpRequestRetry, so each retry attempt re-enters the auth phase
    × 5 targets

# and with the shipped order
PluginOrderTest > aRetryStormCostsRetriesAndNotRefreshes PASSED  × 5
PluginOrderTest > theAuthorizationHeaderIsNeverLogged    PASSED  × 5

And the service-side effect, one week after:

POST /oauth/token  —  request rate 1.02× the 30-day baseline
                      0.3% carrying an already-rotated token

How we proved it#

That the auth phase ran per attempt — the phase counter, which is the measurement that located it after request counting had not:

  one request, API returning 401 ×3 then 200
                          retry first    auth first
  transport attempts            4             4
  Auth phase entered            4             1
  loadTokens invoked            4             1
  refreshTokens invoked         4             1   ← the whole defect, in one row

Counting transport requests shows four either way — that is what retry is for, and it is not the problem. Counting phases shows that one ordering turns four transport attempts into four calls to somebody else's rate-limited endpoint, and the other turns them into one.

That the mutex fixed a different problem. Both measured, because the mutex's improvement was large enough to look like the answer:

  configuration                           refresh rate   logout race
  as shipped                                  4.1×          present
  + refresh mutex                             1.3×          gone
  auth installed before retry (no mutex)      1.0×          present
  both                                        1.0×          gone

The mutex addresses concurrency and the order addresses repetition. They are both worth having and only one of them was the cause.

That the content-negotiation ordering is an idempotency question. Measured with a body carrying a client timestamp, which is the case that makes it visible:

  ContentNegotiation …     body bytes across 4 attempts
  outside retry            identical          ← one serialisation
  inside retry             4 different        ← timestamp re-evaluated per attempt

A retried request with a different body is a second distinct request, and a server deduplicating on body hash would not catch it.

That the logging ordering leaks a token. The fixture, because it is the ordering mistake with a security consequence rather than a cost one:

$ ./gradlew :core:network:allTests --tests '*AuthorizationHeaderIsNeverLogged*'
  Logging installed INSIDE Auth    FAILED — "Authorization: Bearer eyJhb…" in 1 log line
  Logging installed OUTSIDE Auth   PASSED

And sanitizeHeader is not sufficient on its own: it covers the header when Ktor logs it, and an engine-level logger installed below Auth sees the real request regardless.

What I cannot tell you is whether the order rule holds for every plugin pair. Ktor's phases are documented and most plugins declare which phase they attach to, so the nesting is determinable — and I verified it for the four we install, not for all of them. A plugin that attaches to a phase rather than wrapping would not follow the install-order rule at all, and the phase counter is how I would check rather than reasoning from the install list.

And a limit of the test. It asserts the consequence of the ordering, which is right, and it would also pass if someone replaced retry with a no-op. The second assertion — four transport attempts — exists for that, and together they pin the behaviour rather than the file. Neither checks the content-negotiation or logging orderings, which have their own tests.

What this generalizes to#

Where a framework composes behaviour by nesting interceptors, the order of registration is configuration, and it usually has no error state — every ordering produces a working client with different costs and sometimes different correctness. The useful instrument is not a request count but a phase count, because the nesting is visible only in how many times each layer runs. And when the consequence of a wrong order lands on a dependency rather than on you, nothing local will tell you: our alert came from the auth team.

---

Related#

• One HttpTimeout block, four engines that honour it differently — the other configuration surface where a value means different things per engine.
• An 11-second blip became a 38-minute outage — the jitter in the retry block above, and the arithmetic behind it.

Keep reading#

One post a week on shipping mobile software. No digests, no course pitch. Subscribe.