Add instrumentation using :telemetry

lib/fun_with_flags.ex

@@ -74,17 +74,23 @@ defmodule FunWithFlags do
   def enabled?(flag_name, options \\ [])
 
   def enabled?(flag_name, []) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     {:ok, flag} = @store.lookup(flag_name)
-    Flag.enabled?(flag)
+    result = Flag.enabled?(flag)
+    emit_telemetry_event(:enabled?, flag_name, start_time, result, %{options: []})
+    result
   end
 
   def enabled?(flag_name, [for: nil]) do
     enabled?(flag_name)
   end
 
   def enabled?(flag_name, [for: item]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     {:ok, flag} = @store.lookup(flag_name)
-    Flag.enabled?(flag, for: item)
+    result = Flag.enabled?(flag, for: item)
+    emit_telemetry_event(:enabled?, flag_name, start_time, result, %{options: [for: item]})
+    result
   end
 
 
@@ -178,23 +184,29 @@ defmodule FunWithFlags do
   def enable(flag_name, options \\ [])
 
   def enable(flag_name, []) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:boolean, true)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, flag} -> verify(flag)
       error -> error
     end
+    emit_telemetry_event(:enable, flag_name, start_time, result, %{options: []})
+    result
   end
 
   def enable(flag_name, [for_actor: nil]) do
     enable(flag_name)
   end
 
   def enable(flag_name, [for_actor: actor]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:actor, actor, true)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, flag} -> verify(flag, for: actor)
       error -> error
     end
+    emit_telemetry_event(:enable, flag_name, start_time, result, %{options: [for_actor: actor]})
+    result
   end
 
 
@@ -203,28 +215,37 @@ defmodule FunWithFlags do
   end
 
   def enable(flag_name, [for_group: group_name]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:group, group_name, true)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, _flag} -> {:ok, true}
       error -> error
     end
+    emit_telemetry_event(:enable, flag_name, start_time, result, %{options: [for_group: group_name]})
+    result
   end
 
 
   def enable(flag_name, [for_percentage_of: {:time, ratio}]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:percentage_of_time, ratio)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, _flag} -> {:ok, true}
       error -> error
     end
+    emit_telemetry_event(:enable, flag_name, start_time, result, %{options: [for_percentage_of: {:time, ratio}]})
+    result
   end
 
   def enable(flag_name, [for_percentage_of: {:actors, ratio}]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:percentage_of_actors, ratio)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, _flag} -> {:ok, true}
       error -> error
     end
+    emit_telemetry_event(:enable, flag_name, start_time, result, %{options: [for_percentage_of: {:actors, ratio}]})
+    result
   end
 
 
@@ -310,45 +331,57 @@ defmodule FunWithFlags do
   def disable(flag_name, options \\ [])
 
   def disable(flag_name, []) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:boolean, false)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, flag} -> verify(flag)
       error -> error
     end
+    emit_telemetry_event(:disable, flag_name, start_time, result, %{options: []})
+    result
   end
 
   def disable(flag_name, [for_actor: nil]) do
     disable(flag_name)
   end
 
   def disable(flag_name, [for_actor: actor]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:actor, actor, false)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, flag} -> verify(flag, for: actor)
       error -> error
     end
+    emit_telemetry_event(:disable, flag_name, start_time, result, %{options: [for_actor: actor]})
+    result
   end
 
   def disable(flag_name, [for_group: nil]) do
     disable(flag_name)
   end
 
   def disable(flag_name, [for_group: group_name]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:group, group_name, false)
-    case @store.put(flag_name, gate) do
+    result = case @store.put(flag_name, gate) do
       {:ok, _flag} -> {:ok, false}
       error -> error
     end
+    emit_telemetry_event(:disable, flag_name, start_time, result, %{options: [for_group: group_name]})
+    result
   end
 
 
   def disable(flag_name, [for_percentage_of: {type, ratio}])
   when is_atom(flag_name) and is_float(ratio) do
+    start_time = System.monotonic_time()
     inverted_ratio = 1.0 - ratio
-    case enable(flag_name, [for_percentage_of: {type, inverted_ratio}]) do
+    result = case enable(flag_name, [for_percentage_of: {type, inverted_ratio}]) do
       {:ok, true} -> {:ok, false}
       error -> error
     end
+    emit_telemetry_event(:disable, flag_name, start_time, result, %{options: [for_percentage_of: {type, ratio}]})
+    result
   end
 
 
@@ -418,38 +451,53 @@ defmodule FunWithFlags do
   def clear(flag_name, options \\ [])
 
   def clear(flag_name, []) when is_atom(flag_name) do
-    case @store.delete(flag_name) do
+    start_time = System.monotonic_time()
+    result = case @store.delete(flag_name) do
       {:ok, _flag} -> :ok
       error -> error
     end
+    emit_telemetry_event(:clear, flag_name, start_time, result, %{options: []})
+    result
   end
 
   def clear(flag_name, [boolean: true]) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:boolean, false) # we only care about the gate id
-    _clear_gate(flag_name, gate)
+    result = _clear_gate(flag_name, gate)
+    emit_telemetry_event(:clear, flag_name, start_time, result, %{options: [boolean: true]})
+    result
   end
 
   def clear(flag_name, [for_actor: nil]) do
     clear(flag_name)
   end
 
   def clear(flag_name, [for_actor: actor]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:actor, actor, false) # we only care about the gate id
-    _clear_gate(flag_name, gate)
+    result = _clear_gate(flag_name, gate)
+    emit_telemetry_event(:clear, flag_name, start_time, result, %{options: [for_actor: actor]})
+    result
   end
 
   def clear(flag_name, [for_group: nil]) do
     clear(flag_name)
   end
 
   def clear(flag_name, [for_group: group_name]) when is_atom(flag_name) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:group, group_name, false) # we only care about the gate id
-    _clear_gate(flag_name, gate)
+    result = _clear_gate(flag_name, gate)
+    emit_telemetry_event(:clear, flag_name, start_time, result, %{options: [for_group: group_name]})
+    result
   end
 
   def clear(flag_name, [for_percentage: true]) do
+    start_time = System.monotonic_time()
     gate = Gate.new(:percentage_of_time, 0.5) # we only care about the gate id
-    _clear_gate(flag_name, gate)
+    result = _clear_gate(flag_name, gate)
+    emit_telemetry_event(:clear, flag_name, start_time, result, %{options: [for_percentage: true]})
+    result
   end
 
   defp _clear_gate(flag_name, gate) do
@@ -524,4 +572,24 @@ defmodule FunWithFlags do
   #
   @doc false
   def compiled_store, do: @store
+
+  defp emit_telemetry_event(action, flag_name, start_time, result, metadata) do
+    end_time = System.monotonic_time()
+    measurements = %{
+      duration: end_time - start_time
+    }
+
+    event_metadata = Map.merge(metadata, %{
+      flag_name: flag_name,
+      result: result,
+      operation: action,
+    })
+
+    :telemetry.execute(
+       [:fun_with_flags, :flag_operation],
+      measurements,
+      event_metadata
+    )
+  end
+
 end

mix.exs

@@ -80,7 +80,8 @@ defmodule FunWithFlags.Mixfile do
 
       {:ex_doc, "~> 0.21", only: :dev, runtime: false},
       {:credo, "~> 1.7", only: :dev, runtime: false},
-      {:dialyxir, "~> 1.0", only: :dev, runtime: false}
+      {:dialyxir, "~> 1.0", only: :dev, runtime: false},
+      {:telemetry, "~> 1.0", optional: true}
     ]
   end
 

mix.lock

@@ -29,4 +29,5 @@
   "postgrex": {:hex, :postgrex, "0.19.0", "f7d50e50cb42e0a185f5b9a6095125a9ab7e4abccfbe2ab820ab9aa92b71dbab", [:mix], [{:db_connection, "~> 2.1", [hex: :db_connection, repo: "hexpm", optional: false]}, {:decimal, "~> 1.5 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:table, "~> 0.1.0", [hex: :table, repo: "hexpm", optional: true]}], "hexpm", "dba2d2a0a8637defbf2307e8629cb2526388ba7348f67d04ec77a5d6a72ecfae"},
   "redix": {:hex, :redix, "1.5.1", "a2386971e69bf23630fb3a215a831b5478d2ee7dc9ea7ac811ed89186ab5d7b7", [:mix], [{:castore, "~> 0.1.0 or ~> 1.0", [hex: :castore, repo: "hexpm", optional: true]}, {:nimble_options, "~> 0.5.0 or ~> 1.0", [hex: :nimble_options, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.0 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "85224eb2b683c516b80d472eb89b76067d5866913bf0be59d646f550de71f5c4"},
   "telemetry": {:hex, :telemetry, "1.2.1", "68fdfe8d8f05a8428483a97d7aab2f268aaff24b49e0f599faa091f1d4e7f61c", [:rebar3], [], "hexpm", "dad9ce9d8effc621708f99eac538ef1cbe05d6a874dd741de2e689c47feafed5"},
+  "telemetry_test": {:hex, :telemetry_test, "0.1.2", "122d927567c563cf57773105fa8104ae4299718ec2cbdddcf6776562c7488072", [:mix], [{:telemetry, "~> 1.2", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "7bd41a49ecfd33ecd82d2c7edae19a5736f0d2150206d0ee290dcf3885d0e14d"},
 }