squash! squash! fixup! squash! squash! Add Absinthe.Plug integration …

…test.

more realistic tests; still having trouble with unwinding errors

mix.exs

@@ -65,6 +65,7 @@ defmodule Opencensus.Absinthe.MixProject do
       {:licensir, "~> 0.4.0", only: :test},
       {:mix_test_watch, "~> 0.8", only: :test},
       {:opencensus, "~> 0.9.2"},
+      {:opencensus_plug, "~> 0.3", only: :test},
       {:telemetry, "~> 0.4", only: :test}
     ]
   end

mix.lock

@@ -25,6 +25,7 @@
   "mix_test_watch": {:hex, :mix_test_watch, "0.9.0", "c72132a6071261893518fa08e121e911c9358713f62794a90c95db59042af375", [:mix], [{:file_system, "~> 0.2.1 or ~> 0.3", [hex: :file_system, repo: "hexpm", optional: false]}], "hexpm"},
   "nimble_parsec": {:hex, :nimble_parsec, "0.5.0", "90e2eca3d0266e5c53f8fbe0079694740b9c91b6747f2b7e3c5d21966bba8300", [:mix], [], "hexpm"},
   "opencensus": {:hex, :opencensus, "0.9.2", "ab36b0c4e4500b976180bd088cea7520d345711a72df2d7188e2d7b9573a8728", [:rebar3], [{:counters, "~> 0.2.1", [hex: :counters, repo: "hexpm", optional: false]}, {:ctx, "~> 0.5", [hex: :ctx, repo: "hexpm", optional: false]}, {:wts, "~> 0.3", [hex: :wts, repo: "hexpm", optional: false]}], "hexpm"},
+  "opencensus_plug": {:hex, :opencensus_plug, "0.3.0", "ff04bdd59c39dee66fc56086e9300818325afe184a2e8919a8bb47912ad5164c", [:mix], [{:opencensus, "~> 0.9", [hex: :opencensus, repo: "hexpm", optional: false]}, {:plug, "~> 1.6", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm"},
   "parse_trans": {:hex, :parse_trans, "3.3.0", "09765507a3c7590a784615cfd421d101aec25098d50b89d7aa1d66646bc571c1", [:rebar3], [], "hexpm"},
   "plug": {:hex, :plug, "1.8.2", "0bcce1daa420f189a6491f3940cc77ea7fb1919761175c9c3b59800d897440fc", [:mix], [{:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4", [hex: :telemetry, repo: "hexpm", optional: true]}], "hexpm"},
   "plug_crypto": {:hex, :plug_crypto, "1.0.0", "18e49317d3fa343f24620ed22795ec29d4a5e602d52d1513ccea0b07d8ea7d4d", [:mix], [], "hexpm"},

test/opencensus_absinthe_test.exs

@@ -37,6 +37,7 @@ defmodule Opencensus.AbsintheTest do
         arg(:id, non_null(:integer))
 
         resolve(fn %{id: _}, _ ->
+          IO.inspect(:ocp.current_span_ctx(), label: "naughty resolver current_span_ctx")
           raise ArgumentError, message: "NAUGHTY RESOLVER"
         end)
       end
@@ -49,56 +50,59 @@ defmodule Opencensus.AbsintheTest do
     end
   end
 
-  defmodule MyApp.Plug do
-    use Plug.Builder
-
-    plug(Absinthe.Plug,
-      json_codec: Jason,
-      schema: MyApp.Schema,
-      pipeline: {__MODULE__, :traced_pipeline}
-    )
-
-    def call(conn, opts) do
-      span_ctx = :ocp.current_span_ctx() |> IO.inspect(label: "#{__MODULE__}.call/2 span_ctx")
-
-      try do
-        conn
-        |> super(opts)
-        |> assign(:called_all_plugs, true)
-        |> IO.inspect(label: "#{__MODULE__}.call/2 conn AFTER")
-      rescue
-        err ->
-          {err, :ocp.current_span_ctx()} |> IO.inspect(label: "#{__MODULE__}.call/2 err")
-          reraise(err, __STACKTRACE__)
-      after
-        unwind_span_failures(span_ctx)
-        :ocp.with_span_ctx(span_ctx)
-      end
-    end
-
+  defmodule SpanPopper do
     @spec unwind_span_failures(:opencensus.span_ctx() | %SpanContext{}) :: nil
-    defp unwind_span_failures(target_span_ctx) when is_tuple(target_span_ctx) do
+    def unwind_span_failures(target_span_ctx) when is_tuple(target_span_ctx) do
       target_span_ctx
       |> SpanContext.from()
-      |> dead_child_spans(:ocp.current_span_ctx())
+      |> dead_child_spans(:ocp.current_span_ctx(), [])
       |> IO.inspect(label: "dead spans")
       |> Enum.each(&:oc_trace.finish_span(&1))
+
+      :ocp.with_span_ctx(target_span_ctx |> IO.inspect(label: "restoring"))
     end
 
     @spec dead_child_spans(%SpanContext{}, :opencensus.span_ctx(), [:opencensus.span_ctx()]) :: [
             :opencensus.span_ctx()
           ]
-    defp dead_child_spans(target, span_ctx, spans \\ [])
-
-    defp dead_child_spans(%SpanContext{}, :undefined, _), do: []
-
     defp dead_child_spans(%SpanContext{} = target, span_ctx, spans) do
       %{span_id: span_id, trace_id: trace_id} = target
 
       case SpanContext.from(span_ctx) do
-        %{span_id: ^span_id} -> spans
-        %{trace_id: ^trace_id} -> [span_ctx | spans]
-        _ -> []
+        %{span_id: ^span_id} ->
+          spans |> Enum.reverse()
+
+        %{trace_id: ^trace_id} ->
+          dead_child_spans(target, :oc_trace.parent_span_ctx(span_ctx), [span_ctx | spans])
+
+        _ ->
+          []
+      end
+    end
+  end
+
+  defmodule MyApp.TracePlug do
+    use Opencensus.Plug.Trace
+  end
+
+  defmodule MyApp.Plug do
+    use Plug.Builder
+
+    plug(MyApp.TracePlug)
+
+    plug(Absinthe.Plug,
+      json_codec: Jason,
+      schema: MyApp.Schema,
+      pipeline: {__MODULE__, :traced_pipeline}
+    )
+
+    def call(conn, opts) do
+      span_ctx = :ocp.current_span_ctx()
+
+      try do
+        super(conn, opts)
+      after
+        SpanPopper.unwind_span_failures(span_ctx)
       end
     end
 
@@ -125,7 +129,7 @@ defmodule Opencensus.AbsintheTest do
     SpanCaptureReporter.attach()
     on_exit(make_ref(), &SpanCaptureReporter.detach/0)
 
-    :ocp.with_child_span("POST /api")
+    :ocp.with_child_span("test span")
     span_ctx = :ocp.current_span_ctx()
     assert span_ctx != :undefined
 
@@ -137,23 +141,25 @@ defmodule Opencensus.AbsintheTest do
       result =
         conn(:post, "/", ~S'{ item(id: 0) { name } }')
         |> put_req_header("content-type", "application/graphql")
+        |> put_req_header("traceparent", traceparent(span_ctx))
         |> 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
+      [_, request_span, blueprint_span, field_span] = spans
 
-      assert test_span.name == "POST /api"
+      assert request_span.name == "/"
 
       assert_contains!(blueprint_span, %{
         name: "Blueprint",
-        trace_id: test_span.trace_id,
-        parent_span_id: test_span.span_id
+        trace_id: request_span.trace_id,
+        parent_span_id: request_span.span_id
       })
 
       assert blueprint_span.attributes == %{
@@ -189,6 +195,7 @@ defmodule Opencensus.AbsintheTest do
       result =
         conn(:post, "/", ~S'{ simulated_error(id: 0) { name } }')
         |> put_req_header("content-type", "application/graphql")
+        |> put_req_header("traceparent", traceparent(span_ctx))
         |> Plug.Parsers.call(plug_parser_opts())
         |> MyApp.Plug.call(MyApp.Plug.init([]))
 
@@ -209,14 +216,14 @@ defmodule Opencensus.AbsintheTest do
       :ocp.finish_span()
 
       spans = SpanCaptureReporter.collect() |> Enum.sort_by(& &1.start_time)
-      [test_span, blueprint_span, field_span] = spans
+      [_, request_span, blueprint_span, field_span] = spans
 
-      assert test_span.name == "POST /api"
+      assert request_span.name == "/"
 
       assert_contains!(blueprint_span, %{
         name: "Blueprint",
-        trace_id: test_span.trace_id,
-        parent_span_id: test_span.span_id
+        trace_id: request_span.trace_id,
+        parent_span_id: request_span.span_id
       })
 
       assert blueprint_span.attributes == %{
@@ -248,11 +255,17 @@ defmodule Opencensus.AbsintheTest do
       })
     end
 
+    defp traceparent(span_ctx) do
+      [{"traceparent", iolist}] = :oc_propagation_http_tracecontext.to_headers(span_ctx)
+      iolist |> to_string
+    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")
+          |> put_req_header("traceparent", traceparent(span_ctx))
           |> Plug.Parsers.call(plug_parser_opts())
           |> MyApp.Plug.call(MyApp.Plug.init([]))
         rescue
@@ -266,17 +279,55 @@ defmodule Opencensus.AbsintheTest do
       assert :ocp.current_span_ctx() == span_ctx
       :ocp.finish_span()
 
-      spans = SpanCaptureReporter.collect() |> Enum.sort_by(& &1.start_time)
-      [test_span, blueprint_span] = spans
+      # TODO the reason this isn't working the way we want is because we are NOT tracking the
+      # resolver's trace using OCP. We need to find another way:
+      [_, request_span, blueprint_span, field_span] =
+        SpanCaptureReporter.collect()
+        |> Enum.sort_by(& &1.start_time)
+        |> IO.inspect(label: "all spans")
+
+      assert request_span.name == "/"
+
+      assert_contains!(blueprint_span, %{
+        name: "Blueprint",
+        trace_id: request_span.trace_id,
+        parent_span_id: request_span.span_id
+      })
 
-      assert test_span.name == "POST /api"
-      assert blueprint_span.name == "Blueprint"
+      assert blueprint_span.attributes == %{
+               "absinthe.blueprint.error_count" => 1,
+               "absinthe.blueprint.status" => "error"
+             }
+
+      assert_contains!(field_span, %{
+        name: "Opencensus.AbsintheTest.MyApp.Schema:simulated_error",
+        trace_id: blueprint_span.trace_id,
+        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_contains!(field_span.attributes, %{
+        "absinthe.field.module" => "Opencensus.AbsintheTest.MyApp.Schema",
+        "absinthe.field.name" => "simulated_error",
+        "absinthe.field.resolution_error_count" => 1,
+        "absinthe.field.resolution_status" => "error"
+      })
     end
 
     test "bad query", %{span_ctx: span_ctx} do
       result =
         conn(:post, "/", ~S'{ error(id: "foo") { name } }')
         |> put_req_header("content-type", "application/graphql")
+        |> put_req_header("traceparent", traceparent(span_ctx))
         |> Plug.Parsers.call(plug_parser_opts())
         |> MyApp.Plug.call(MyApp.Plug.init([]))
 
@@ -299,18 +350,15 @@ defmodule Opencensus.AbsintheTest do
       assert :ocp.current_span_ctx() == span_ctx
       :ocp.finish_span()
 
-      spans =
-        SpanCaptureReporter.collect()
-        |> Enum.sort_by(& &1.start_time)
-
-      [test_span, blueprint_span] = spans
+      [_, request_span, blueprint_span] =
+        SpanCaptureReporter.collect() |> Enum.sort_by(& &1.start_time)
 
-      assert test_span.name == "POST /api"
+      assert request_span.name == "/"
 
       assert Map.take(blueprint_span, [:name, :trace_id, :parent_span_id]) == %{
                name: "Blueprint",
-               trace_id: test_span.trace_id,
-               parent_span_id: test_span.span_id
+               trace_id: request_span.trace_id,
+               parent_span_id: request_span.span_id
              }
 
       assert blueprint_span.attributes == %{