From d9e204074898b347a12f63932916c1318dc4f7a5 Mon Sep 17 00:00:00 2001 From: Zach Daniel Date: Mon, 27 Aug 2018 12:00:17 -0400 Subject: [PATCH] standardize return types from strategies (and by proxy from Spandex) (#62) * standardize return types from strategies (and by proxy from Spandex) --- README.md | 12 ++-- lib/spandex.ex | 118 +++++++++++++++++++++------------ lib/strategy.ex | 5 +- lib/strategy/pdict.ex | 25 ++++--- lib/tracer.ex | 20 +++--- test/plug/add_context_test.exs | 4 +- test/plug/end_trace_test.exs | 2 +- test/spandex_test.exs | 40 +++++++++-- 8 files changed, 147 insertions(+), 79 deletions(-) diff --git a/README.md b/README.md index 7b3e6f5..3504f71 100644 --- a/README.md +++ b/README.md @@ -103,24 +103,24 @@ defmodule ManuallyTraced do # Does not handle exceptions for you. def trace_me() do - _ = Tracer.start_trace("my_trace") #also opens a span - _ = Tracer.update_span(service: :my_app, type: :db) + Tracer.start_trace("my_trace") #also opens a span + Tracer.update_span(service: :my_app, type: :db) result = span_me() - _ = Tracer.finish_trace() + Tracer.finish_trace() result end # Does not handle exceptions for you. def span_me() do - _ = Tracer.start_span("this_span") - _ = Tracer.update_span(service: :my_app, type: :web) + Tracer.start_span("this_span") + Tracer.update_span(service: :my_app, type: :web) result = span_me_also() - _ = Tracer.finish_span() + Tracer.finish_span() end # Handles exception at the span level. Trace still must be reported. diff --git a/lib/spandex.ex b/lib/spandex.ex index 3d3cfda..36cc77b 100644 --- a/lib/spandex.ex +++ b/lib/spandex.ex @@ -26,7 +26,7 @@ defmodule Spandex do def start_trace(name, opts) do strategy = opts[:strategy] - if strategy.get_trace(opts[:tracer]) do + if strategy.trace_active?(opts[:trace_key]) do Logger.error("Tried to start a trace over top of another trace.") {:error, :trace_running} else @@ -44,12 +44,15 @@ defmodule Spandex do def start_span(name, opts) do strategy = opts[:strategy] - case strategy.get_trace(opts[:tracer]) do - nil -> + case strategy.get_trace(opts[:trace_key]) do + {:error, :no_trace_context} = error -> Logger.error("Tried to start a span without an active trace.") - {:error, :no_trace_context} + error - trace -> + {:error, _} = error -> + error + + {:ok, trace} -> do_start_span(name, trace, opts) end end @@ -66,17 +69,20 @@ defmodule Spandex do def update_span(opts, top?) do strategy = opts[:strategy] - case strategy.get_trace(opts[:tracer]) do - nil -> + case strategy.get_trace(opts[:trace_key]) do + {:error, :no_trace_context} = error -> Logger.error("Tried to update a span without an active trace.") - {:error, :no_trace_context} + error - %Trace{stack: []} -> + {:ok, %Trace{stack: []}} -> Logger.error("Tried to update a span without an active span.") {:error, :no_span_context} - trace -> + {:ok, trace} -> do_update_span(trace, opts, top?) + + {:error, _} = error -> + error end end @@ -99,15 +105,18 @@ defmodule Spandex do def update_all_spans(opts) do strategy = opts[:strategy] - case strategy.get_trace(opts[:tracer]) do - nil -> + case strategy.get_trace(opts[:trace_key]) do + {:error, :no_trace_context} = error -> Logger.error("Tried to update a span without an active trace.") - {:error, :no_trace_context} + error - %Trace{stack: stack, spans: spans} = trace -> + {:ok, %Trace{stack: stack, spans: spans} = trace} -> new_stack = Enum.map(stack, &update_or_keep(&1, opts)) new_spans = Enum.map(spans, &update_or_keep(&1, opts)) - strategy.put_trace(opts[:tracer], %{trace | stack: new_stack, spans: new_spans}) + strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack, spans: new_spans}) + + {:error, _} = error -> + error end end @@ -122,16 +131,19 @@ defmodule Spandex do strategy = opts[:strategy] adapter = opts[:adapter] - case strategy.get_trace(opts[:tracer]) do - nil -> + case strategy.get_trace(opts[:trace_key]) do + {:error, :no_trace_context} = error -> Logger.error("Tried to finish a trace without an active trace.") - {:error, :no_trace_context} + error - %Trace{spans: spans, stack: stack} -> + {:ok, %Trace{spans: spans, stack: stack}} -> unfinished_spans = Enum.map(stack, &ensure_completion_time_set(&1, adapter)) sender = opts[:sender] || adapter.default_sender() sender.send_spans(spans ++ unfinished_spans) - strategy.delete_trace(opts[:tracer]) + strategy.delete_trace(opts[:trace_key]) + + {:error, _} = error -> + error end end @@ -147,19 +159,28 @@ defmodule Spandex do strategy = opts[:strategy] adapter = opts[:adapter] - case strategy.get_trace(opts[:tracer]) do - nil -> + case strategy.get_trace(opts[:trace_key]) do + {:error, :no_trace_context} = error -> Logger.error("Tried to finish a span without an active trace.") - {:error, :no_trace_context} + error - %Trace{stack: []} -> + {:ok, %Trace{stack: []}} -> Logger.error("Tried to finish a span without an active span.") {:error, :no_span_context} - %Trace{stack: [span | tail], spans: spans} = trace -> + {:ok, %Trace{stack: [span | tail], spans: spans} = trace} -> finished_span = ensure_completion_time_set(span, adapter) - strategy.put_trace(opts[:tracer], %{trace | stack: tail, spans: [finished_span | spans]}) + + strategy.put_trace(opts[:trace_key], %{ + trace + | stack: tail, + spans: [finished_span | spans] + }) + {:ok, finished_span} + + {:error, _} = error -> + error end end @@ -182,12 +203,14 @@ defmodule Spandex do def current_trace_id(opts) do strategy = opts[:strategy] - case strategy.get_trace(opts[:tracer]) do - nil -> - nil - - %Trace{id: id} -> + case strategy.get_trace(opts[:trace_key]) do + {:ok, %Trace{id: id}} -> id + + {:error, _} -> + # TODO: Alter the return type of this interface to allow for returning + # errors from fetching the trace. + nil end end @@ -207,10 +230,17 @@ defmodule Spandex do def current_span(opts) do strategy = opts[:strategy] - case strategy.get_trace(opts[:tracer]) do - nil -> nil - %Trace{stack: []} -> nil - %Trace{stack: [span | _]} -> span + case strategy.get_trace(opts[:trace_key]) do + {:ok, %Trace{stack: []}} -> + nil + + {:ok, %Trace{stack: [span | _]}} -> + span + + {:error, _} -> + # TODO: Alter the return type of this interface to allow for returning + # errors from fetching the trace. + nil end end @@ -225,7 +255,7 @@ defmodule Spandex do strategy = opts[:strategy] opts = Keyword.put(opts, :parent_id, span_id) - if strategy.get_trace(opts[:tracer]) do + if strategy.trace_active?(opts[:trace_key]) do Logger.error("Tried to continue a trace over top of another trace.") {:error, :trace_already_present} else @@ -243,7 +273,7 @@ defmodule Spandex do def continue_trace_from_span(name, span, opts) do strategy = opts[:strategy] - if strategy.get_trace(opts[:tracer]) do + if strategy.trace_active?(opts[:trace_key]) do Logger.error("Tried to continue a trace over top of another trace.") {:error, :trace_already_present} else @@ -270,7 +300,7 @@ defmodule Spandex do with {:ok, top_span} <- span(name, opts, trace_id, adapter) do trace = %Trace{id: trace_id, stack: [top_span], spans: []} - strategy.put_trace(opts[:tracer], trace) + strategy.put_trace(opts[:trace_key], trace) end end @@ -280,7 +310,7 @@ defmodule Spandex do with {:ok, span} <- Span.child_of(span, name, adapter.span_id(), adapter.now(), opts) do trace = %Trace{id: adapter.trace_id(), stack: [span], spans: []} - strategy.put_trace(opts[:tracer], trace) + strategy.put_trace(opts[:trace_key], trace) end end @@ -289,7 +319,7 @@ defmodule Spandex do adapter = opts[:adapter] with {:ok, span} <- Span.child_of(current_span, name, adapter.span_id(), adapter.now(), opts), - {:ok, _trace} <- strategy.put_trace(opts[:tracer], %{trace | stack: [span | trace.stack]}) do + {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: [span | trace.stack]}) do Logger.metadata(span_id: span.id) {:ok, span} end @@ -300,7 +330,7 @@ defmodule Spandex do adapter = opts[:adapter] with {:ok, span} <- span(name, opts, trace_id, adapter), - {:ok, _trace} <- strategy.put_trace(opts[:tracer], %{trace | stack: [span]}) do + {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: [span]}) do Logger.metadata(span_id: span.id) {:ok, span} end @@ -314,7 +344,7 @@ defmodule Spandex do with {:ok, span} <- span(name, opts, trace_id, adapter) do Logger.metadata(trace_id: trace_id, span_id: span.id) trace = %Trace{spans: [], stack: [span], id: trace_id} - strategy.put_trace(opts[:tracer], trace) + strategy.put_trace(opts[:trace_key], trace) end end @@ -322,7 +352,7 @@ defmodule Spandex do strategy = opts[:strategy] new_stack = List.update_at(stack, -1, &update_or_keep(&1, opts)) - with {:ok, _trace} <- strategy.put_trace(opts[:tracer], %{trace | stack: new_stack}) do + with {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do {:ok, Enum.at(new_stack, -1)} end end @@ -332,7 +362,7 @@ defmodule Spandex do updated_span = update_or_keep(current_span, opts) new_stack = [updated_span | other_spans] - with {:ok, _trace} <- strategy.put_trace(opts[:tracer], %{trace | stack: new_stack}) do + with {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do {:ok, updated_span} end end diff --git a/lib/strategy.ex b/lib/strategy.ex index aa68957..fe80507 100644 --- a/lib/strategy.ex +++ b/lib/strategy.ex @@ -6,7 +6,8 @@ defmodule Spandex.Strategy do alias Spandex.Trace - @callback get_trace(tracer) :: Trace.t() | nil + @callback delete_trace(tracer) :: {:ok, Trace.t()} | {:error, term} + @callback get_trace(tracer) :: {:ok, Trace.t()} | {:error, term} @callback put_trace(tracer, Trace.t()) :: {:ok, Trace.t()} | {:error, term} - @callback delete_trace(tracer) :: :ok | {:error, term} + @callback trace_active?(tracer) :: boolean end diff --git a/lib/strategy/pdict.ex b/lib/strategy/pdict.ex index 49a7938..cba0248 100644 --- a/lib/strategy/pdict.ex +++ b/lib/strategy/pdict.ex @@ -7,21 +7,30 @@ defmodule Spandex.Strategy.Pdict do @behaviour Spandex.Strategy @impl Spandex.Strategy - def get_trace(tracer) do - Process.get({:spandex_trace, tracer}) + def trace_active?(trace_key) do + Process.get({:spandex_trace, trace_key}) end @impl Spandex.Strategy - def put_trace(tracer, trace) do - Process.put({:spandex_trace, tracer}, trace) + def get_trace(trace_key) do + trace = Process.get({:spandex_trace, trace_key}) - {:ok, trace} + if trace do + {:ok, trace} + else + {:error, :no_trace_context} + end end @impl Spandex.Strategy - def delete_trace(tracer) do - Process.delete({:spandex_trace, tracer}) + def put_trace(trace_key, trace) do + Process.put({:spandex_trace, trace_key}, trace) - :ok + {:ok, trace} + end + + @impl Spandex.Strategy + def delete_trace(trace_key) do + {:ok, Process.delete({:spandex_trace, trace_key})} end end diff --git a/lib/tracer.ex b/lib/tracer.ex index f916ed4..2456703 100644 --- a/lib/tracer.ex +++ b/lib/tracer.ex @@ -44,7 +44,7 @@ defmodule Spandex.Tracer do services: {:keyword, :atom}, strategy: :atom, sender: :atom, - tracer: :atom + trace_key: :atom ], required: [:adapter, :service], defaults: [ @@ -55,7 +55,7 @@ defmodule Spandex.Tracer do ], describe: [ adapter: "The third party adapter to use", - tracer: "Don't set manually. This option is passed automatically.", + trace_key: "Don't set manually. This option is passed automatically.", sender: "Once a trace is complete, it is sent using this module. Defaults to the `default_sender/0` of the selected adapter", service: "The default service name to use for spans declared without a service", @@ -115,16 +115,16 @@ defmodule Spandex.Tracer do opts = unquote(opts) name = unquote(name) - _ = unquote(__MODULE__).start_trace(name, opts) + unquote(__MODULE__).start_trace(name, opts) span_id = unquote(__MODULE__).current_span_id() - _ = Logger.metadata(span_id: span_id) + Logger.metadata(span_id: span_id) try do unquote(body) rescue exception -> stacktrace = System.stacktrace() - _ = unquote(__MODULE__).span_error(exception, stacktrace, opts) + unquote(__MODULE__).span_error(exception, stacktrace, opts) reraise exception, stacktrace after unquote(__MODULE__).finish_trace() @@ -137,16 +137,16 @@ defmodule Spandex.Tracer do quote do opts = unquote(opts) name = unquote(name) - _ = unquote(__MODULE__).start_span(name, opts) + unquote(__MODULE__).start_span(name, opts) span_id = unquote(__MODULE__).current_span_id() - _ = Logger.metadata(span_id: span_id) + Logger.metadata(span_id: span_id) try do unquote(body) rescue exception -> stacktrace = System.stacktrace() - _ = unquote(__MODULE__).span_error(exception, stacktrace, opts) + unquote(__MODULE__).span_error(exception, stacktrace, opts) reraise exception, stacktrace after unquote(__MODULE__).finish_span() @@ -229,7 +229,7 @@ defmodule Spandex.Tracer do |> Kernel.||([]) |> Keyword.merge(opts || []) |> Optimal.validate!(@opts) - |> Keyword.put(:tracer, __MODULE__) + |> Keyword.put(:trace_key, __MODULE__) end defp config(opts, otp_app) do @@ -255,7 +255,7 @@ defmodule Spandex.Tracer do opts |> Optimal.validate!(schema) - |> Keyword.put(:tracer, __MODULE__) + |> Keyword.put(:trace_key, __MODULE__) |> Keyword.put(:strategy, env[:strategy] || Spandex.Strategy.Pdict) end end diff --git a/test/plug/add_context_test.exs b/test/plug/add_context_test.exs index b0f92a0..b92d921 100644 --- a/test/plug/add_context_test.exs +++ b/test/plug/add_context_test.exs @@ -28,7 +28,7 @@ defmodule Spandex.Plug.AddContextTest do tracer_opts: [] ) - :ok = Tracer.finish_trace() + {:ok, _} = Tracer.finish_trace() %{resource: resource, http: http} = Spandex.Test.Util.find_span("request") @@ -53,7 +53,7 @@ defmodule Spandex.Plug.AddContextTest do assert Keyword.fetch!(Logger.metadata(), :trace_id) == tid assert Keyword.fetch!(Logger.metadata(), :span_id) == expected_span.id - :ok = Tracer.finish_trace() + {:ok, _} = Tracer.finish_trace() %{trace_id: trace_id, type: type, http: http, resource: resource} = Spandex.Test.Util.find_span("request") diff --git a/test/plug/end_trace_test.exs b/test/plug/end_trace_test.exs index 366c5f2..99d397e 100644 --- a/test/plug/end_trace_test.exs +++ b/test/plug/end_trace_test.exs @@ -24,7 +24,7 @@ defmodule Spandex.Plug.EndTraceTest do assert Tracer.current_trace_id() == tid - :ok = Tracer.finish_trace() + {:ok, _} = Tracer.finish_trace() end test "updates top span and finish span, when we trace request for 200", %{ diff --git a/test/spandex_test.exs b/test/spandex_test.exs index 85a77f8..aa3ebc8 100644 --- a/test/spandex_test.exs +++ b/test/spandex_test.exs @@ -92,7 +92,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.start_span("span_name", @base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -148,7 +150,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.update_span(@base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -222,7 +226,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.update_top_span(@base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -239,6 +245,7 @@ defmodule Spandex.Test.SpandexTest do assert %Span{id: ^span_id, service: :updated_service} = Spandex.current_span(@base_opts) Spandex.finish_span(@base_opts) + assert %Span{id: ^root_span_id, service: :updated_service} = Spandex.current_span(@base_opts) end @@ -262,7 +269,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.update_all_spans(@base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -274,7 +283,7 @@ defmodule Spandex.Test.SpandexTest do assert %Span{id: root_span_id} = Spandex.current_span(@base_opts) assert {:ok, %Span{id: span_id}} = Spandex.start_span("span_name", opts) - assert :ok = Spandex.finish_trace(@base_opts) + assert {:ok, _} = Spandex.finish_trace(@base_opts) spans = Util.sent_spans() assert length(spans) == 2 assert Enum.any?(spans, fn span -> span.id == root_span_id end) @@ -290,7 +299,7 @@ defmodule Spandex.Test.SpandexTest do assert %Span{id: root_span_id} = Spandex.current_span(@base_opts) assert {:ok, %Span{id: span_id}} = Spandex.start_span("span_name", opts) - assert :ok == Spandex.finish_trace(@base_opts ++ [sender: PdictSender]) + assert {:ok, _} = Spandex.finish_trace(@base_opts ++ [sender: PdictSender]) spans = Process.get(:spans) assert length(spans) == 2 assert Enum.any?(spans, fn span -> span.id == root_span_id end) @@ -306,7 +315,7 @@ defmodule Spandex.Test.SpandexTest do assert %Span{id: root_span_id} = Spandex.current_span(@base_opts) assert {:ok, %Span{id: span_id}} = Spandex.start_span("span_name", opts) - assert :ok = Spandex.finish_trace(@base_opts) + assert {:ok, _} = Spandex.finish_trace(@base_opts) spans = Util.sent_spans() assert length(spans) == 2 assert Enum.all?(spans, fn span -> span.completion_time != nil end) @@ -316,13 +325,17 @@ defmodule Spandex.Test.SpandexTest do now = :os.system_time(:nano_seconds) opts = @base_opts ++ @span_opts assert {:ok, %Trace{}} = Spandex.start_trace("root_span", opts) + assert {:ok, %Span{id: span_id}} = Spandex.start_span("span_name", opts ++ [start: now - 10]) + assert {:ok, %Span{id: ^span_id}} = Spandex.update_span(@base_opts ++ [completion_time: now - 9]) + assert {:ok, %Span{id: ^span_id}} = Spandex.finish_span(@base_opts) - assert :ok = Spandex.finish_trace(@base_opts) + assert {:ok, _} = Spandex.finish_trace(@base_opts) spans = Util.sent_spans() assert length(spans) == 2 + assert Enum.any?(spans, fn span -> span.id == span_id && span.completion_time == now - 9 end) end @@ -344,7 +357,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.finish_trace(@base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -411,7 +426,9 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if invalid options are specified" do opts = @base_opts ++ @span_opts assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) + assert {:error, validation_errors} = Spandex.finish_span(@base_opts ++ [type: "not an atom"]) + assert {:type, "must be of type :atom"} in validation_errors end end @@ -461,7 +478,11 @@ defmodule Spandex.Test.SpandexTest do assert {:ok, %Trace{id: trace_id}} = Spandex.start_trace("root_span", opts) assert {:error, validation_errors} = - Spandex.span_error(@runtime_error, @fake_stacktrace, @base_opts ++ [type: "not an atom"]) + Spandex.span_error( + @runtime_error, + @fake_stacktrace, + @base_opts ++ [type: "not an atom"] + ) assert {:type, "must be of type :atom"} in validation_errors end @@ -565,7 +586,9 @@ defmodule Spandex.Test.SpandexTest do describe "Spandex.continue_trace_from_span/3" do test "returns a new trace based on a specified name and existing span" do existing_span = %Span{id: 456, trace_id: 123, name: "existing"} + assert {:ok, %Trace{id: trace_id}} = Spandex.continue_trace_from_span("root_span", existing_span, @base_opts) + assert trace_id != 123 assert %Span{parent_id: 456, name: "root_span"} = Spandex.current_span(@base_opts) end @@ -586,6 +609,7 @@ defmodule Spandex.Test.SpandexTest do test "returns an error if tracing is disabled" do existing_span = %Span{id: 456, trace_id: 123, name: "existing"} + assert {:error, :disabled} == Spandex.continue_trace_from_span("root_span", existing_span, :disabled) end @@ -593,7 +617,11 @@ defmodule Spandex.Test.SpandexTest do existing_span = %Span{id: 456, trace_id: 123, name: "existing"} assert {:error, validation_errors} = - Spandex.continue_trace_from_span("span_name", existing_span, @base_opts ++ [type: "not an atom"]) + Spandex.continue_trace_from_span( + "span_name", + existing_span, + @base_opts ++ [type: "not an atom"] + ) assert {:type, "must be of type :atom"} in validation_errors end