Reduce number of reductions in Appsignal.Instrumentation.instrument/3 (…

…#855)

* Remove calls to Config.active?/0 from Span

Currently, the Config.active?/0 function is called every time
Span.set_name/2 or Span.do_add_error/4 functions are called. Because
calling either of these functions on a nil is a noop, and nils are
passed around instead of spans when the package is not active, these can
be safely removed.

This reduces the amount of ets lookups by 2n when calling the
instrument/3 function with a name and a category.

* Pass fetched config from active?/0 to valid?/1

Currently, the Config.active?/0 function calls out to valid?/0 if the
configuration is marked as active. Both functions fetch the
configuration, which requires an ets lookup.

Calling the valid?/1 function from active?/0 while passing the
already-fetched configuration saves the second lookup.

* Run lookups without checking the registry first

Currently, each lookup is preceded by a check if the registry is
running. This patch removes that check and adds error handling for doing
lookups when the registry is not running.

* Remove running?/0 checks before insert or delete

Much like checking to see if the registry was running before every
lookup, the current version checks if the registry is running before
every insertion or deletion. Instead, this patch handles errors caused
by the registry being down.

* Handle nil timestamps in span creation functions

Instead of checking if a timestamp is present, pass whatever's passed as
a timestamp in the options keyword list and have the Span.create_root/3
and Span.create_child/3 functions handle calls with or without
timestamps.

* Add changeset to describe tracer performance fixes

"Improve Tracer performance by removing duplicate runtime configuration
and storage checks"

.changesets/improve-tracer-performance-by-removing-duplicate-runtime-configuration-and-storage-checks.md

@@ -0,0 +1,6 @@
+---
+bump: "patch"
+type: "fix"
+---
+
+Improve Tracer performance by removing duplicate runtime configuration and storage checks

lib/appsignal/config.ex

@@ -137,14 +137,18 @@ defmodule Appsignal.Config do
   """
   @spec valid?() :: boolean
   def valid? do
-    do_valid?(Application.get_env(:appsignal, :config)[:push_api_key])
+    :appsignal
+    |> Application.get_env(:config)
+    |> valid?
   end
 
-  defp do_valid?(push_api_key) when is_binary(push_api_key) do
-    !empty?(String.trim(push_api_key))
+  defp valid?(%{push_api_key: key}) when is_binary(key) do
+    !(key
+      |> String.trim()
+      |> empty?())
   end
 
-  defp do_valid?(_push_api_key), do: false
+  defp valid?(_config), do: false
 
   @doc """
   Returns true if the configuration is valid and the AppSignal agent is
@@ -154,11 +158,14 @@ defmodule Appsignal.Config do
   def active? do
     :appsignal
     |> Application.get_env(:config, @default_config)
-    |> do_active?
+    |> active?
+  end
+
+  defp active?(%{active: true} = config) do
+    valid?(config)
   end
 
-  defp do_active?(%{active: true}), do: valid?()
-  defp do_active?(_), do: false
+  defp active?(_config), do: false
 
   @doc """
   Returns true if debug mode is turned on, false otherwise.

lib/appsignal/span.ex

@@ -22,15 +22,9 @@ defmodule Appsignal.Span do
       Appsignal.Span.create_root("http_request", self())
 
   """
-  def create_root(namespace, pid) do
-    if Config.active?() do
-      {:ok, reference} = @nif.create_root_span(namespace)
+  def create_root(namespace, pid), do: create_root(namespace, pid, nil)
 
-      %Span{reference: reference, pid: pid}
-    end
-  end
-
-  @spec create_root(String.t(), pid(), integer()) :: t() | nil
+  @spec create_root(String.t(), pid(), integer() | nil) :: t() | nil
   @doc """
   Create a root `Appsignal.Span` with a namespace, a pid and an explicit start time.
 
@@ -40,6 +34,14 @@ defmodule Appsignal.Span do
       Appsignal.Span.create_root("http_request", self(), :os.system_time())
 
   """
+  def create_root(namespace, pid, nil) do
+    if Config.active?() do
+      {:ok, reference} = @nif.create_root_span(namespace)
+
+      %Span{reference: reference, pid: pid}
+    end
+  end
+
   def create_root(namespace, pid, start_time) do
     if Config.active?() do
       sec = :erlang.convert_time_unit(start_time, :native, :second)
@@ -59,15 +61,9 @@ defmodule Appsignal.Span do
       |> Appsignal.Span.create_child(self())
 
   """
-  def create_child(%Span{reference: parent}, pid) do
-    if Config.active?() do
-      {:ok, reference} = @nif.create_child_span(parent)
+  def create_child(span, pid), do: create_child(span, pid, nil)
 
-      %Span{reference: reference, pid: pid}
-    end
-  end
-
-  @spec create_child(t() | nil, pid(), integer()) :: t() | nil
+  @spec create_child(t() | nil, pid(), integer() | nil) :: t() | nil
   @doc """
   Create a child `Appsignal.Span` with an explicit start time.
 
@@ -76,6 +72,14 @@ defmodule Appsignal.Span do
       |> Appsignal.Span.create_child(self(), :os.system_time())
 
   """
+  def create_child(%Span{reference: parent}, pid, nil) do
+    if Config.active?() do
+      {:ok, reference} = @nif.create_child_span(parent)
+
+      %Span{reference: reference, pid: pid}
+    end
+  end
+
   def create_child(%Span{reference: parent}, pid, start_time) do
     if Config.active?() do
       sec = :erlang.convert_time_unit(start_time, :native, :second)
@@ -98,10 +102,8 @@ defmodule Appsignal.Span do
   """
   def set_name(%Span{reference: reference} = span, name)
       when is_reference(reference) and is_binary(name) do
-    if Config.active?() do
-      :ok = @nif.set_span_name(reference, name)
-      span
-    end
+    :ok = @nif.set_span_name(reference, name)
+    span
   end
 
   def set_name(span, _name), do: span
@@ -268,17 +270,15 @@ defmodule Appsignal.Span do
 
   @doc false
   def do_add_error(%Span{reference: reference} = span, name, message, stacktrace) do
-    if Config.active?() do
-      :ok =
-        @nif.add_span_error(
-          reference,
-          name,
-          message,
-          Appsignal.Utils.DataEncoder.encode(stacktrace)
-        )
-
-      span
-    end
+    :ok =
+      @nif.add_span_error(
+        reference,
+        name,
+        message,
+        Appsignal.Utils.DataEncoder.encode(stacktrace)
+      )
+
+    span
   end
 
   def do_add_error(nil, _name, _message, _stacktrace), do: nil

lib/appsignal/tracer.ex

@@ -49,37 +49,33 @@ defmodule Appsignal.Tracer do
   def create_span(namespace, nil, options) do
     pid = Keyword.get(options, :pid, self())
 
-    if running?() && !ignored?(pid) do
-      span =
-        case Keyword.get(options, :start_time) do
-          nil -> Span.create_root(namespace, pid)
-          timestamp -> Span.create_root(namespace, pid, timestamp)
-        end
-
-      register(span)
+    unless ignored?(pid) do
+      namespace
+      |> Span.create_root(pid, options[:start_time])
+      |> register()
     end
   end
 
   def create_span(_namespace, parent, options) do
     pid = Keyword.get(options, :pid, self())
 
-    if running?() && !ignored?(pid) do
-      span =
-        case Keyword.get(options, :start_time) do
-          nil -> Span.create_child(parent, pid)
-          timestamp -> Span.create_child(parent, pid, timestamp)
-        end
-
-      register(span)
+    unless ignored?(pid) do
+      parent
+      |> Span.create_child(pid, options[:start_time])
+      |> register()
     end
   end
 
   @doc """
   Finds the span in the registry table.
   """
-  @spec lookup(pid()) :: list()
+  @spec lookup(pid()) :: list() | []
   def lookup(pid) do
-    if running?(), do: :ets.lookup(@table, pid)
+    try do
+      :ets.lookup(@table, pid)
+    rescue
+      ArgumentError -> []
+    end
   end
 
   @doc """
@@ -148,11 +144,9 @@ defmodule Appsignal.Tracer do
 
   """
   def close_span(%Span{} = span) do
-    if running?() do
-      span
-      |> Span.close()
-      |> deregister()
-    end
+    span
+    |> Span.close()
+    |> deregister()
 
     :ok
   end
@@ -172,11 +166,9 @@ defmodule Appsignal.Tracer do
   def close_span(span, options)
 
   def close_span(%Span{} = span, end_time: end_time) do
-    if running?() do
-      span
-      |> Span.close(end_time)
-      |> deregister()
-    end
+    span
+    |> Span.close(end_time)
+    |> deregister()
 
     :ok
   end
@@ -188,19 +180,15 @@ defmodule Appsignal.Tracer do
   """
   @spec ignore(pid()) :: :ok
   def ignore(pid) do
-    if running?() do
-      delete(pid)
-      :ets.insert(@table, {pid, :ignore})
-      @monitor.add()
-    end
-
+    delete(pid)
+    insert({pid, :ignore}) && @monitor.add()
     :ok
   end
 
   @doc """
   Ignores the current process.
   """
-  @spec ignore() :: :ok | nil
+  @spec ignore() :: :ok
   def ignore do
     self() |> ignore()
   end
@@ -210,20 +198,30 @@ defmodule Appsignal.Tracer do
   """
   @spec delete(pid()) :: :ok
   def delete(pid) do
-    if running?(), do: :ets.delete(@table, pid)
+    try do
+      :ets.delete(@table, pid)
+    rescue
+      ArgumentError -> :ok
+    end
+
     :ok
   end
 
   defp register(%Span{pid: pid} = span) do
-    :ets.insert(@table, {pid, span})
-    @monitor.add()
-    span
+    if insert({pid, span}) do
+      @monitor.add()
+      span
+    end
   end
 
   defp register(nil), do: nil
 
   defp deregister(%Span{pid: pid} = span) do
-    :ets.delete_object(@table, {pid, span})
+    try do
+      :ets.delete_object(@table, {pid, span})
+    rescue
+      ArgumentError -> false
+    end
   end
 
   defp ignored?(pid) when is_pid(pid) do
@@ -235,7 +233,11 @@ defmodule Appsignal.Tracer do
   defp ignored?([{_pid, :ignore}]), do: true
   defp ignored?(_), do: false
 
-  defp running? do
-    is_pid(Process.whereis(__MODULE__))
+  defp insert(span) do
+    try do
+      :ets.insert(@table, span)
+    rescue
+      ArgumentError -> nil
+    end
   end
 end

test/appsignal/span_test.exs

@@ -194,22 +194,6 @@ defmodule AppsignalSpanTest do
     end
   end
 
-  describe ".set_name/2, when disabled" do
-    setup [:create_root_span, :disable_appsignal]
-
-    setup %{span: span} do
-      [return: Span.set_name(span, "test")]
-    end
-
-    test "returns nil", %{return: return} do
-      assert return == nil
-    end
-
-    test "does not set the name through the Nif" do
-      assert Test.Nif.get(:set_span_name) == :error
-    end
-  end
-
   describe ".set_namespace/2" do
     setup :create_root_span
 
@@ -314,29 +298,6 @@ defmodule AppsignalSpanTest do
     end
   end
 
-  describe ".add_error/3, when disabled" do
-    setup [:create_root_span, :disable_appsignal]
-
-    setup %{span: span} do
-      return =
-        try do
-          raise "Exception!"
-        rescue
-          exception -> Span.add_error(span, exception, __STACKTRACE__)
-        end
-
-      [return: return]
-    end
-
-    test "returns nil", %{return: return} do
-      assert return == nil
-    end
-
-    test "does not set the error through the Nif" do
-      assert Test.Nif.get(:add_span_error) == :error
-    end
-  end
-
   describe ".add_error/4" do
     setup :create_root_span
 
@@ -405,29 +366,6 @@ defmodule AppsignalSpanTest do
     end
   end
 
-  describe ".add_error/4, when disabled" do
-    setup [:create_root_span, :disable_appsignal]
-
-    setup %{span: span} do
-      return =
-        try do
-          raise "Exception!"
-        catch
-          kind, reason -> Span.add_error(span, kind, reason, __STACKTRACE__)
-        end
-
-      [return: return]
-    end
-
-    test "returns nil", %{return: return} do
-      assert return == nil
-    end
-
-    test "does not set the error through the Nif" do
-      assert Test.Nif.get(:add_span_error) == :error
-    end
-  end
-
   describe ".set_sample_data/3" do
     setup :create_root_span