Fix/mint client side timeout by freevova · Pull Request #571 · elixir-grpc/grpc

freevova · 2026-08-14T11:26:54Z

The Mint adapter accepts and parses :timeout, but never applies it. do_receive_data/3 waits on the stream response process with GenServer.call(pid, :get_response, :infinity), so the option only ever leaves the client as the grpc-timeout header — a deadline the server enforces. When no response can arrive at all, the caller blocks forever despite having asked for a deadline.

We hit this in production. The connection process crashed partway through notifying pending requests on a closed connection, so the callers queued behind it were never told the connection was gone; their background jobs stayed blocked for ~19 hours until the pod was restarted. #559 fixes that particular crash (thank you — 1.0.3 resolved it for us), but the :infinity receive means any other path that leaves a caller unnotified ends the same way.

What this changes

The requested timeout is passed down to build_stream/3, and an elapsed deadline becomes a DEADLINE_EXCEEDED GRPC.RPCError. Two related corrections came out of that:

:deadline now takes precedence over :timeout, as recv/2 documents ("when the request is timeout, will override timeout"). recv/2 always fills in the 10s default under :timeout via Keyword.put_new/3, so an explicit deadline could otherwise never take effect.
Both options are resolved by GRPC.TimeUtils.to_relative/2, which returns a float — and a negative one for a deadline already in the past — so the value is rounded and clamped before it reaches a receive timeout, which requires a non-negative integer.

Giving up also cleans up after itself: the request is reset, so the server stops working on it, and the process buffering the response is stopped. That process is linked to the caller rather than to the connection, so nothing else would shut it down — least of all when the connection process is the very thing that went away. Both steps are best effort and bounded: they run after the deadline already elapsed, against processes that may themselves be gone or wedged, so a failure to tidy up must neither replace the error the caller is about to get nor keep it waiting much longer. ConnectionProcess.cancel/3 gained an optional timeout for that; its default is unchanged.

Scope

Only unary receives are bounded.

Server and bidirectional streams are consumed lazily by the caller, where a gap between messages is expected rather than a failure.

Client streams are left as they are: recv/2 fills in the unary 10s default for every request type, while GRPC.Stub documents streaming calls as unbounded, so honouring :timeout there would silently cut off uploads that legitimately take longer to be answered.

Behaviour changes

A unary call that never receives a response now fails after the 10s that GRPC.Stub.call/5 already documents, instead of blocking indefinitely.
If DATA arrived but trailers never did, the call now returns DEADLINE_EXCEEDED rather than the partial message. A unary response is not complete without grpc-status, so I believe this is correct, but it is a deliberate choice rather than an accident.

Both are recorded in the changelog. There was no unreleased heading to file them under, so I added one — move the entry wherever you prefer.

Tests

the deadline fires and halts the stream, and does not fire when the response arrives in time
the float milliseconds a :deadline resolves into are accepted, and a deadline already in the past is treated as an immediate one
an explicit :deadline wins over a long :timeout
the stream response process is stopped after the caller gives up
an end-to-end deadline: call through GRPC.Stub against a live server, which is what actually exercises the parse_req_opts pipeline the two fixes above live in

The whole suite passes locally (375 passed, 2 skipped), and reverting the library change makes every new test fail.

One adjacent thing, not fixed here

While adding the reset I noticed that handle_call({:cancel_request, ref}, ...) pops the ref and calls Mint.HTTP2.cancel_request/2, but does not call drop_queued_request_chunks/2 the way cancel_dead_stream/4 does. Leftover {ref, body, from} entries then survive in request_stream_queue, and the next handle_continue(:process_request_stream_queue, ...) calls get_window_size/2 for a ref Mint no longer knows, which raises ArgumentError. That was reachable before only through an explicit GRPC.Stub.cancel/1; automatic reset on a deadline makes it easier to hit.

I have only reproduced the leftover state by injecting it rather than by starving a real send window end to end, so I am flagging it rather than fixing it here.

The Mint adapter accepts and parses `:timeout` but never applies it: unary receives wait on the stream response process with `:infinity`, so the option only ever reaches the server as the `grpc-timeout` header. When no response can arrive — the connection going down without notifying the pending request, for instance — the caller blocks forever even though it asked for a deadline. Pass the requested timeout down to `build_stream/3` and translate an elapsed deadline into `DEADLINE_EXCEEDED`. Along the way: * `:deadline` now takes precedence over `:timeout`, as documented. `recv/2` always fills in the 10s default under `:timeout`, so an explicit deadline could otherwise never take effect. * Both options are resolved by `GRPC.TimeUtils.to_relative/2`, which returns a float — and a negative one for a deadline already in the past — so the value is rounded and clamped before it reaches a receive timeout. * Giving up resets the request, so the server stops working on it, and stops the process buffering the response, which is linked to the caller rather than to the connection and would otherwise outlive the call. Both steps are bounded and best effort: they run after the deadline elapsed, against processes that may themselves be gone or wedged. Only unary receives are bounded. Server and bidirectional streams are consumed lazily by the caller, where a gap between messages is expected rather than a failure. A client stream awaits its response through a separate `recv/2` call, which `GRPC.Stub` documents as unbounded even though it fills in the same 10s default — worth settling separately from this fix. Note this changes the default behaviour of a unary call that never receives a response: it now fails after the 10s documented in `GRPC.Stub.call/5` instead of blocking indefinitely.

The enforced deadline alters a documented default, which is the kind of change this changelog records under `### Behavior Changes`. There was no unreleased heading to file it under, so add one rather than assume the next version number.

sleipnir · 2026-08-18T21:00:21Z

Thank you @freevova

Two defects in grpc_core, both silent, both making the deadline a caller asks for differ from the one that travels. 1. encode_timeout/1 truncated any duration >= 1000 ms to whole seconds. @ms_ceiling was 1000, so only sub-second values used the millisecond unit and everything above went through div(timeout, 1000). 2500 ms went out as "2S" and was read back as 2000 ms; 3847 ms lost 847 ms. The wire format defines TimeoutValue as "a positive integer as ASCII string of at most 8 digits", with Millisecond among the valid units, so any duration below 100_000_000 ms is representable exactly and needs no coarser unit. The ceiling is raised to that limit and the second/minute/hour ladder rescaled to stay inside 8 digits. grpc-go does the opposite of the current behaviour on both axes. Its EncodeDuration starts at nanoseconds and steps coarser only when the value will not fit, maximising precision, and its div() rounds *up* -- so a deadline is never silently shortened. Its maxTimeoutValue is 100000000 - 1, the same 8-digit limit this now uses. Round-number timeouts encoded exactly (1000 -> "1S" -> 1000 ms), which is why this went unnoticed: a configured constant is usually a round number. A *propagated* deadline is not -- it is whatever is left of the caller's budget, so the loss lands on every value and compounds at every hop. 2. TimeUtils.to_relative/2 returned a float, so the :deadline option was inert. The result was built as `DateTime.to_unix(dt, :second) * 1000 + elem(dt.microsecond, 0) * 0.001`; the trailing term made every return value a float and added binary rounding error, so 5.005 ms came back as 5.0048828125. append_timeout/2 matches on is_integer/1 and falls through to a catch-all, so `deadline:` produced no grpc-timeout header at all. The gun adapter's start_timeout/1 has the same is_integer//:infinity clause pair with no catch-all, so a float also failed locally -- as a FunctionClauseError that await/2 converts into a misleading terminated-stream error, and only when the response had not already arrived. Fast calls silently lost the deadline; slow ones failed pointing at the wrong cause. DateTime.diff/3 over microseconds, truncated with div/2, replaces the hand-rolled arithmetic. Relationship to elixir-grpc#571 -------------------- elixir-grpc#571 (Fix/mint client side timeout) independently ran into (2) and works around it at the call site in mint.ex: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) With this commit that round/1 becomes redundant. The max(0, _) should stay: a deadline already in the past still resolves to a negative number of milliseconds (verified: -5003 for a deadline 5s ago), and a receive timeout needs a non-negative integer. Nothing here overlaps elixir-grpc#571's own subject -- that the mint adapter never applied the timeout at all -- and this touches no file it touches. elixir-grpc#571 also corrects `:deadline` being unable to override the `:timeout` that recv/2 fills in by default. That fix is left to it rather than duplicated here. Verification ------------ The existing encode_timeout tests asserted encoded strings and never a round-trip, which is exactly how the truncation survived: encode_timeout(1000) == "1S" holds both before and after data is lost. Added round-trip fidelity assertions, an 8-digit wire-limit check, and grpc-timeout header coverage. Every new assertion was confirmed to fail against the unfixed code. Separately property-checked 448 values from 1 ms to 1.8e13 ms: no encoding exceeds 8 digits, no decoded value is greater than its input, and the loss is always below the granularity of the unit chosen. utils_test.exs moves from grpc/test to grpc_core/test. It covers a grpc_core module, but the grpc package resolves grpc_core from hex, so a test there cannot exercise a local change to it -- and its assertions, written against a 1000 ms ceiling, would have broken the next time grpc bumped grpc_core. http2_test.exs stays in grpc because it needs GRPC.Channel and GRPC.Server.Stream from sibling packages; the new header coverage lives in grpc_core against a bare map. All three suites pass with --warnings-as-errors: grpc_core 116, grpc_server 211, grpc 342.

…re change elixir-grpc#571 landed `assert is_float(timeout)` on the value GRPC.TimeUtils.to_relative/2 returns. The parent commit makes that an integer, so the assertion becomes wrong -- but not visibly: the grpc package resolves grpc_core from hex, so its suite tests the published 1.0.4 and stays green either way. Verified by path-linking grpc_core, where it fails with `code: assert is_float(timeout)`. It would have broken whoever next bumped grpc's grpc_core requirement rather than failing here. Swapping it to is_integer just inverts the problem -- green after the release, red before it. No concrete type is correct on both sides, and this package straddles that release by construction. So it asserts is_number/1, which mirrors the guard the call site actually depends on: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) That is the real contract, and it holds whichever grpc_core is resolved. The test's subject is unchanged and still passes: a `:deadline` resolved through to_relative/2 is accepted and fires DEADLINE_EXCEEDED. Also notes which half of the call site is load-bearing -- round/1 becomes a no-op once to_relative/2 returns an integer, while max(0, _) is still required, because a deadline in the past resolves to a negative number of milliseconds and a receive timeout must be non-negative.

Two defects in grpc_core, both silent, both making the deadline a caller asks for differ from the one that travels. 1. encode_timeout/1 truncated any duration >= 1000 ms to whole seconds. @ms_ceiling was 1000, so only sub-second values used the millisecond unit and everything above went through div(timeout, 1000). 2500 ms went out as "2S" and was read back as 2000 ms; 3847 ms lost 847 ms. The wire format defines TimeoutValue as "a positive integer as ASCII string of at most 8 digits", with Millisecond among the valid units, so any duration below 100_000_000 ms is representable exactly and needs no coarser unit. The ceiling is raised to that limit and the second/minute/hour ladder rescaled to stay inside 8 digits. grpc-go does the opposite of the current behaviour on both axes. Its EncodeDuration starts at nanoseconds and steps coarser only when the value will not fit, maximising precision, and its div() rounds *up* -- so a deadline is never silently shortened. Its maxTimeoutValue is 100000000 - 1, the same 8-digit limit this now uses. Round-number timeouts encoded exactly (1000 -> "1S" -> 1000 ms), which is why this went unnoticed: a configured constant is usually a round number. A *propagated* deadline is not -- it is whatever is left of the caller's budget, so the loss lands on every value and compounds at every hop. 2. TimeUtils.to_relative/2 returned a float, so the :deadline option was inert. The result was built as `DateTime.to_unix(dt, :second) * 1000 + elem(dt.microsecond, 0) * 0.001`; the trailing term made every return value a float and added binary rounding error, so 5.005 ms came back as 5.0048828125. append_timeout/2 matches on is_integer/1 and falls through to a catch-all, so `deadline:` produced no grpc-timeout header at all. The gun adapter's start_timeout/1 has the same is_integer//:infinity clause pair with no catch-all, so a float also failed locally -- as a FunctionClauseError that await/2 converts into a misleading terminated-stream error, and only when the response had not already arrived. Fast calls silently lost the deadline; slow ones failed pointing at the wrong cause. DateTime.diff/3 over microseconds, truncated with div/2, replaces the hand-rolled arithmetic. Relationship to elixir-grpc#571 -------------------- elixir-grpc#571 (Fix/mint client side timeout) independently ran into (2) and works around it at the call site in mint.ex: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) With this commit that round/1 becomes redundant. The max(0, _) should stay: a deadline already in the past still resolves to a negative number of milliseconds (verified: -5003 for a deadline 5s ago), and a receive timeout needs a non-negative integer. Nothing here overlaps elixir-grpc#571's own subject -- that the mint adapter never applied the timeout at all -- and this touches no file it touches. elixir-grpc#571 also corrects `:deadline` being unable to override the `:timeout` that recv/2 fills in by default. That fix is left to it rather than duplicated here. Verification ------------ The existing encode_timeout tests asserted encoded strings and never a round-trip, which is exactly how the truncation survived: encode_timeout(1000) == "1S" holds both before and after data is lost. Added round-trip fidelity assertions, an 8-digit wire-limit check, and grpc-timeout header coverage. Every new assertion was confirmed to fail against the unfixed code. Separately property-checked 448 values from 1 ms to 1.8e13 ms: no encoding exceeds 8 digits, no decoded value is greater than its input, and the loss is always below the granularity of the unit chosen. utils_test.exs moves from grpc/test to grpc_core/test. It covers a grpc_core module, but the grpc package resolves grpc_core from hex, so a test there cannot exercise a local change to it -- and its assertions, written against a 1000 ms ceiling, would have broken the next time grpc bumped grpc_core. http2_test.exs stays in grpc because it needs GRPC.Channel and GRPC.Server.Stream from sibling packages; the new header coverage lives in grpc_core against a bare map. All three suites pass with --warnings-as-errors: grpc_core 116, grpc_server 211, grpc 342.

…re change elixir-grpc#571 landed `assert is_float(timeout)` on the value GRPC.TimeUtils.to_relative/2 returns. The parent commit makes that an integer, so the assertion becomes wrong -- but not visibly: the grpc package resolves grpc_core from hex, so its suite tests the published 1.0.4 and stays green either way. Verified by path-linking grpc_core, where it fails with `code: assert is_float(timeout)`. It would have broken whoever next bumped grpc's grpc_core requirement rather than failing here. Swapping it to is_integer just inverts the problem -- green after the release, red before it. No concrete type is correct on both sides, and this package straddles that release by construction. So it asserts is_number/1, which mirrors the guard the call site actually depends on: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) That is the real contract, and it holds whichever grpc_core is resolved. The test's subject is unchanged and still passes: a `:deadline` resolved through to_relative/2 is accepted and fires DEADLINE_EXCEEDED. Also notes which half of the call site is load-bearing -- round/1 becomes a no-op once to_relative/2 returns an integer, while max(0, _) is still required, because a deadline in the past resolves to a negative number of milliseconds and a receive timeout must be non-negative.

* fix(core): stop silently shortening gRPC deadlines on the wire Two defects in grpc_core, both silent, both making the deadline a caller asks for differ from the one that travels. 1. encode_timeout/1 truncated any duration >= 1000 ms to whole seconds. @ms_ceiling was 1000, so only sub-second values used the millisecond unit and everything above went through div(timeout, 1000). 2500 ms went out as "2S" and was read back as 2000 ms; 3847 ms lost 847 ms. The wire format defines TimeoutValue as "a positive integer as ASCII string of at most 8 digits", with Millisecond among the valid units, so any duration below 100_000_000 ms is representable exactly and needs no coarser unit. The ceiling is raised to that limit and the second/minute/hour ladder rescaled to stay inside 8 digits. grpc-go does the opposite of the current behaviour on both axes. Its EncodeDuration starts at nanoseconds and steps coarser only when the value will not fit, maximising precision, and its div() rounds *up* -- so a deadline is never silently shortened. Its maxTimeoutValue is 100000000 - 1, the same 8-digit limit this now uses. Round-number timeouts encoded exactly (1000 -> "1S" -> 1000 ms), which is why this went unnoticed: a configured constant is usually a round number. A *propagated* deadline is not -- it is whatever is left of the caller's budget, so the loss lands on every value and compounds at every hop. 2. TimeUtils.to_relative/2 returned a float, so the :deadline option was inert. The result was built as `DateTime.to_unix(dt, :second) * 1000 + elem(dt.microsecond, 0) * 0.001`; the trailing term made every return value a float and added binary rounding error, so 5.005 ms came back as 5.0048828125. append_timeout/2 matches on is_integer/1 and falls through to a catch-all, so `deadline:` produced no grpc-timeout header at all. The gun adapter's start_timeout/1 has the same is_integer//:infinity clause pair with no catch-all, so a float also failed locally -- as a FunctionClauseError that await/2 converts into a misleading terminated-stream error, and only when the response had not already arrived. Fast calls silently lost the deadline; slow ones failed pointing at the wrong cause. DateTime.diff/3 over microseconds, truncated with div/2, replaces the hand-rolled arithmetic. Relationship to #571 -------------------- #571 (Fix/mint client side timeout) independently ran into (2) and works around it at the call site in mint.ex: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) With this commit that round/1 becomes redundant. The max(0, _) should stay: a deadline already in the past still resolves to a negative number of milliseconds (verified: -5003 for a deadline 5s ago), and a receive timeout needs a non-negative integer. Nothing here overlaps #571's own subject -- that the mint adapter never applied the timeout at all -- and this touches no file it touches. #571 also corrects `:deadline` being unable to override the `:timeout` that recv/2 fills in by default. That fix is left to it rather than duplicated here. Verification ------------ The existing encode_timeout tests asserted encoded strings and never a round-trip, which is exactly how the truncation survived: encode_timeout(1000) == "1S" holds both before and after data is lost. Added round-trip fidelity assertions, an 8-digit wire-limit check, and grpc-timeout header coverage. Every new assertion was confirmed to fail against the unfixed code. Separately property-checked 448 values from 1 ms to 1.8e13 ms: no encoding exceeds 8 digits, no decoded value is greater than its input, and the loss is always below the granularity of the unit chosen. utils_test.exs moves from grpc/test to grpc_core/test. It covers a grpc_core module, but the grpc package resolves grpc_core from hex, so a test there cannot exercise a local change to it -- and its assertions, written against a 1000 ms ceiling, would have broken the next time grpc bumped grpc_core. http2_test.exs stays in grpc because it needs GRPC.Channel and GRPC.Server.Stream from sibling packages; the new header coverage lives in grpc_core against a bare map. All three suites pass with --warnings-as-errors: grpc_core 116, grpc_server 211, grpc 342. * test(grpc): make the mint deadline type assertion survive the grpc_core change #571 landed `assert is_float(timeout)` on the value GRPC.TimeUtils.to_relative/2 returns. The parent commit makes that an integer, so the assertion becomes wrong -- but not visibly: the grpc package resolves grpc_core from hex, so its suite tests the published 1.0.4 and stays green either way. Verified by path-linking grpc_core, where it fails with `code: assert is_float(timeout)`. It would have broken whoever next bumped grpc's grpc_core requirement rather than failing here. Swapping it to is_integer just inverts the problem -- green after the release, red before it. No concrete type is correct on both sides, and this package straddles that release by construction. So it asserts is_number/1, which mirrors the guard the call site actually depends on: milliseconds when is_number(milliseconds) -> max(0, round(milliseconds)) That is the real contract, and it holds whichever grpc_core is resolved. The test's subject is unchanged and still passes: a `:deadline` resolved through to_relative/2 is accepted and fires DEADLINE_EXCEEDED. Also notes which half of the call site is load-bearing -- round/1 becomes a no-op once to_relative/2 returns an integer, while max(0, _) is still required, because a deadline in the past resolves to a negative number of milliseconds and a receive timeout must be non-negative. * test: remove explanatory comments from the deadline tests Every comment removed here restated the name of the test it sat above. The 8-digit wire limit comment duplicated the test named for that limit, and the float comment duplicated an assertion on is_integer. The one case where the comment carried information the code did not is now in the test name: to_relative/2 returns an integer because append_timeout/2 drops a float rather than sending it. The reasoning behind the change belongs in the pull request, not beside the assertions.

freevova added 2 commits August 14, 2026 12:24

cgreeno mentioned this pull request Aug 18, 2026

fix(core): stop silently shortening gRPC deadlines on the wire #574

Merged

Merge branch 'master' into fix/mint-client-side-timeout

68f1e03

sleipnir merged commit 75fd2d8 into elixir-grpc:master Aug 18, 2026
7 checks passed

Navigation Menu

Uh oh!

Fix/mint client side timeout - #571

Fix/mint client side timeout#571
sleipnir merged 3 commits into
elixir-grpc:masterfrom
freevova:fix/mint-client-side-timeout

freevova commented Aug 14, 2026

Uh oh!

Uh oh!

sleipnir commented Aug 18, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Uh oh!

Conversation

freevova commented Aug 14, 2026

What this changes

Scope

Behaviour changes

Tests

One adjacent thing, not fixed here

Uh oh!

Uh oh!

sleipnir commented Aug 18, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants