From 9457b1c2a093e45d9ce65bec8ce0700f08511a73 Mon Sep 17 00:00:00 2001 From: Garth Kidd Date: Sat, 22 Jun 2019 22:33:06 +1000 Subject: [PATCH] Add Absinthe.Plug integration test. --- config/config.exs | 6 + lib/opencensus/absinthe/middleware.ex | 13 ++ lib/opencensus/absinthe/phase/pop.ex | 23 +- mix.exs | 4 +- mix.lock | 1 + test/opencensus_absinthe_test.exs | 322 ++++++++++++++++++++++++++ 6 files changed, 367 insertions(+), 2 deletions(-) create mode 100644 test/opencensus_absinthe_test.exs diff --git a/config/config.exs b/config/config.exs index d2d855e..b815360 100644 --- a/config/config.exs +++ b/config/config.exs @@ -1 +1,7 @@ use Mix.Config + +config :opencensus, :send_interval_ms, 5 + +config :logger, + backends: [:console], + level: :warn diff --git a/lib/opencensus/absinthe/middleware.ex b/lib/opencensus/absinthe/middleware.ex index 496e833..2cafc8c 100644 --- a/lib/opencensus/absinthe/middleware.ex +++ b/lib/opencensus/absinthe/middleware.ex @@ -24,7 +24,20 @@ defmodule Opencensus.Absinthe.Middleware do end @doc false + @spec on_complete(Resolution.t(), span_ctx: :opencensus.span_ctx()) :: Resolution.t() def on_complete(%{state: :resolved} = resolution, span_ctx: span_ctx) do + # credo:disable-for-next-line + error_count = length(resolution.errors) + status = if error_count == 0, do: "ok", else: "error" + + :oc_trace.put_attributes( + %{ + "absinthe.field.resolution_error_count" => error_count, + "absinthe.field.resolution_status" => status + }, + span_ctx + ) + :oc_trace.finish_span(span_ctx) resolution end diff --git a/lib/opencensus/absinthe/phase/pop.ex b/lib/opencensus/absinthe/phase/pop.ex index ba70269..bc26422 100644 --- a/lib/opencensus/absinthe/phase/pop.ex +++ b/lib/opencensus/absinthe/phase/pop.ex @@ -5,11 +5,32 @@ defmodule Opencensus.Absinthe.Phase.Pop do alias Absinthe.Blueprint alias Absinthe.Phase + alias Opencensus.Absinthe.Acc @impl true @spec run(Blueprint.t(), keyword()) :: Phase.result_t() def run(blueprint, _opts \\ []) do - :ocp.finish_span() + acc = Acc.get(blueprint) + + {status, error_count} = + case blueprint do + %{result: %{errors: errors}} -> {:error, length(errors)} + _ -> {:ok, 0} + end + + :oc_trace.put_attributes( + %{ + "absinthe.blueprint.error_count" => error_count, + "absinthe.blueprint.status" => Atom.to_string(status) + }, + acc.span_ctx + ) + + # Finish our span, even if it isn't current: + :oc_trace.finish_span(acc.span_ctx) + # Restore our parent span: + :ocp.with_span_ctx(acc.parent_span_ctx) + {:ok, blueprint} end end diff --git a/mix.exs b/mix.exs index a30fa00..b063c71 100644 --- a/mix.exs +++ b/mix.exs @@ -57,9 +57,11 @@ defmodule Opencensus.Absinthe.MixProject do {:ex_doc, ">= 0.0.0", only: :docs}, {:excoveralls, "~> 0.11.1", only: :test}, {:inch_ex, "~> 2.0.0", only: :docs}, + {:jason, "~> 1.0", only: :test}, {:licensir, "~> 0.4.0", only: :test}, {:mix_test_watch, "~> 0.8", only: :test}, - {:opencensus, "~> 0.9.2"} + {:opencensus, "~> 0.9.2"}, + {:telemetry, "~> 0.4", only: :test} ] end diff --git a/mix.lock b/mix.lock index 8b99133..8061915 100644 --- a/mix.lock +++ b/mix.lock @@ -30,6 +30,7 @@ "plug_crypto": {:hex, :plug_crypto, "1.0.0", "18e49317d3fa343f24620ed22795ec29d4a5e602d52d1513ccea0b07d8ea7d4d", [:mix], [], "hexpm"}, "rfc3339": {:hex, :rfc3339, "0.9.0", "2075653dc9407541c84b1e15f8bda2abe95fb17c9694025e079583f2d19c1060", [:mix, :rebar], [], "hexpm"}, "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.4", "f0eafff810d2041e93f915ef59899c923f4568f4585904d010387ed74988e77b", [:make, :mix, :rebar3], [], "hexpm"}, + "telemetry": {:hex, :telemetry, "0.4.0", "8339bee3fa8b91cb84d14c2935f8ecf399ccd87301ad6da6b71c09553834b2ab", [:rebar3], [], "hexpm"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.4.1", "d869e4c68901dd9531385bb0c8c40444ebf624e60b6962d95952775cac5e90cd", [:rebar3], [], "hexpm"}, "wts": {:hex, :wts, "0.3.0", "5cdf22c775cb1ebae24c326a5db6074d753c42f4bd12a9aa47cc62d3e2c71ad1", [:rebar3], [{:rfc3339, "~>0.9.0", [hex: :rfc3339, repo: "hexpm", optional: false]}], "hexpm"}, } diff --git a/test/opencensus_absinthe_test.exs b/test/opencensus_absinthe_test.exs new file mode 100644 index 0000000..6781cea --- /dev/null +++ b/test/opencensus_absinthe_test.exs @@ -0,0 +1,322 @@ +defmodule Opencensus.AbsintheTest do + use ExUnit.Case, async: false + use Plug.Test + + defmodule MyApp.Schema do + use Absinthe.Schema + + @impl Absinthe.Schema + def middleware(middleware, field, object) do + Opencensus.Absinthe.middleware(middleware, field, object) + end + + query do + field :item, :item, meta: [trace: true] do + arg(:id, non_null(:integer)) + + resolve(fn %{id: item_id}, _ -> + case item_id do + 0 -> {:ok, %{id: 0, name: "Foo"}} + _ -> {:error, %ArgumentError{message: "404 NOT FOUND"}} + end + end) + end + + field :simulated_error, :item, meta: [trace: true] do + arg(:id, non_null(:integer)) + + resolve(fn %{id: _}, _ -> + {:error, "Something went horribly wrong."} + end) + end + + field :simulated_crash, :item, meta: [trace: true] do + arg(:id, non_null(:integer)) + + resolve(fn %{id: _}, _ -> + raise ArgumentError, message: "NAUGHTY RESOLVER" + end) + end + end + + @desc "An item" + object :item do + field(:id, :integer) + field(:name, :string) + end + end + + defmodule MyApp.Plug do + use Plug.Builder + + plug(Absinthe.Plug, + json_codec: Jason, + schema: MyApp.Schema, + pipeline: {__MODULE__, :traced_pipeline} + ) + + def traced_pipeline(config, pipeline_opts \\ []) do + config + |> Absinthe.Plug.default_pipeline(pipeline_opts) + |> Opencensus.Absinthe.add_phases() + end + end + + defmodule SpanCaptureReporter do + @moduledoc """ + `:oc_reporter` can't unregister reporters, but `:telemetry` can detach handlers, so... + """ + + @behaviour :oc_reporter + + @impl true + def init([]), do: [] + + @impl true + def report(spans, []) do + :telemetry.execute([__MODULE__], %{}, %{spans: spans}) + :ok + end + + def attach(), do: :telemetry.attach(__MODULE__, [__MODULE__], &handler/4, self()) + def detach(), do: :telemetry.detach(__MODULE__) + def handler([__MODULE__], %{}, %{spans: spans}, pid), do: send(pid, {:spans, spans}) + + defmodule Span do + require Record + @fields Record.extract(:span, from_lib: "opencensus/include/opencensus.hrl") + Record.defrecordp(:span, @fields) + defstruct Keyword.keys(@fields) + + def from(record) when Record.is_record(record, :span), do: struct!(__MODULE__, span(record)) + end + + def collect(acc \\ []) do + receive do + {:spans, spans} -> collect(acc ++ spans) + after + 50 -> + acc |> Enum.map(&Span.from/1) + end + end + end + + setup_all do + :ok = Application.ensure_started(:mime) + :ok = Application.ensure_started(:plug_crypto) + :ok = Application.ensure_started(:plug) + :ok = Application.ensure_started(:telemetry) + :oc_reporter.register(SpanCaptureReporter) + :ok + end + + setup do + old_ctx = :ocp.current_span_ctx() + on_exit(make_ref(), fn -> :ocp.with_span_ctx(old_ctx) end) + :ocp.with_span_ctx(:undefined) + + SpanCaptureReporter.attach() + on_exit(make_ref(), &SpanCaptureReporter.detach/0) + + :ocp.with_child_span("POST /api") + span_ctx = :ocp.current_span_ctx() + assert span_ctx != :undefined + + %{span_ctx: span_ctx} + end + + describe "integration tests:" do + test "happy path", %{span_ctx: span_ctx} do + result = + conn(:post, "/", ~S'{ item(id: 0) { name } }') + |> put_req_header("content-type", "application/graphql") + |> Plug.Parsers.call(plug_parser_opts()) + |> MyApp.Plug.call(MyApp.Plug.init([])) + + assert result.status == 200 + assert result.resp_body == ~S'{"data":{"item":{"name":"Foo"}}}' + assert :ocp.current_span_ctx() == span_ctx + :ocp.finish_span() + + spans = SpanCaptureReporter.collect() |> Enum.sort_by(& &1.start_time) + [test_span, blueprint_span, field_span] = spans + + assert test_span.name == "POST /api" + + assert blueprint_span.name == "Blueprint" + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.parent_span_id == test_span.span_id + + assert Map.keys(blueprint_span.attributes) == [ + "absinthe.blueprint.error_count", + "absinthe.blueprint.status" + ] + + assert blueprint_span.attributes["absinthe.blueprint.error_count"] == 0 + assert blueprint_span.attributes["absinthe.blueprint.status"] == "ok" + + assert field_span.name == "Opencensus.AbsintheTest.MyApp.Schema:item" + assert field_span.trace_id == blueprint_span.trace_id + assert field_span.parent_span_id == blueprint_span.span_id + + assert Map.keys(field_span.attributes) == [ + "absinthe.field.file", + "absinthe.field.line", + "absinthe.field.module", + "absinthe.field.name", + "absinthe.field.resolution_error_count", + "absinthe.field.resolution_status", + "absinthe.field.type" + ] + + assert field_span.attributes["absinthe.field.module"] == + "Opencensus.AbsintheTest.MyApp.Schema" + + assert field_span.attributes["absinthe.field.name"] == "item" + assert field_span.attributes["absinthe.field.resolution_error_count"] == 0 + assert field_span.attributes["absinthe.field.resolution_status"] == "ok" + end + + test "field resolver error", %{span_ctx: span_ctx} do + result = + conn(:post, "/", ~S'{ simulated_error(id: 0) { name } }') + |> put_req_header("content-type", "application/graphql") + |> Plug.Parsers.call(plug_parser_opts()) + |> MyApp.Plug.call(MyApp.Plug.init([])) + + assert result.status == 200 + + assert result.resp_body |> Jason.decode!() == %{ + "data" => %{"simulated_error" => nil}, + "errors" => [ + %{ + "locations" => [%{"column" => 0, "line" => 1}], + "message" => "Something went horribly wrong.", + "path" => ["simulated_error"] + } + ] + } + + assert :ocp.current_span_ctx() == span_ctx + :ocp.finish_span() + + spans = SpanCaptureReporter.collect() |> Enum.sort_by(& &1.start_time) + [test_span, blueprint_span, field_span] = spans + + assert test_span.name == "POST /api" + + assert blueprint_span.name == "Blueprint" + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.parent_span_id == test_span.span_id + + assert Map.keys(blueprint_span.attributes) == [ + "absinthe.blueprint.error_count", + "absinthe.blueprint.status" + ] + + assert blueprint_span.attributes["absinthe.blueprint.error_count"] == 1 + assert blueprint_span.attributes["absinthe.blueprint.status"] == "error" + + assert field_span.name == "Opencensus.AbsintheTest.MyApp.Schema:simulated_error" + assert field_span.trace_id == blueprint_span.trace_id + assert field_span.parent_span_id == blueprint_span.span_id + + assert Map.keys(field_span.attributes) == [ + "absinthe.field.file", + "absinthe.field.line", + "absinthe.field.module", + "absinthe.field.name", + "absinthe.field.resolution_error_count", + "absinthe.field.resolution_status", + "absinthe.field.type" + ] + + assert field_span.attributes["absinthe.field.module"] == + "Opencensus.AbsintheTest.MyApp.Schema" + + assert field_span.attributes["absinthe.field.name"] == "simulated_error" + assert field_span.attributes["absinthe.field.resolution_error_count"] == 1 + assert field_span.attributes["absinthe.field.resolution_status"] == "error" + end + + test "field resolver crash", %{span_ctx: span_ctx} do + result = + try do + conn(:post, "/", ~S'{ simulated_crash(id: 0) { name } }') + |> put_req_header("content-type", "application/graphql") + |> Plug.Parsers.call(plug_parser_opts()) + |> MyApp.Plug.call(MyApp.Plug.init([])) + rescue + err -> err + end + + assert result == %ArgumentError{message: "NAUGHTY RESOLVER"} + + # We're still stuck in the blueprint span, so: + assert :ocp.current_span_ctx() != span_ctx + :ocp.finish_span() + assert :ocp.current_span_ctx() == span_ctx + :ocp.finish_span() + + SpanCaptureReporter.collect() + # ... and there's no point studying the blueprint span, as in real life it'll just time out. + end + + test "bad query", %{span_ctx: span_ctx} do + result = + conn(:post, "/", ~S'{ error(id: "foo") { name } }') + |> put_req_header("content-type", "application/graphql") + |> Plug.Parsers.call(plug_parser_opts()) + |> MyApp.Plug.call(MyApp.Plug.init([])) + + assert result.status == 200 + + assert result.resp_body |> Jason.decode!() == %{ + "errors" => [ + %{ + "locations" => [%{"column" => 0, "line" => 1}], + "message" => "Cannot query field \"error\" on type \"RootQueryType\"." + }, + %{ + "locations" => [%{"column" => 0, "line" => 1}], + "message" => + "Unknown argument \"id\" on field \"error\" of type \"RootQueryType\"." + } + ] + } + + assert :ocp.current_span_ctx() == span_ctx + :ocp.finish_span() + + spans = + SpanCaptureReporter.collect() + |> Enum.sort_by(& &1.start_time) + + [test_span, blueprint_span] = spans + + assert test_span.name == "POST /api" + + assert blueprint_span.name == "Blueprint" + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.trace_id == test_span.trace_id + assert blueprint_span.parent_span_id == test_span.span_id + + assert Map.keys(blueprint_span.attributes) == [ + "absinthe.blueprint.error_count", + "absinthe.blueprint.status" + ] + + assert blueprint_span.attributes["absinthe.blueprint.error_count"] == 2 + assert blueprint_span.attributes["absinthe.blueprint.status"] == "error" + end + end + + def plug_parser_opts, + do: + Plug.Parsers.init( + parsers: [:urlencoded, :multipart, :json, Absinthe.Plug.Parser], + json_decoder: Jason + ) +end