diff --git a/lib/fun_with_flags.ex b/lib/fun_with_flags.ex index 7987875f..b186c7e4 100644 --- a/lib/fun_with_flags.ex +++ b/lib/fun_with_flags.ex @@ -74,8 +74,11 @@ 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 @@ -83,8 +86,11 @@ defmodule FunWithFlags do 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,11 +184,14 @@ 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 @@ -190,11 +199,14 @@ defmodule FunWithFlags do 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,11 +331,14 @@ 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 @@ -322,11 +346,14 @@ defmodule FunWithFlags do 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 @@ -334,21 +361,27 @@ defmodule FunWithFlags do 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,15 +451,21 @@ 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 @@ -434,8 +473,11 @@ defmodule FunWithFlags do 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 @@ -443,13 +485,19 @@ defmodule FunWithFlags do 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 diff --git a/mix.exs b/mix.exs index f6194f1a..e5e0af18 100644 --- a/mix.exs +++ b/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 diff --git a/mix.lock b/mix.lock index 460576f3..ce602743 100644 --- a/mix.lock +++ b/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"}, } diff --git a/test/fun_with_flags/telemetry_test.exs b/test/fun_with_flags/telemetry_test.exs new file mode 100644 index 00000000..3f7b1a2f --- /dev/null +++ b/test/fun_with_flags/telemetry_test.exs @@ -0,0 +1,558 @@ +defmodule FunWithFlags.TelemetryTest do + use FunWithFlags.TestCase, async: false + import FunWithFlags.TestUtils + import Mock + + describe ":enable telemetry" do + setup do + attach_telemetry() + + scrooge = %FunWithFlags.TestUser{ + id: 1, + email: "scrooge@mcduck.pdp", + groups: [:ducks, :billionaires] + } + + donald = %FunWithFlags.TestUser{ + id: 2, + email: "donald@duck.db", + groups: [:ducks, :super_heroes] + } + + {:ok, scrooge: scrooge, donald: donald, flag_name: unique_atom()} + end + + test "emits telemetry event when enabling a flag", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [], + result: {:ok, true}, + flag_name: ^flag_name, + operation: :enable + } + } + end + + test "emits telemetry event when enabling a flag for an actor", %{ + flag_name: flag_name, + scrooge: scrooge + } do + FunWithFlags.enable(flag_name, for_actor: scrooge) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_actor: ^scrooge], + result: {:ok, true}, + flag_name: ^flag_name, + operation: :enable + } + } + end + + test "emits telemetry event when enabling a flag for a group", %{flag_name: flag_name} do + group_name = :test_group + FunWithFlags.enable(flag_name, for_group: group_name) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_group: ^group_name], + result: {:ok, true}, + flag_name: ^flag_name, + operation: :enable + } + } + end + + test "emits telemetry event when enabling a flag for percentage of time", %{ + flag_name: flag_name + } do + ratio = 0.5 + FunWithFlags.enable(flag_name, for_percentage_of: {:time, ratio}) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_percentage_of: {:time, ^ratio}], + result: {:ok, true}, + flag_name: ^flag_name, + operation: :enable + } + } + end + + test "emits telemetry event when enabling a flag for percentage of actors", %{ + flag_name: flag_name + } do + ratio = 0.5 + FunWithFlags.enable(flag_name, for_percentage_of: {:actors, ratio}) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_percentage_of: {:actors, ^ratio}], + result: {:ok, true}, + flag_name: ^flag_name, + operation: :enable + } + } + end + end + + describe "enabled? telemetry" do + setup do + attach_telemetry() + + scrooge = %FunWithFlags.TestUser{ + id: 1, + email: "scrooge@mcduck.pdp", + groups: [:ducks, :billionaires] + } + + donald = %FunWithFlags.TestUser{ + id: 2, + email: "donald@duck.db", + groups: [:ducks, :super_heroes] + } + + flag_name = unique_atom() + {:ok, scrooge: scrooge, donald: donald, flag_name: flag_name} + end + + test "emits telemetry event when checking an enabled flag", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name) + + FunWithFlags.enabled?(flag_name) + + assert_receive %{ + event: [:fun_with_flags, :flag_operation], + measurements: %{duration: _}, + metadata: %{ + options: [], + result: true, + flag_name: ^flag_name, + operation: :enabled? + } + } + end + + test "emits telemetry event when checking a disabled flag", %{flag_name: flag_name} do + FunWithFlags.disable(flag_name) + + FunWithFlags.enabled?(flag_name) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [], + result: false, + flag_name: ^flag_name, + operation: :enabled? + } + } + end + + test "emits telemetry event when checking an enabled flag for a specific actor", %{ + flag_name: flag_name, + scrooge: scrooge + } do + FunWithFlags.enable(flag_name, for_actor: scrooge) + + FunWithFlags.enabled?(flag_name, for: scrooge) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for: ^scrooge], + result: true, + flag_name: ^flag_name, + operation: :enabled? + } + } + end + + test "emits telemetry event when checking a disabled flag for a specific actor", %{ + flag_name: flag_name, + donald: donald + } do + FunWithFlags.enable(flag_name) + FunWithFlags.disable(flag_name, for_actor: donald) + FunWithFlags.enabled?(flag_name, for: donald) + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for: ^donald], + result: false, + flag_name: ^flag_name, + operation: :enabled? + } + } + end + + test "emits telemetry event when checking an enabled flag for a group", %{ + flag_name: flag_name, + scrooge: scrooge + } do + group = :billionaires + FunWithFlags.enable(flag_name, for_group: group) + + result = FunWithFlags.enabled?(flag_name, for: scrooge) + + assert result == true + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for: ^scrooge], + result: true, + flag_name: ^flag_name, + operation: :enabled? + } + } + end + end + + describe "disable telemetry" do + setup do + attach_telemetry() + + scrooge = %FunWithFlags.TestUser{ + id: 1, + email: "scrooge@mcduck.pdp", + groups: [:ducks, :billionaires] + } + + donald = %FunWithFlags.TestUser{ + id: 2, + email: "donald@duck.db", + groups: [:ducks, :super_heroes] + } + + flag_name = unique_atom() + {:ok, scrooge: scrooge, donald: donald, flag_name: flag_name} + end + + test "emits telemetry event when disabling a flag globally", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name) + + result = FunWithFlags.disable(flag_name) + + assert result == {:ok, false} + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [], + result: {:ok, false}, + flag_name: ^flag_name, + operation: :disable + } + } + end + + test "emits telemetry event when disabling a flag for an actor", %{ + flag_name: flag_name, + scrooge: scrooge + } do + FunWithFlags.enable(flag_name, for_actor: scrooge) + + result = FunWithFlags.disable(flag_name, for_actor: scrooge) + + assert result == {:ok, false} + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_actor: ^scrooge], + result: {:ok, false}, + flag_name: ^flag_name, + operation: :disable + } + } + end + + test "emits telemetry event when disabling a flag for a group", %{flag_name: flag_name} do + group = :billionaires + FunWithFlags.enable(flag_name, for_group: group) + + result = FunWithFlags.disable(flag_name, for_group: group) + + assert result == {:ok, false} + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_group: ^group], + result: {:ok, false}, + flag_name: ^flag_name, + operation: :disable + } + } + end + + test "emits telemetry event when disabling a flag for a percentage of time", %{ + flag_name: flag_name + } do + ratio = 0.5 + FunWithFlags.enable(flag_name, for_percentage_of: {:time, ratio}) + + result = FunWithFlags.disable(flag_name, for_percentage_of: {:time, ratio}) + + assert result == {:ok, false} + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_percentage_of: {:time, ^ratio}], + result: {:ok, false}, + flag_name: ^flag_name, + operation: :disable + } + } + end + + test "emits telemetry event when disabling a flag for a percentage of actors", %{ + flag_name: flag_name + } do + ratio = 0.5 + FunWithFlags.enable(flag_name, for_percentage_of: {:actors, ratio}) + + result = FunWithFlags.disable(flag_name, for_percentage_of: {:actors, ratio}) + + assert result == {:ok, false} + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_percentage_of: {:actors, ^ratio}], + result: {:ok, false}, + flag_name: ^flag_name, + operation: :disable + } + } + end + end + + describe "clear telemetry" do + setup do + attach_telemetry() + + scrooge = %FunWithFlags.TestUser{ + id: 1, + email: "scrooge@mcduck.pdp", + groups: [:ducks, :billionaires] + } + + donald = %FunWithFlags.TestUser{ + id: 2, + email: "donald@duck.db", + groups: [:ducks, :super_heroes] + } + + flag_name = unique_atom() + {:ok, scrooge: scrooge, donald: donald, flag_name: flag_name} + end + + test "emits telemetry event when clearing a flag globally", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name) + + result = FunWithFlags.clear(flag_name) + + assert result == :ok + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [], + result: :ok, + flag_name: ^flag_name, + operation: :clear + } + } + end + + test "emits telemetry event when clearing a boolean gate", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name) + + result = FunWithFlags.clear(flag_name, boolean: true) + + assert result == :ok + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [boolean: true], + result: :ok, + flag_name: ^flag_name, + operation: :clear + } + } + end + + test "emits telemetry event when clearing a flag for an actor", %{ + flag_name: flag_name, + scrooge: scrooge + } do + FunWithFlags.enable(flag_name, for_actor: scrooge) + + result = FunWithFlags.clear(flag_name, for_actor: scrooge) + + assert result == :ok + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_actor: ^scrooge], + result: :ok, + flag_name: ^flag_name, + operation: :clear + } + } + end + + test "emits telemetry event when clearing a flag for a group", %{flag_name: flag_name} do + group = :billionaires + FunWithFlags.enable(flag_name, for_group: group) + + result = FunWithFlags.clear(flag_name, for_group: group) + + assert result == :ok + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_group: ^group], + result: :ok, + flag_name: ^flag_name, + operation: :clear + } + } + end + + test "emits telemetry event when clearing a percentage gate", %{flag_name: flag_name} do + FunWithFlags.enable(flag_name, for_percentage_of: {:time, 0.5}) + + result = FunWithFlags.clear(flag_name, for_percentage: true) + + assert result == :ok + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_percentage: true], + result: :ok, + flag_name: ^flag_name, + operation: :clear + } + } + end + + test "emits telemetry event when clearing fails globally", %{flag_name: flag_name} do + error_reason = {:error, :test_error} + + with_mock FunWithFlags.Store, [:passthrough], delete: fn _ -> error_reason end do + result = FunWithFlags.clear(flag_name) + + assert result == error_reason + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [], + result: ^error_reason, + flag_name: ^flag_name, + operation: :clear + } + } + end + end + + test "emits telemetry event when clearing fails for an actor", %{ + flag_name: flag_name, + scrooge: scrooge + } do + error_reason = {:error, :test_error} + + with_mock FunWithFlags.Store, [:passthrough], delete: fn _, _ -> error_reason end do + result = FunWithFlags.clear(flag_name, for_actor: scrooge) + + assert result == error_reason + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_actor: ^scrooge], + result: ^error_reason, + flag_name: ^flag_name, + operation: :clear + } + } + end + end + + test "emits telemetry event when clearing fails for a group", %{flag_name: flag_name} do + error_reason = {:error, :test_error} + group = :billionaires + + with_mock FunWithFlags.Store, [:passthrough], delete: fn _, _ -> error_reason end do + result = FunWithFlags.clear(flag_name, for_group: group) + + assert result == error_reason + + assert_receive %{ + measurements: %{duration: _}, + event: [:fun_with_flags, :flag_operation], + metadata: %{ + options: [for_group: ^group], + result: ^error_reason, + flag_name: ^flag_name, + operation: :clear + } + } + end + end + + defp attach_telemetry do + :telemetry.attach_many( + "test-handler", + [ + [:fun_with_flags, :flag_operation] + ], + fn event_name, measurements, metadata, reply_to -> + send(reply_to, %{event: event_name, measurements: measurements, metadata: metadata}) + end, + self() + ) + + on_exit(fn -> + :telemetry.detach("test-handler") + end) + end + end +end