Skip to content

Commit

Permalink
Raise informative error on batched resolver timeout
Browse files Browse the repository at this point in the history
When the Task that runs a batched resolver times out we currently
raise a generic error like this:

** (exit) exited in: Task.await(%Task{owner: #PID<0.15353.21>, pid: #PID<0.15380.21>, ref: #Reference<0.2441152191.2237136897.192020>}, 5000)

This provides no context to the engineer debugging the error about the resolver
that timed out, making debugging much harder.

This change raises a RuntimeError which includes the resolver that timed out
along with the arguments it received:

Batch resolver timed out after 1 ms.
Batch fun: {Absinthe.Middleware.BatchTest.Schema, :slow_field_by_user_id}
Batch data: [3, 2, 1]
Batch opts: [timeout: 1]

This should make the debugging experience a lot better.
  • Loading branch information
jordi-chacon committed Sep 3, 2023
1 parent 2ba17d8 commit 9a69133
Show file tree
Hide file tree
Showing 2 changed files with 50 additions and 1 deletion.
14 changes: 13 additions & 1 deletion lib/absinthe/middleware/batch.ex
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,19 @@ defmodule Absinthe.Middleware.Batch do
end)
|> Map.new(fn {batch_opts, task, start_time_mono, metadata} ->
timeout = Keyword.get(batch_opts, :timeout, 5_000)
result = Task.await(task, timeout)

result =
try do
Task.await(task, timeout)
catch
:exit, {:timeout, {Task, :await, _}} ->
raise """
Batch resolver timed out after #{timeout} ms.
Batch fun: #{inspect(metadata.batch_fun)}
Batch data: #{inspect(metadata.batch_data)}
Batch opts: #{inspect(metadata.batch_opts)}
"""
end

end_time_mono = System.monotonic_time()
duration = end_time_mono - start_time_mono
Expand Down
37 changes: 37 additions & 0 deletions test/absinthe/middleware/batch_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,17 @@ defmodule Absinthe.Middleware.BatchTest do
end)
end
end

field :slow_field, :integer do
resolve fn user, _, _ ->
batch(
{__MODULE__, :slow_field_by_user_id},
user.id,
fn batch -> {:ok, Map.get(batch, user.id)} end,
timeout: 1
)
end
end
end

query do
Expand Down Expand Up @@ -69,6 +80,11 @@ defmodule Absinthe.Middleware.BatchTest do
def otel_ctx(_, _) do
OpenTelemetry.Ctx.get_value("stored_value", nil)
end

def slow_field_by_user_id(_, ids) do
:timer.sleep(5000)
ids |> Enum.with_index() |> Map.new()
end
end

test "can resolve a field using the normal async helper" do
Expand Down Expand Up @@ -150,4 +166,25 @@ defmodule Absinthe.Middleware.BatchTest do

assert {:ok, %{data: %{"ctx" => "some_value"}}} == Absinthe.run(doc, Schema)
end

test "raises when batched resolver times out" do
doc = """
{
users {
slowField
}
}
"""

assert_raise(
RuntimeError,
"""
Batch resolver timed out after 1 ms.
Batch fun: {Absinthe.Middleware.BatchTest.Schema, :slow_field_by_user_id}
Batch data: [3, 2, 1]
Batch opts: [timeout: 1]
""",
fn -> Absinthe.run(doc, Schema) end
)
end
end

0 comments on commit 9a69133

Please sign in to comment.