From 96f2246c7555e1574d83928f1d31b77eeea8acdb Mon Sep 17 00:00:00 2001 From: Garth Kidd Date: Mon, 5 Aug 2019 20:04:01 +1000 Subject: [PATCH 1/2] WIP: configurable span tracking behaviour --- config/config.exs | 1 + lib/opencensus/process_context.ex | 63 ++++++++++++++++++++++++++ lib/opencensus/trace.ex | 68 ++++++++++++++++++++++++++-- test/opencensus_trace_async_test.exs | 2 +- 4 files changed, 130 insertions(+), 4 deletions(-) create mode 100644 lib/opencensus/process_context.ex diff --git a/config/config.exs b/config/config.exs index 369af7c..6b159da 100644 --- a/config/config.exs +++ b/config/config.exs @@ -8,6 +8,7 @@ if Mix.env() == :test do report_dir: "reports/exunit" config :opencensus, + process_context: Opencensus.ProcessContext.DefaultImplementation, reporters: [{Opencensus.TestSupport.SpanCaptureReporter, []}], send_interval_ms: 100 end diff --git a/lib/opencensus/process_context.ex b/lib/opencensus/process_context.ex new file mode 100644 index 0000000..06de917 --- /dev/null +++ b/lib/opencensus/process_context.ex @@ -0,0 +1,63 @@ +defmodule Opencensus.ProcessContext do + @moduledoc """ + Experimental behaviour to control how the span context is tracked. + + Use the matching methods in `Opencensus.ProcessContext.ConfiguredImplementation`. + """ + + @doc """ + Put the current context. + + Returns the previous value. + """ + @callback put_span_ctx(span_ctx :: :opencensus.span_ctx() | :undefined) :: + :opencensus.span_ctx() | :undefined + + @doc """ + Get the current span context. + + Implementations [SHOULD NOT] attempt recovery if the span context isn't where `c:put_span_ctx/1` + should have put it. Callers [MAY] rely on this behaviour, using `c:put_span_ctx/1` to "put back" + any value they got from `c:get_span_ctx/0`. + + [SHOULD NOT]: https://tools.ietf.org/html/rfc2119#section-4 + [MAY]: https://tools.ietf.org/html/rfc2119#section-5 + """ + @callback get_span_ctx() :: :opencensus.span_ctx() | :undefined + + @doc """ + Recover the current span context by less reliable means. + + Implementations [SHOULD] check `c:get_span_ctx/0` and return its value if not `:undefined`. + + Callers [SHOULD] check `c:get_span_ctx/0` and avoid calling `c:recover_span_ctx/0` if possible. + Callers [MUST NOT] pass a value obtained via `c:recover_span_ctx/0` to `c:put_span_ctx/1`. + + [SHOULD]: https://tools.ietf.org/html/rfc2119#section-3 + [MUST NOT]: https://tools.ietf.org/html/rfc2119#section-2 + """ + @callback recover_span_ctx() :: :opencensus.span_ctx() | :undefined +end + +defmodule Opencensus.ProcessContext.DefaultImplementation do + @moduledoc "Process context behaviour matching the default implementation." + + @behaviour Opencensus.ProcessContext + + @impl true + def put_span_ctx(span_ctx) do + previous_span_ctx = get_span_ctx() + Process.put(:oc_span_ctx_key, span_ctx) + previous_span_ctx + end + + @impl true + def get_span_ctx do + Process.get(:oc_span_ctx_key, :undefined) + end + + @impl true + def recover_span_ctx do + get_span_ctx() + end +end diff --git a/lib/opencensus/trace.ex b/lib/opencensus/trace.ex index f8cfd5f..8eb5622 100644 --- a/lib/opencensus/trace.ex +++ b/lib/opencensus/trace.ex @@ -45,6 +45,9 @@ defmodule Opencensus.Trace do end ``` """ + + @behaviour Opencensus.ProcessContext + defmacro with_child_span(label, attributes \\ quote(do: %{}), do: block) do line = __CALLER__.line module = __CALLER__.module @@ -60,21 +63,22 @@ defmodule Opencensus.Trace do }) quote do - parent_span_ctx = :ocp.current_span_ctx() + previous_span_ctx = Opencensus.Trace.get_span_ctx() + parent_span_ctx = Opencensus.Trace.effective_span_ctx() new_span_ctx = :oc_trace.start_span(unquote(label), parent_span_ctx, %{ :attributes => unquote(computed_attributes) }) - _ = :ocp.with_span_ctx(new_span_ctx) + _ = Opencensus.Trace.put_span_ctx(new_span_ctx) Opencensus.Logger.set_logger_metadata() try do unquote(block) after _ = :oc_trace.finish_span(new_span_ctx) - _ = :ocp.with_span_ctx(parent_span_ctx) + _ = Opencensus.Trace.put_span_ctx(previous_span_ctx) Opencensus.Logger.set_logger_metadata() end end @@ -166,4 +170,62 @@ defmodule Opencensus.Trace do """ @spec await(Task.t(), :infinity | pos_integer()) :: term() defdelegate await(task, timeout \\ 5000), to: Task + + @doc """ + Put the current span context. + + Replaces `:ocp.with_span_ctx/1`. + + Callers [MAY] pass values from `get_span_ctx/0` to `put_span_ctx/1`. + + Callers [MUST NOT] pass a value obtained via `recover_span_ctx/0` to `put_span_ctx/1`. + + Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. + + [MAY]: https://tools.ietf.org/html/rfc2119#section-5 + """ + @impl Opencensus.ProcessContext + def put_span_ctx(span_ctx), do: process_context() |> apply(:put_span_ctx, [span_ctx]) + + @doc """ + Get the current span context. + + Replaces `:ocp.current_span_ctx/0`, along with `recover_span_ctx/0`. + + Callers [MAY] pass values from `get_span_ctx/0` to `put_span_ctx/1`. + + Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. + + [MAY]: https://tools.ietf.org/html/rfc2119#section-5 + """ + @impl Opencensus.ProcessContext + def get_span_ctx, do: process_context() |> apply(:get_span_ctx, []) + + @doc """ + Recover the current span context by less reliable means. + + Replaces `:ocp.current_span_ctx/0`, along with `get_span_ctx/0`. + + Callers [MUST NOT] pass a value obtained via `recover_span_ctx/0` to `put_span_ctx/1`. + + Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. + """ + @impl Opencensus.ProcessContext + def recover_span_ctx, do: process_context() |> apply(:recover_span_ctx, []) + + @doc false + def effective_span_ctx do + case get_span_ctx() do + :undefined -> recover_span_ctx() + span_ctx -> span_ctx + end + end + + defp process_context do + Application.get_env( + :opencensus, + :process_context, + Opencensus.ProcessContext.DefaultImplementation + ) + end end diff --git a/test/opencensus_trace_async_test.exs b/test/opencensus_trace_async_test.exs index e4bdc0b..6540873 100644 --- a/test/opencensus_trace_async_test.exs +++ b/test/opencensus_trace_async_test.exs @@ -42,7 +42,7 @@ defmodule Opencensus.AsyncTest do {inner, outer} = Trace.with_child_span "outside" do outer = :ocp.current_span_ctx() |> Span.load() - Trace.async(M, :f, [outer]) |> Trace.await(10) + M |> Trace.async(:f, [outer]) |> Trace.await(10) end assert inner.trace_id == outer.trace_id From 66d460294a7ca879da7c384c0461b2b4f7010dc5 Mon Sep 17 00:00:00 2001 From: Garth Kidd Date: Tue, 6 Aug 2019 17:44:00 +1000 Subject: [PATCH 2/2] WIP: configurable span tracking behaviour --- config/config.exs | 6 +- lib/opencensus/process_context.ex | 63 ----------- lib/opencensus/trace.ex | 69 +----------- lib/opencensus/unstable.ex | 158 +++++++++++++++++++++++++++ test/opencensus_test.exs | 4 +- test/opencensus_trace_async_test.exs | 12 +- 6 files changed, 176 insertions(+), 136 deletions(-) delete mode 100644 lib/opencensus/process_context.ex create mode 100644 lib/opencensus/unstable.ex diff --git a/config/config.exs b/config/config.exs index 6b159da..436f766 100644 --- a/config/config.exs +++ b/config/config.exs @@ -8,7 +8,11 @@ if Mix.env() == :test do report_dir: "reports/exunit" config :opencensus, - process_context: Opencensus.ProcessContext.DefaultImplementation, + process_contexts: [ + Opencensus.Unstable.ProcessContext.SeqTrace, + Opencensus.Unstable.ProcessContext.ProcessDictionary, + Opencensus.Unstable.ProcessContext.ProcessDictionaryWithRecovery + ], reporters: [{Opencensus.TestSupport.SpanCaptureReporter, []}], send_interval_ms: 100 end diff --git a/lib/opencensus/process_context.ex b/lib/opencensus/process_context.ex deleted file mode 100644 index 06de917..0000000 --- a/lib/opencensus/process_context.ex +++ /dev/null @@ -1,63 +0,0 @@ -defmodule Opencensus.ProcessContext do - @moduledoc """ - Experimental behaviour to control how the span context is tracked. - - Use the matching methods in `Opencensus.ProcessContext.ConfiguredImplementation`. - """ - - @doc """ - Put the current context. - - Returns the previous value. - """ - @callback put_span_ctx(span_ctx :: :opencensus.span_ctx() | :undefined) :: - :opencensus.span_ctx() | :undefined - - @doc """ - Get the current span context. - - Implementations [SHOULD NOT] attempt recovery if the span context isn't where `c:put_span_ctx/1` - should have put it. Callers [MAY] rely on this behaviour, using `c:put_span_ctx/1` to "put back" - any value they got from `c:get_span_ctx/0`. - - [SHOULD NOT]: https://tools.ietf.org/html/rfc2119#section-4 - [MAY]: https://tools.ietf.org/html/rfc2119#section-5 - """ - @callback get_span_ctx() :: :opencensus.span_ctx() | :undefined - - @doc """ - Recover the current span context by less reliable means. - - Implementations [SHOULD] check `c:get_span_ctx/0` and return its value if not `:undefined`. - - Callers [SHOULD] check `c:get_span_ctx/0` and avoid calling `c:recover_span_ctx/0` if possible. - Callers [MUST NOT] pass a value obtained via `c:recover_span_ctx/0` to `c:put_span_ctx/1`. - - [SHOULD]: https://tools.ietf.org/html/rfc2119#section-3 - [MUST NOT]: https://tools.ietf.org/html/rfc2119#section-2 - """ - @callback recover_span_ctx() :: :opencensus.span_ctx() | :undefined -end - -defmodule Opencensus.ProcessContext.DefaultImplementation do - @moduledoc "Process context behaviour matching the default implementation." - - @behaviour Opencensus.ProcessContext - - @impl true - def put_span_ctx(span_ctx) do - previous_span_ctx = get_span_ctx() - Process.put(:oc_span_ctx_key, span_ctx) - previous_span_ctx - end - - @impl true - def get_span_ctx do - Process.get(:oc_span_ctx_key, :undefined) - end - - @impl true - def recover_span_ctx do - get_span_ctx() - end -end diff --git a/lib/opencensus/trace.ex b/lib/opencensus/trace.ex index 8eb5622..947513d 100644 --- a/lib/opencensus/trace.ex +++ b/lib/opencensus/trace.ex @@ -46,8 +46,6 @@ defmodule Opencensus.Trace do ``` """ - @behaviour Opencensus.ProcessContext - defmacro with_child_span(label, attributes \\ quote(do: %{}), do: block) do line = __CALLER__.line module = __CALLER__.module @@ -63,22 +61,23 @@ defmodule Opencensus.Trace do }) quote do - previous_span_ctx = Opencensus.Trace.get_span_ctx() - parent_span_ctx = Opencensus.Trace.effective_span_ctx() + previous_span_ctx = Opencensus.Unstable.current_span_ctx() + parent_span_ctx = Opencensus.Unstable.recover_span_ctx() new_span_ctx = :oc_trace.start_span(unquote(label), parent_span_ctx, %{ :attributes => unquote(computed_attributes) }) - _ = Opencensus.Trace.put_span_ctx(new_span_ctx) + _ = Opencensus.Unstable.with_span_ctx(new_span_ctx) + ^new_span_ctx = Opencensus.Unstable.current_span_ctx() Opencensus.Logger.set_logger_metadata() try do unquote(block) after _ = :oc_trace.finish_span(new_span_ctx) - _ = Opencensus.Trace.put_span_ctx(previous_span_ctx) + _ = Opencensus.Unstable.with_span_ctx(previous_span_ctx) Opencensus.Logger.set_logger_metadata() end end @@ -170,62 +169,4 @@ defmodule Opencensus.Trace do """ @spec await(Task.t(), :infinity | pos_integer()) :: term() defdelegate await(task, timeout \\ 5000), to: Task - - @doc """ - Put the current span context. - - Replaces `:ocp.with_span_ctx/1`. - - Callers [MAY] pass values from `get_span_ctx/0` to `put_span_ctx/1`. - - Callers [MUST NOT] pass a value obtained via `recover_span_ctx/0` to `put_span_ctx/1`. - - Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. - - [MAY]: https://tools.ietf.org/html/rfc2119#section-5 - """ - @impl Opencensus.ProcessContext - def put_span_ctx(span_ctx), do: process_context() |> apply(:put_span_ctx, [span_ctx]) - - @doc """ - Get the current span context. - - Replaces `:ocp.current_span_ctx/0`, along with `recover_span_ctx/0`. - - Callers [MAY] pass values from `get_span_ctx/0` to `put_span_ctx/1`. - - Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. - - [MAY]: https://tools.ietf.org/html/rfc2119#section-5 - """ - @impl Opencensus.ProcessContext - def get_span_ctx, do: process_context() |> apply(:get_span_ctx, []) - - @doc """ - Recover the current span context by less reliable means. - - Replaces `:ocp.current_span_ctx/0`, along with `get_span_ctx/0`. - - Callers [MUST NOT] pass a value obtained via `recover_span_ctx/0` to `put_span_ctx/1`. - - Uses the configured `process_context`. See also: `Opencensus.ProcessContext`. - """ - @impl Opencensus.ProcessContext - def recover_span_ctx, do: process_context() |> apply(:recover_span_ctx, []) - - @doc false - def effective_span_ctx do - case get_span_ctx() do - :undefined -> recover_span_ctx() - span_ctx -> span_ctx - end - end - - defp process_context do - Application.get_env( - :opencensus, - :process_context, - Opencensus.ProcessContext.DefaultImplementation - ) - end end diff --git a/lib/opencensus/unstable.ex b/lib/opencensus/unstable.ex new file mode 100644 index 0000000..252542e --- /dev/null +++ b/lib/opencensus/unstable.ex @@ -0,0 +1,158 @@ +defmodule Opencensus.Unstable do + @moduledoc """ + Experimental higher-level API built on proposed `ot_ctx` behaviour. + """ + + @doc """ + Get the current span context. + + Uses the first configured `process_context` only to ensure the value is safe to pass to + `with_span_ctx/1` and `with_span_ctx/2` after you've finished your work. + """ + @spec current_span_ctx() :: :opencensus.span_ctx() | :undefined + def current_span_ctx do + process_contexts() + |> hd + |> get_span_ctx_via() + end + + @doc """ + Recovers the span context. + + Uses all configured `process_context`. + Results MAY be used as the parent of a new span. + Results MUST NOT be passed to `with_span_ctx/1` or `with_span_ctx/2`. + """ + @spec recover_span_ctx() :: :opencensus.span_ctx() | :undefined + def recover_span_ctx do + process_contexts() + |> Enum.find_value(:undefined, &get_span_ctx_via/1) + end + + @doc """ + Sets the span context. Replaces `:ocp.with_span_ctx/1`. + + Uses all configured `process_context`. + Returns the previous value of `current_span_ctx/0`. + """ + @spec with_span_ctx(span_ctx :: :opencensus.span_ctx() | :undefined) :: + :opencensus.span_ctx() | :undefined + def with_span_ctx(span_ctx) do + return_span_ctx = current_span_ctx() + process_contexts() |> Enum.each(&put_span_ctx_via(&1, span_ctx)) + return_span_ctx + end + + defp get_span_ctx_via(module) do + apply(module, :get, [span_ctx_key()]) + |> case do + nil -> :undefined + span_ctx -> span_ctx + end + end + + defp put_span_ctx_via(module, value) do + apply(module, :with_value, [span_ctx_key(), value]) + end + + @spec span_ctx_key() :: atom() + defp span_ctx_key do + Application.get_env(:opencensus, :span_ctx_key, :oc_span_ctx_key) + end + + @spec process_contexts() :: list(module()) + defp process_contexts do + Application.get_env(:opencensus, :process_contexts, [ + Opencensus.Unstable.ProcessContext.SeqTrace, + Opencensus.Unstable.ProcessContext.ProcessDictionary, + Opencensus.Unstable.ProcessContext.ProcessDictionaryWithRecovery + ]) + end +end + +defmodule Opencensus.Unstable.ProcessContext do + @moduledoc "Abstraction over process-local storage." + + @doc "Get a value." + @callback get(key :: atom()) :: any() | nil + + @doc "Put a value." + @callback with_value(key :: atom, value :: any()) :: :ok +end + +defmodule Opencensus.Unstable.ProcessContext.SeqTrace do + @moduledoc """ + Process-local storage using `seq_trace`. + + Shares well with any other use that maintains a namespace in the second element of a 2-tuple + `{:shared_label, _map}`. Otherwise leaves the trace label alone to avoid disrupting the other + usage. + """ + + @behaviour Opencensus.Unstable.ProcessContext + + @doc "Get a value from the shared `seq_trace` label." + @impl Opencensus.Unstable.ProcessContext + def get(key) do + case :seq_trace.get_token(:label) do + {:label, {:shared_label, %{^key => value}}} -> + value + + _ -> + nil + end + end + + @doc "Put a value to the shared `seq_trace` label if safe." + @impl Opencensus.Unstable.ProcessContext + def with_value(key, value) do + case :seq_trace.get_token(:label) do + [] -> + :seq_trace.set_token(:label, {:shared_label, %{key => value}}) + + {:label, {:shared_label, map}} when is_map(map) -> + :seq_trace.set_token(:label, {:shared_label, Map.put(map, key, value)}) + + _ -> + nil + end + + :ok + end +end + +defmodule Opencensus.Unstable.ProcessContext.ProcessDictionary do + @moduledoc """ + Process-local storage using the process dictionary. + """ + + @behaviour Opencensus.Unstable.ProcessContext + + @doc "Get a value from the process dictionary." + @impl Opencensus.Unstable.ProcessContext + def get(key), do: Process.get(key) + + @impl Opencensus.Unstable.ProcessContext + def with_value(key, value) do + Process.put(key, value) + :ok + end +end + +defmodule Opencensus.Unstable.ProcessContext.ProcessDictionaryWithRecovery do + @moduledoc """ + Process-local storage using the process dictionary. + """ + + @behaviour Opencensus.Unstable.ProcessContext + + @doc "Get a value from the process dictionary." + @impl Opencensus.Unstable.ProcessContext + def get(key) do + [self() | Process.get(:"$callers", [])] + |> Enum.find_value(fn pid -> pid |> Process.info() |> get_in([:dictionary, key]) end) + end + + @impl Opencensus.Unstable.ProcessContext + defdelegate with_value(key, value), to: Opencensus.Unstable.ProcessContext.ProcessDictionary +end diff --git a/test/opencensus_test.exs b/test/opencensus_test.exs index e4b8c04..01fd336 100644 --- a/test/opencensus_test.exs +++ b/test/opencensus_test.exs @@ -11,12 +11,12 @@ defmodule OpencensusTest do on_exit(make_ref(), &detach/0) assert Logger.metadata() == [] - assert :ocp.current_span_ctx() == :undefined + assert Opencensus.Unstable.current_span_ctx() == :undefined with_child_span "child_span" do :do_something - assert :ocp.current_span_ctx() != :undefined + assert Opencensus.Unstable.current_span_ctx() != :undefined assert Logger.metadata() |> Keyword.keys() |> Enum.sort() == [ :span_id, diff --git a/test/opencensus_trace_async_test.exs b/test/opencensus_trace_async_test.exs index 6540873..681e3ba 100644 --- a/test/opencensus_trace_async_test.exs +++ b/test/opencensus_trace_async_test.exs @@ -7,15 +7,15 @@ defmodule Opencensus.AsyncTest do alias Opencensus.Trace test "Trace.async/1" do - assert :ocp.current_span_ctx() == :undefined + assert Opencensus.Unstable.current_span_ctx() == :undefined {inner, outer} = Trace.with_child_span "outside" do - outer = :ocp.current_span_ctx() |> Span.load() + outer = Opencensus.Unstable.current_span_ctx() |> Span.load() Trace.async(fn -> Trace.with_child_span "inside" do - inner = :ocp.current_span_ctx() |> Span.load() + inner = Opencensus.Unstable.current_span_ctx() |> Span.load() {inner, outer} end end) @@ -30,18 +30,18 @@ defmodule Opencensus.AsyncTest do defmodule M do def f(outer) do Trace.with_child_span "inside" do - inner = :ocp.current_span_ctx() |> Span.load() + inner = Opencensus.Unstable.current_span_ctx() |> Span.load() {inner, outer} end end end test "Trace.async/3" do - assert :ocp.current_span_ctx() == :undefined + assert Opencensus.Unstable.current_span_ctx() == :undefined {inner, outer} = Trace.with_child_span "outside" do - outer = :ocp.current_span_ctx() |> Span.load() + outer = Opencensus.Unstable.current_span_ctx() |> Span.load() M |> Trace.async(:f, [outer]) |> Trace.await(10) end