From c20616666033aee85ccd39ac7652525d34ab8fc4 Mon Sep 17 00:00:00 2001 From: Chris Greeno Date: Tue, 18 Aug 2026 15:24:54 +0100 Subject: [PATCH 1/3] 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. --- grpc/test/grpc/transport/utils_test.exs | 78 ------------ grpc_core/lib/grpc/time_utils.ex | 14 +-- grpc_core/lib/grpc/transport/utils.ex | 5 +- grpc_core/test/grpc/time_utils_test.exs | 26 ++++ .../grpc/transport/http2_timeout_test.exs | 32 +++++ grpc_core/test/grpc/transport/utils_test.exs | 116 ++++++++++++++++++ 6 files changed, 181 insertions(+), 90 deletions(-) delete mode 100644 grpc/test/grpc/transport/utils_test.exs create mode 100644 grpc_core/test/grpc/transport/http2_timeout_test.exs create mode 100644 grpc_core/test/grpc/transport/utils_test.exs diff --git a/grpc/test/grpc/transport/utils_test.exs b/grpc/test/grpc/transport/utils_test.exs deleted file mode 100644 index 244dcbde7..000000000 --- a/grpc/test/grpc/transport/utils_test.exs +++ /dev/null @@ -1,78 +0,0 @@ -defmodule GRPC.Transport.UtilsTest do - use ExUnit.Case, async: true - - import GRPC.Transport.Utils - - # unit: ns - @ns_ceiling 1000 - @us_ceiling 1000_000 - - # unit: ms - @ms_ceiling 1000 - @second_ceiling @ms_ceiling * 60 - @minute_ceiling @second_ceiling * 60 - - test "encode_ns/1 returns 0" do - assert encode_ns(-1) == "0u" - assert encode_ns(0) == "0u" - end - - test "encode_ns/1 returns nanoseconds" do - assert encode_ns(1) == "1n" - assert encode_ns(@ns_ceiling - 1) == "999n" - end - - test "encode_ns/1 returns microseconds" do - assert encode_ns(@ns_ceiling) == "1u" - assert encode_ns(@us_ceiling - 1) == "999u" - end - - test "encode_timeout/1 returns 0" do - assert encode_timeout(-1) == "0u" - assert encode_timeout(0) == "0u" - end - - test "encode_timeout/1 returns millisecond" do - assert encode_timeout(1) == "1m" - assert encode_timeout(@ms_ceiling - 1) == "999m" - end - - test "encode_timeout/1 returns second" do - assert encode_timeout(@ms_ceiling) == "1S" - assert encode_timeout(@second_ceiling - 1) == "59S" - end - - test "encode_timeout/1 returns minute" do - assert encode_timeout(@second_ceiling) == "1M" - assert encode_timeout(@minute_ceiling - 1) == "59M" - end - - test "encode_timeout/1 returns hour" do - assert encode_timeout(@minute_ceiling) == "1H" - assert encode_timeout(@minute_ceiling * 24) == "24H" - end - - test "decode_timeout/1 returns 0" do - assert decode_timeout("0u") == 0 - end - - test "decode_timeout/1 returns 0.123" do - assert decode_timeout("123u") == 0 - end - - test "decode_timeout/1 returns 123 ms" do - assert decode_timeout("123m") == 123 - end - - test "decode_timeout/1 returns seconds" do - assert decode_timeout("123S") == 123_000 - end - - test "decode_timeout/1 returns minutes" do - assert decode_timeout("123M") == 123 * 60_000 - end - - test "decode_timeout/1 returns hour" do - assert decode_timeout("123H") == 123 * 3_600_000 - end -end diff --git a/grpc_core/lib/grpc/time_utils.ex b/grpc_core/lib/grpc/time_utils.ex index 4acdcb8f2..dc2b9b80e 100644 --- a/grpc_core/lib/grpc/time_utils.ex +++ b/grpc_core/lib/grpc/time_utils.ex @@ -2,23 +2,17 @@ defmodule GRPC.TimeUtils do @moduledoc false @doc """ - Returns relative time in milliseconds. + Returns relative time in whole milliseconds, truncated so a deadline is never extended. ## Examples iex> from = DateTime.utc_now iex> us = DateTime.to_unix(from, :microsecond) iex> datetime = DateTime.from_unix!(us + 5005, :microsecond) - iex> Float.round(GRPC.TimeUtils.to_relative(datetime, from), 3) - 5.005 + iex> GRPC.TimeUtils.to_relative(datetime, from) + 5 """ def to_relative(datetime, from \\ DateTime.utc_now()) do - ms = datetime_to_milliseconds(datetime) - now_ms = datetime_to_milliseconds(from) - ms - now_ms - end - - defp datetime_to_milliseconds(datetime) do - DateTime.to_unix(datetime, :second) * 1000 + elem(datetime.microsecond, 0) * 0.001 + datetime |> DateTime.diff(from, :microsecond) |> div(1000) end end diff --git a/grpc_core/lib/grpc/transport/utils.ex b/grpc_core/lib/grpc/transport/utils.ex index 5e2b33181..5e6fe3567 100644 --- a/grpc_core/lib/grpc/transport/utils.ex +++ b/grpc_core/lib/grpc/transport/utils.ex @@ -7,8 +7,9 @@ defmodule GRPC.Transport.Utils do # @ms_ceiling @us_ceiling * 1000 # unit: ms - @ms_ceiling 1000 - @second_ceiling @ms_ceiling * 60 + # TimeoutValue is capped at 8 digits, so anything below @ms_ceiling encodes exactly. + @ms_ceiling 100_000_000 + @second_ceiling @ms_ceiling * 1000 @minute_ceiling @second_ceiling * 60 @doc """ diff --git a/grpc_core/test/grpc/time_utils_test.exs b/grpc_core/test/grpc/time_utils_test.exs index 588130ccd..7e3544cee 100644 --- a/grpc_core/test/grpc/time_utils_test.exs +++ b/grpc_core/test/grpc/time_utils_test.exs @@ -2,4 +2,30 @@ defmodule GRPC.TimeUtilsTest do use ExUnit.Case, async: true doctest GRPC.TimeUtils + + describe "to_relative/2" do + test "returns an integer" do + # A float is dropped by append_timeout/2 rather than sent. + from = DateTime.utc_now() + + for offset_us <- [1_000, 5_005, 2_000_000, 999] do + result = GRPC.TimeUtils.to_relative(DateTime.add(from, offset_us, :microsecond), from) + assert is_integer(result), "got #{inspect(result)} for #{offset_us}us" + end + end + + test "truncates rather than rounds, so a deadline is never extended" do + from = DateTime.utc_now() + almost_6ms = DateTime.add(from, 5_999, :microsecond) + + assert GRPC.TimeUtils.to_relative(almost_6ms, from) == 5 + end + + test "an already-expired deadline is non-positive" do + from = DateTime.utc_now() + past = DateTime.add(from, -1_500, :millisecond) + + assert GRPC.TimeUtils.to_relative(past, from) <= 0 + end + end end diff --git a/grpc_core/test/grpc/transport/http2_timeout_test.exs b/grpc_core/test/grpc/transport/http2_timeout_test.exs new file mode 100644 index 000000000..c08233658 --- /dev/null +++ b/grpc_core/test/grpc/transport/http2_timeout_test.exs @@ -0,0 +1,32 @@ +defmodule GRPC.Transport.HTTP2TimeoutTest do + use ExUnit.Case, async: true + + alias GRPC.Transport.HTTP2 + + # A bare map suffices: GRPC.Client.Stream lives in the grpc package, unreachable from here. + @stream %{ + codec: GRPC.Codec.Proto, + compressor: nil, + accepted_compressors: [], + channel: %{headers: %{}}, + headers: %{} + } + + defp timeout_header(opts) do + HTTP2.client_headers_without_reserved(@stream, opts) + |> Enum.find(fn {k, _v} -> k == "grpc-timeout" end) + end + + describe "grpc-timeout header" do + test "an integer timeout is sent in milliseconds" do + assert timeout_header(%{timeout: 5}) == {"grpc-timeout", "5m"} + assert timeout_header(%{timeout: 1500}) == {"grpc-timeout", "1500m"} + end + + test ":infinity and nil send no deadline" do + assert timeout_header(%{timeout: :infinity}) == nil + assert timeout_header(%{timeout: nil}) == nil + assert timeout_header(%{}) == nil + end + end +end diff --git a/grpc_core/test/grpc/transport/utils_test.exs b/grpc_core/test/grpc/transport/utils_test.exs new file mode 100644 index 000000000..32b735ea5 --- /dev/null +++ b/grpc_core/test/grpc/transport/utils_test.exs @@ -0,0 +1,116 @@ +defmodule GRPC.Transport.UtilsTest do + use ExUnit.Case, async: true + + import GRPC.Transport.Utils + + # unit: ns + @ns_ceiling 1000 + @us_ceiling 1000_000 + + # unit: ms, must track GRPC.Transport.Utils. + @ms_ceiling 100_000_000 + @second_ceiling @ms_ceiling * 1000 + @minute_ceiling @second_ceiling * 60 + + test "encode_ns/1 returns 0" do + assert encode_ns(-1) == "0u" + assert encode_ns(0) == "0u" + end + + test "encode_ns/1 returns nanoseconds" do + assert encode_ns(1) == "1n" + assert encode_ns(@ns_ceiling - 1) == "999n" + end + + test "encode_ns/1 returns microseconds" do + assert encode_ns(@ns_ceiling) == "1u" + assert encode_ns(@us_ceiling - 1) == "999u" + end + + test "encode_timeout/1 returns 0" do + assert encode_timeout(-1) == "0u" + assert encode_timeout(0) == "0u" + end + + test "encode_timeout/1 returns millisecond" do + assert encode_timeout(1) == "1m" + assert encode_timeout(1500) == "1500m" + assert encode_timeout(@ms_ceiling - 1) == "99999999m" + end + + test "encode_timeout/1 returns second" do + assert encode_timeout(@ms_ceiling) == "100000S" + assert encode_timeout(@second_ceiling - 1) == "99999999S" + end + + test "encode_timeout/1 returns minute" do + assert encode_timeout(@second_ceiling) == "1666666M" + assert encode_timeout(@minute_ceiling - 1) == "99999999M" + end + + test "encode_timeout/1 returns hour" do + assert encode_timeout(@minute_ceiling) == "1666666H" + end + + describe "encode_timeout/1 fidelity" do + test "millisecond values survive a round-trip exactly" do + # Regression guard: with a 1000 ms ceiling, 2500 ms encoded as "2S" and decoded as 2000. + for ms <- [1, 999, 1000, 1500, 2000, 2500, 3847, 5000, 59_999, 60_000, 3_600_000] do + assert decode_timeout(encode_timeout(ms)) == ms, + "#{ms} ms did not survive encode/decode: " <> + "#{inspect(encode_timeout(ms))} -> #{decode_timeout(encode_timeout(ms))} ms" + end + end + + test "values above the millisecond ceiling lose less than one second" do + # Past 8 digits of ms a coarser unit is forced, so bound the loss instead. + ms = @ms_ceiling + 1 + decoded = decode_timeout(encode_timeout(ms)) + + assert decoded <= ms + assert ms - decoded < 1000 + end + + test "the encoded value stays within the 8-digit wire limit" do + # TimeoutValue is "a positive integer as ASCII string of at most 8 digits". + for ms <- [ + 1, + @ms_ceiling - 1, + @ms_ceiling, + @second_ceiling - 1, + @second_ceiling, + @minute_ceiling - 1, + @minute_ceiling + ] do + {digits, _unit} = String.split_at(encode_timeout(ms), -1) + + assert String.length(digits) <= 8, + "#{ms} ms encoded to #{digits} (#{String.length(digits)} digits)" + end + end + end + + test "decode_timeout/1 returns 0" do + assert decode_timeout("0u") == 0 + end + + test "decode_timeout/1 returns 0.123" do + assert decode_timeout("123u") == 0 + end + + test "decode_timeout/1 returns 123 ms" do + assert decode_timeout("123m") == 123 + end + + test "decode_timeout/1 returns seconds" do + assert decode_timeout("123S") == 123_000 + end + + test "decode_timeout/1 returns minutes" do + assert decode_timeout("123M") == 123 * 60_000 + end + + test "decode_timeout/1 returns hour" do + assert decode_timeout("123H") == 123 * 3_600_000 + end +end From e7e51b62c79bbd7d81f8bbf8e9099c5414b2c55b Mon Sep 17 00:00:00 2001 From: Chris Greeno Date: Tue, 18 Aug 2026 22:52:22 +0100 Subject: [PATCH 2/3] 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. --- grpc/test/grpc/adapters/mint_test.exs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/grpc/test/grpc/adapters/mint_test.exs b/grpc/test/grpc/adapters/mint_test.exs index e5e23e633..01892740d 100644 --- a/grpc/test/grpc/adapters/mint_test.exs +++ b/grpc/test/grpc/adapters/mint_test.exs @@ -181,10 +181,11 @@ defmodule GRPC.Client.Adapters.MintTest do refute Process.alive?(stream_response_pid) end - test "accepts the float milliseconds a :deadline is resolved into", %{stream: stream} do + test "accepts the milliseconds a :deadline is resolved into", %{stream: stream} do timeout = GRPC.TimeUtils.to_relative(DateTime.add(DateTime.utc_now(), 20, :millisecond)) - assert is_float(timeout) + # Not a concrete type: to_relative/2 returns a float before grpc_core 1.0.5, integer after. + assert is_number(timeout) assert {:error, %GRPC.RPCError{status: status}} = Mint.receive_data(stream, timeout: timeout) From 9c68b47d57dea6e139021731656c4b7cd7557f34 Mon Sep 17 00:00:00 2001 From: Chris Greeno Date: Wed, 19 Aug 2026 09:31:00 +0100 Subject: [PATCH 3/3] 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. --- grpc/test/grpc/adapters/mint_test.exs | 1 - grpc_core/test/grpc/time_utils_test.exs | 3 +-- grpc_core/test/grpc/transport/http2_timeout_test.exs | 1 - grpc_core/test/grpc/transport/utils_test.exs | 5 +---- 4 files changed, 2 insertions(+), 8 deletions(-) diff --git a/grpc/test/grpc/adapters/mint_test.exs b/grpc/test/grpc/adapters/mint_test.exs index 01892740d..ede5b958b 100644 --- a/grpc/test/grpc/adapters/mint_test.exs +++ b/grpc/test/grpc/adapters/mint_test.exs @@ -184,7 +184,6 @@ defmodule GRPC.Client.Adapters.MintTest do test "accepts the milliseconds a :deadline is resolved into", %{stream: stream} do timeout = GRPC.TimeUtils.to_relative(DateTime.add(DateTime.utc_now(), 20, :millisecond)) - # Not a concrete type: to_relative/2 returns a float before grpc_core 1.0.5, integer after. assert is_number(timeout) assert {:error, %GRPC.RPCError{status: status}} = diff --git a/grpc_core/test/grpc/time_utils_test.exs b/grpc_core/test/grpc/time_utils_test.exs index 7e3544cee..7a0bdf6cb 100644 --- a/grpc_core/test/grpc/time_utils_test.exs +++ b/grpc_core/test/grpc/time_utils_test.exs @@ -4,8 +4,7 @@ defmodule GRPC.TimeUtilsTest do doctest GRPC.TimeUtils describe "to_relative/2" do - test "returns an integer" do - # A float is dropped by append_timeout/2 rather than sent. + test "returns an integer, because append_timeout/2 drops a float rather than sending it" do from = DateTime.utc_now() for offset_us <- [1_000, 5_005, 2_000_000, 999] do diff --git a/grpc_core/test/grpc/transport/http2_timeout_test.exs b/grpc_core/test/grpc/transport/http2_timeout_test.exs index c08233658..79ce6837c 100644 --- a/grpc_core/test/grpc/transport/http2_timeout_test.exs +++ b/grpc_core/test/grpc/transport/http2_timeout_test.exs @@ -3,7 +3,6 @@ defmodule GRPC.Transport.HTTP2TimeoutTest do alias GRPC.Transport.HTTP2 - # A bare map suffices: GRPC.Client.Stream lives in the grpc package, unreachable from here. @stream %{ codec: GRPC.Codec.Proto, compressor: nil, diff --git a/grpc_core/test/grpc/transport/utils_test.exs b/grpc_core/test/grpc/transport/utils_test.exs index 32b735ea5..c140c9221 100644 --- a/grpc_core/test/grpc/transport/utils_test.exs +++ b/grpc_core/test/grpc/transport/utils_test.exs @@ -7,7 +7,7 @@ defmodule GRPC.Transport.UtilsTest do @ns_ceiling 1000 @us_ceiling 1000_000 - # unit: ms, must track GRPC.Transport.Utils. + # unit: ms @ms_ceiling 100_000_000 @second_ceiling @ms_ceiling * 1000 @minute_ceiling @second_ceiling * 60 @@ -54,7 +54,6 @@ defmodule GRPC.Transport.UtilsTest do describe "encode_timeout/1 fidelity" do test "millisecond values survive a round-trip exactly" do - # Regression guard: with a 1000 ms ceiling, 2500 ms encoded as "2S" and decoded as 2000. for ms <- [1, 999, 1000, 1500, 2000, 2500, 3847, 5000, 59_999, 60_000, 3_600_000] do assert decode_timeout(encode_timeout(ms)) == ms, "#{ms} ms did not survive encode/decode: " <> @@ -63,7 +62,6 @@ defmodule GRPC.Transport.UtilsTest do end test "values above the millisecond ceiling lose less than one second" do - # Past 8 digits of ms a coarser unit is forced, so bound the loss instead. ms = @ms_ceiling + 1 decoded = decode_timeout(encode_timeout(ms)) @@ -72,7 +70,6 @@ defmodule GRPC.Transport.UtilsTest do end test "the encoded value stays within the 8-digit wire limit" do - # TimeoutValue is "a positive integer as ASCII string of at most 8 digits". for ms <- [ 1, @ms_ceiling - 1,