From e5e8f6b6695a82e0d760a26e5ba8d7708f9ed046 Mon Sep 17 00:00:00 2001 From: Zach Daniel Date: Mon, 26 Nov 2018 20:49:44 -0500 Subject: [PATCH] fix: don't silence errors on span update calls (#90) --- lib/spandex.ex | 164 +++++++++++++++++++++++++++++++++++------- test/spandex_test.exs | 25 ++----- 2 files changed, 142 insertions(+), 47 deletions(-) diff --git a/lib/spandex.ex b/lib/spandex.ex index ee586d7..d34f7f9 100644 --- a/lib/spandex.ex +++ b/lib/spandex.ex @@ -19,6 +19,13 @@ defmodule Spandex do @typedoc "Unix timestamp in nanoseconds" @type timestamp :: non_neg_integer() + @doc """ + Starts a new trace. + + Span updates for the first span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a second call to `update_span/2` and check the return value. + """ @spec start_trace(binary(), Tracer.opts()) :: {:ok, Trace.t()} | {:error, :disabled} @@ -37,11 +44,17 @@ defmodule Spandex do end end + @doc """ + Start a new span. + + Span updates for that span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a second call to `update_span/2` and check the return value. + """ @spec start_span(String.t(), Tracer.opts()) :: {:ok, Span.t()} | {:error, :disabled} | {:error, :no_trace_context} - | {:error, [Optimal.error()]} def start_span(_, :disabled), do: {:error, :disabled} def start_span(name, opts) do @@ -59,6 +72,11 @@ defmodule Spandex do end end + @doc """ + Updates the current span. + + In the case of an invalid update, validation errors are returned. + """ @spec update_span(Tracer.opts(), boolean()) :: {:ok, Span.t()} | {:error, :disabled} @@ -86,6 +104,15 @@ defmodule Spandex do end end + @doc """ + Updates the top-most parent span. + + Any spans that have already been started will not inherit any of the updates + from that span. For instance, if you change `service`, it will not be + reflected in already-started spans. + + In the case of an invalid update, validation errors are returned. + """ @spec update_top_span(Tracer.opts()) :: {:ok, Span.t()} | {:error, :disabled} @@ -95,6 +122,11 @@ defmodule Spandex do def update_top_span(opts), do: update_span(opts, true) + @doc """ + Updates all spans, whether complete or in-progress. + + In the case of an invalid update for any span, validation errors are returned. + """ @spec update_all_spans(Tracer.opts()) :: {:ok, Trace.t()} | {:error, :disabled} @@ -105,25 +137,25 @@ defmodule Spandex do def update_all_spans(opts) do strategy = opts[:strategy] - case strategy.get_trace(opts[:trace_key]) do - {:error, :no_trace_context} = error -> - error - - {: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[:trace_key], %{trace | stack: new_stack, spans: new_spans}) - - {:error, _} = error -> - error + with {:ok, %Trace{stack: stack, spans: spans} = trace} <- strategy.get_trace(opts[:trace_key]), + {:ok, new_spans} <- update_many_spans(spans, opts), + {:ok, new_stack} <- update_many_spans(stack, opts) do + strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack, spans: new_spans}) end end + @doc """ + Finishes the current trace. + + Span updates for the top span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a call to `update_span/2` and check the return value before + finishing the trace. + """ @spec finish_trace(Tracer.opts()) :: {:ok, Trace.t()} | {:error, :disabled} | {:error, :no_trace_context} - | {:error, [Optimal.error()]} def finish_trace(:disabled), do: {:error, :disabled} def finish_trace(opts) do @@ -151,12 +183,19 @@ defmodule Spandex do end end + @doc """ + Finishes the current span. + + Span updates for that span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a call to `update_span/2` and check the return value before + finishing the span. + """ @spec finish_span(Tracer.opts()) :: {:ok, Span.t()} | {:error, :disabled} | {:error, :no_trace_context} | {:error, :no_span_context} - | {:error, [Optimal.error()]} def finish_span(:disabled), do: {:error, :disabled} def finish_span(opts) do @@ -190,6 +229,11 @@ defmodule Spandex do end end + @doc """ + Updates the current span with error details. + + In the case of an invalid value, validation errors are returned. + """ @spec span_error(Exception.t(), Enum.t(), Tracer.opts()) :: {:ok, Span.t()} | {:error, :disabled} @@ -203,6 +247,9 @@ defmodule Spandex do update_span(Keyword.put_new(opts, :error, updates)) end + @doc """ + Returns the id of the currently-running trace. + """ @spec current_trace_id(Tracer.opts()) :: Spandex.id() | nil def current_trace_id(:disabled), do: nil @@ -220,6 +267,9 @@ defmodule Spandex do end end + @doc """ + Returns the id of the currently-running span. + """ @spec current_span_id(Tracer.opts()) :: Spandex.id() | nil def current_span_id(:disabled), do: nil @@ -230,6 +280,9 @@ defmodule Spandex do end end + @doc """ + Returns the `%Span{}` struct for the currently-running span + """ @spec current_span(Tracer.opts()) :: Span.t() | nil def current_span(:disabled), do: nil @@ -250,12 +303,20 @@ defmodule Spandex do end end + @doc """ + Returns the current `%SpanContext{}` or an error. + + ### DEPRECATION WARNING + + Expect changes to this in the future, as this will eventualy be refactored to + only ever return a `%SpanContext{}`, or at least to always return something + consistent. + """ @spec current_context(Tracer.opts()) :: {:ok, SpanContext.t()} | {:error, :disabled} | {:error, :no_span_context} | {:error, :no_trace_context} - | {:error, [Optimal.error()]} def current_context(:disabled), do: {:error, :disabled} def current_context(opts) do @@ -273,11 +334,17 @@ defmodule Spandex do end end + @doc """ + Given a `%SpanContext{}`, resumes a trace from a different process or service. + + Span updates for the top span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a second call to `update_span/2` and check the return value. + """ @spec continue_trace(String.t(), SpanContext.t(), Keyword.t()) :: {:ok, Trace.t()} | {:error, :disabled} | {:error, :trace_already_present} - | {:error, [Optimal.error()]} def continue_trace(_, _, :disabled), do: {:error, :disabled} def continue_trace(name, %SpanContext{} = span_context, opts) do @@ -291,11 +358,17 @@ defmodule Spandex do end end + @doc """ + Given a trace_id and span_id, resumes a trace from a different process or service. + + Span updates for the top span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a second call to `update_span/2` and check the return value. + """ @spec continue_trace(String.t(), Spandex.id(), Spandex.id(), Keyword.t()) :: {:ok, Trace.t()} | {:error, :disabled} | {:error, :trace_already_present} - | {:error, [Optimal.error()]} @deprecated "Use continue_trace/3 instead" def continue_trace(_, _, _, :disabled), do: {:error, :disabled} @@ -303,11 +376,17 @@ defmodule Spandex do continue_trace(name, %SpanContext{trace_id: trace_id, parent_id: span_id}, opts) end + @doc """ + Given a span struct, resumes a trace from a different process or service. + + Span updates for the top span may be passed in. They are skipped if they are + invalid updates. As such, if you aren't sure if your updates are valid, it is + safer to perform a second call to `update_span/2` and check the return value. + """ @spec continue_trace_from_span(String.t(), Span.t(), Tracer.opts()) :: {:ok, Trace.t()} | {:error, :disabled} | {:error, :trace_already_present} - | {:error, [Optimal.error()]} def continue_trace_from_span(_name, _span, :disabled), do: {:error, :disabled} def continue_trace_from_span(name, span, opts) do @@ -321,10 +400,12 @@ defmodule Spandex do end end + @doc """ + Returns the context from a given set of HTTP headers, as determined by the adapter. + """ @spec distributed_context(Plug.Conn.t(), Tracer.opts()) :: {:ok, SpanContext.t()} | {:error, :disabled} - | {:error, [Optimal.error()]} def distributed_context(_, :disabled), do: {:error, :disabled} def distributed_context(conn, opts) do @@ -332,6 +413,10 @@ defmodule Spandex do adapter.distributed_context(conn, opts) end + @doc """ + Alters headers to include the outgoing HTTP headers necessary to continue a + distributed trace, as determined by the adapter. + """ @spec inject_context(headers(), SpanContext.t(), Tracer.opts()) :: headers() def inject_context(headers, %SpanContext{} = span_context, opts) do adapter = opts[:adapter] @@ -340,6 +425,30 @@ defmodule Spandex do # Private Helpers + defp update_many_spans(spans, opts) do + spans + |> Enum.reduce({:ok, []}, fn + span, {:ok, acc} -> + case Span.update(span, opts) do + {:ok, updated} -> + {:ok, [updated | acc]} + + {:error, error} -> + {:error, error} + end + + _, {:error, error} -> + {:error, error} + end) + |> case do + {:ok, list} -> + {:ok, Enum.reverse(list)} + + {:error, error} -> + {:error, error} + end + end + defp do_continue_trace(name, span_context, opts) do strategy = opts[:strategy] adapter = opts[:adapter] @@ -405,20 +514,23 @@ defmodule Spandex do defp do_update_span(%Trace{stack: stack} = trace, opts, true) do strategy = opts[:strategy] - new_stack = List.update_at(stack, -1, &update_or_keep(&1, opts)) - with {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do - {:ok, Enum.at(new_stack, -1)} + top_span = Enum.at(stack, -1) + + with {:ok, updated} <- Span.update(top_span, opts), + new_stack <- List.replace_at(stack, -1, updated), + {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do + {:ok, updated} end end defp do_update_span(%Trace{stack: [current_span | other_spans]} = trace, opts, false) do strategy = opts[:strategy] - updated_span = update_or_keep(current_span, opts) - new_stack = [updated_span | other_spans] - with {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do - {:ok, updated_span} + with {:ok, updated} <- Span.update(current_span, opts), + new_stack <- [updated | other_spans], + {:ok, _trace} <- strategy.put_trace(opts[:trace_key], %{trace | stack: new_stack}) do + {:ok, updated} end end diff --git a/test/spandex_test.exs b/test/spandex_test.exs index 4dc40cc..08baa72 100644 --- a/test/spandex_test.exs +++ b/test/spandex_test.exs @@ -130,8 +130,6 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.update_span(:disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip 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) @@ -200,8 +198,6 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.update_top_span(:disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip 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) @@ -237,8 +233,6 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.update_all_spans(:disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip 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) @@ -325,15 +319,11 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.finish_trace(:disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip - test "returns an error if invalid options are specified" do + test "does not return an error if invalid update options are supplied" 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 + assert {:ok, %Trace{id: trace_id}} = Spandex.finish_trace(@base_opts ++ [type: "not an atom"]) end end @@ -389,15 +379,11 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.finish_trace(:disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip - test "returns an error if invalid options are specified" do + test "ignores any span update failures" 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 + assert {:ok, %Span{}} = Spandex.finish_span(@base_opts ++ [type: "not an atom"]) end end @@ -427,8 +413,6 @@ defmodule Spandex.Test.SpandexTest do assert {:error, :disabled} = Spandex.span_error(@runtime_error, @fake_stacktrace, :disabled) end - # TODO: Currently, invalid opts are silently ignored. Should we change that? - @tag :skip 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) @@ -439,7 +423,6 @@ defmodule Spandex.Test.SpandexTest do @fake_stacktrace, @base_opts ++ [type: "not an atom"] ) - assert {:type, "must be of type :atom"} in validation_errors end end