From 393caac208b5242eceb1b018441a45db1a8e4e43 Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Wed, 28 Aug 2024 11:02:55 +0200 Subject: [PATCH 1/8] Create a regression demonstration test for race condition --- lib/plausible/session/cache_store.ex | 6 +- test/plausible/session/cache_store_test.exs | 92 +++++++++++++++++++-- 2 files changed, 87 insertions(+), 11 deletions(-) diff --git a/lib/plausible/session/cache_store.ex b/lib/plausible/session/cache_store.ex index d9fa2f9761b1..123fd1a647a5 100644 --- a/lib/plausible/session/cache_store.ex +++ b/lib/plausible/session/cache_store.ex @@ -2,16 +2,16 @@ defmodule Plausible.Session.CacheStore do require Logger alias Plausible.Session.WriteBuffer - def on_event(event, session_attributes, prev_user_id, buffer \\ WriteBuffer) do + def on_event(event, session_attributes, prev_user_id, buffer_insert \\ &WriteBuffer.insert/1) do found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) if found_session do updated_session = update_session(found_session, event) - buffer.insert([%{found_session | sign: -1}, %{updated_session | sign: 1}]) + buffer_insert.([%{found_session | sign: -1}, %{updated_session | sign: 1}]) persist_session(updated_session) else new_session = new_session_from_event(event, session_attributes) - buffer.insert([new_session]) + buffer_insert.([new_session]) persist_session(new_session) end end diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index 58fd5f32c523..51eec550253c 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -2,15 +2,91 @@ defmodule Plausible.Session.CacheStoreTest do use Plausible.DataCase alias Plausible.Session.CacheStore - defmodule FakeBuffer do - def insert(sessions) do - send(self(), {WriteBuffer, :insert, [sessions]}) + setup do + current_pid = self() + + buffer = fn sessions -> + send(current_pid, {:buffer, :insert, [sessions]}) + {:ok, sessions} + end + + slow_buffer = fn sessions -> + Process.sleep(200) + send(current_pid, {:slow_buffer, :insert, [sessions]}) {:ok, sessions} end + + [buffer: buffer, slow_buffer: slow_buffer] end - setup do - [buffer: FakeBuffer] + test "event processing is sequential within session", %{ + buffer: buffer, + slow_buffer: slow_buffer + } do + event1 = build(:event, name: "pageview") + event2 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) + event3 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) + + session_params = %{ + referrer: "ref", + referrer_source: "refsource", + utm_medium: "medium", + utm_source: "source", + utm_campaign: "campaign", + utm_content: "content", + utm_term: "term", + browser: "browser", + browser_version: "55", + country_code: "EE", + screen_size: "Desktop", + operating_system: "Mac", + operating_system_version: "11" + } + + CacheStore.on_event(event1, session_params, nil, buffer) + + assert_receive({:buffer, :insert, [[session1]]}) + + [event2, event3] + |> Enum.map(fn e -> + Task.async(fn -> + CacheStore.on_event(e, session_params, nil, slow_buffer) + end) + end) + |> Task.await_many() + + assert_receive({:slow_buffer, :insert, [[removed_session11, updated_session12]]}) + assert_receive({:slow_buffer, :insert, [[removed_session12, updated_session13]]}) + + # event2 and event3 both get executed in parallel and treat event1 as + # event to be updated. This results in a following set of entries + # in Clickhouse sessions table for _the same_ session: + # + # session_id | is_bounce | sign + # (event1) 123 1 1 + # (event2) 123 1 -1 + # 123 0 1 + # (event3) 123 1 -1 + # 123 0 1 + # + # Once collapsing merge tree table does collapsing, we end up with: + # + # session_id | is_bounce | sign + # 123 0 1 + # 123 1 -1 + # 123 0 1 + # + # This leads to sum(sign * is_bounce) < 0 which, after underflowed casting, ends up + # with 2^32-(small n) for bounce_rate value. + + assert removed_session11 == %{session1 | sign: -1} + assert removed_session12 == %{session1 | sign: -1} + assert updated_session12.sign == 1 + assert updated_session12.events == 2 + assert updated_session12.pageviews == 2 + assert updated_session13.sign == 1 + assert updated_session13.events == 2 + assert updated_session13.pageviews == 2 end test "creates a session from an event", %{buffer: buffer} do @@ -39,7 +115,7 @@ defmodule Plausible.Session.CacheStoreTest do CacheStore.on_event(event, session_params, nil, buffer) - assert_receive({WriteBuffer, :insert, [sessions]}) + assert_receive({:buffer, :insert, [sessions]}) assert [session] = sessions assert session.hostname == event.hostname @@ -82,7 +158,7 @@ defmodule Plausible.Session.CacheStoreTest do CacheStore.on_event(event1, %{}, nil, buffer) CacheStore.on_event(event2, %{}, nil, buffer) - assert_receive({WriteBuffer, :insert, [[_negative_record, session]]}) + assert_receive({:buffer, :insert, [[_negative_record, session]]}) assert session.is_bounce == false assert session.duration == 10 assert session.pageviews == 2 @@ -286,7 +362,7 @@ defmodule Plausible.Session.CacheStoreTest do CacheStore.on_event(event1, %{}, nil, buffer) CacheStore.on_event(event2, %{}, nil, buffer) - assert_receive({WriteBuffer, :insert, [[_negative_record, session]]}) + assert_receive({:buffer, :insert, [[_negative_record, session]]}) assert session.duration == 10 end From 9f8ecc1f44bfa0bd3d38c888e43c1c51e0b020cc Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Wed, 28 Aug 2024 11:51:16 +0200 Subject: [PATCH 2/8] Use `ConCache.isolated/1` to force sequential processing of session events --- lib/plausible/session/cache_store.ex | 22 +++++++++++---------- test/plausible/session/cache_store_test.exs | 6 +++--- 2 files changed, 15 insertions(+), 13 deletions(-) diff --git a/lib/plausible/session/cache_store.ex b/lib/plausible/session/cache_store.ex index 123fd1a647a5..b05ce8de4b80 100644 --- a/lib/plausible/session/cache_store.ex +++ b/lib/plausible/session/cache_store.ex @@ -3,17 +3,19 @@ defmodule Plausible.Session.CacheStore do alias Plausible.Session.WriteBuffer def on_event(event, session_attributes, prev_user_id, buffer_insert \\ &WriteBuffer.insert/1) do - found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) + ConCache.isolated(:sessions, {event.site_id, event.user_id}, fn -> + found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) - if found_session do - updated_session = update_session(found_session, event) - buffer_insert.([%{found_session | sign: -1}, %{updated_session | sign: 1}]) - persist_session(updated_session) - else - new_session = new_session_from_event(event, session_attributes) - buffer_insert.([new_session]) - persist_session(new_session) - end + if found_session do + updated_session = update_session(found_session, event) + buffer_insert.([%{found_session | sign: -1}, %{updated_session | sign: 1}]) + persist_session(updated_session) + else + new_session = new_session_from_event(event, session_attributes) + buffer_insert.([new_session]) + persist_session(new_session) + end + end) end defp find_session(_domain, nil), do: nil diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index 51eec550253c..c9018ed9bbc3 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -80,13 +80,13 @@ defmodule Plausible.Session.CacheStoreTest do # with 2^32-(small n) for bounce_rate value. assert removed_session11 == %{session1 | sign: -1} - assert removed_session12 == %{session1 | sign: -1} assert updated_session12.sign == 1 assert updated_session12.events == 2 assert updated_session12.pageviews == 2 + assert removed_session12 == %{updated_session12 | sign: -1} assert updated_session13.sign == 1 - assert updated_session13.events == 2 - assert updated_session13.pageviews == 2 + assert updated_session13.events == 3 + assert updated_session13.pageviews == 3 end test "creates a session from an event", %{buffer: buffer} do From d9fc2320d7bf25928edaa513e3c6a100c0f1d747 Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Wed, 28 Aug 2024 11:54:05 +0200 Subject: [PATCH 3/8] Revise comment in regression test --- test/plausible/session/cache_store_test.exs | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index c9018ed9bbc3..a609cfba207e 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -58,9 +58,11 @@ defmodule Plausible.Session.CacheStoreTest do assert_receive({:slow_buffer, :insert, [[removed_session11, updated_session12]]}) assert_receive({:slow_buffer, :insert, [[removed_session12, updated_session13]]}) - # event2 and event3 both get executed in parallel and treat event1 as - # event to be updated. This results in a following set of entries - # in Clickhouse sessions table for _the same_ session: + # Without isolation enforced in `CacheStore.on_event/4`, + # event2 and event3 would both get executed in parallel + # and treat event1 as event to be updated. This would result + # in a following set of entries in Clickhouse sessions + # table for _the same_ session: # # session_id | is_bounce | sign # (event1) 123 1 1 @@ -69,15 +71,15 @@ defmodule Plausible.Session.CacheStoreTest do # (event3) 123 1 -1 # 123 0 1 # - # Once collapsing merge tree table does collapsing, we end up with: + # Once collapsing merge tree table does collapsing, we'd end up with: # # session_id | is_bounce | sign # 123 0 1 # 123 1 -1 # 123 0 1 # - # This leads to sum(sign * is_bounce) < 0 which, after underflowed casting, ends up - # with 2^32-(small n) for bounce_rate value. + # This in turn led to sum(sign * is_bounce) < 0 which, after underflowed casting, + # ended up with 2^32-(small n) for bounce_rate value. assert removed_session11 == %{session1 | sign: -1} assert updated_session12.sign == 1 From 58cd58645819431418965e50fd7b31adf21cf13d Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Fri, 30 Aug 2024 10:18:59 +0200 Subject: [PATCH 4/8] Put lock call behind cache adapter API --- lib/plausible/cache/adapter.ex | 5 +++++ lib/plausible/session/cache_store.ex | 29 +++++++++++++++++----------- 2 files changed, 23 insertions(+), 11 deletions(-) diff --git a/lib/plausible/cache/adapter.ex b/lib/plausible/cache/adapter.ex index 65f8c254c4d0..70e9d3602572 100644 --- a/lib/plausible/cache/adapter.ex +++ b/lib/plausible/cache/adapter.ex @@ -107,4 +107,9 @@ defmodule Plausible.Cache.Adapter do Logger.error("Error retrieving key from '#{inspect(cache_name)}'") [] end + + @spec with_lock!(atom(), any(), pos_integer(), (-> result)) :: result when result: any() + def with_lock!(cache_name, key, timeout, fun) do + ConCache.isolated(cache_name, key, timeout, fun) + end end diff --git a/lib/plausible/session/cache_store.ex b/lib/plausible/session/cache_store.ex index b05ce8de4b80..0ef54cd59530 100644 --- a/lib/plausible/session/cache_store.ex +++ b/lib/plausible/session/cache_store.ex @@ -2,20 +2,27 @@ defmodule Plausible.Session.CacheStore do require Logger alias Plausible.Session.WriteBuffer + @lock_timeout 500 + def on_event(event, session_attributes, prev_user_id, buffer_insert \\ &WriteBuffer.insert/1) do - ConCache.isolated(:sessions, {event.site_id, event.user_id}, fn -> - found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) + Plausible.Cache.Adapter.with_lock!( + :sessions, + {event.site_id, event.user_id}, + @lock_timeout, + fn -> + found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) - if found_session do - updated_session = update_session(found_session, event) - buffer_insert.([%{found_session | sign: -1}, %{updated_session | sign: 1}]) - persist_session(updated_session) - else - new_session = new_session_from_event(event, session_attributes) - buffer_insert.([new_session]) - persist_session(new_session) + if found_session do + updated_session = update_session(found_session, event) + buffer_insert.([%{found_session | sign: -1}, %{updated_session | sign: 1}]) + persist_session(updated_session) + else + new_session = new_session_from_event(event, session_attributes) + buffer_insert.([new_session]) + persist_session(new_session) + end end - end) + ) end defp find_session(_domain, nil), do: nil From 4ebd31a099bf355da0c8922205b36890b2505b63 Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Fri, 30 Aug 2024 12:46:12 +0200 Subject: [PATCH 5/8] Add more explicit handling of failing lock NOTE: Apparent double execution of lock function needs to be investigated. --- lib/plausible/cache/adapter.ex | 3 + test/plausible/session/cache_store_test.exs | 87 +++++++++++++++++++++ 2 files changed, 90 insertions(+) diff --git a/lib/plausible/cache/adapter.ex b/lib/plausible/cache/adapter.ex index 70e9d3602572..728142d7534d 100644 --- a/lib/plausible/cache/adapter.ex +++ b/lib/plausible/cache/adapter.ex @@ -111,5 +111,8 @@ defmodule Plausible.Cache.Adapter do @spec with_lock!(atom(), any(), pos_integer(), (-> result)) :: result when result: any() def with_lock!(cache_name, key, timeout, fun) do ConCache.isolated(cache_name, key, timeout, fun) + catch + :exit, {:timeout, _} -> + Logger.error("Timeout while executing with lock on key in '#{inspect(cache_name)}'") end end diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index a609cfba207e..50a6bdabbc1c 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -1,5 +1,8 @@ defmodule Plausible.Session.CacheStoreTest do use Plausible.DataCase + + import ExUnit.CaptureLog + alias Plausible.Session.CacheStore setup do @@ -91,6 +94,90 @@ defmodule Plausible.Session.CacheStoreTest do assert updated_session13.pageviews == 3 end + @tag :slow + test "in case of lock kicking in, the slow event finishes processing", %{buffer: buffer} do + # FIXME: for some reason sometimes `very_slow_buffer` is called twice, + # as if there was some implicit retry? Happens once per multiple runs + # of this test. + current_pid = self() + + very_slow_buffer = fn sessions -> + Process.sleep(1000) + send(current_pid, {:very_slow_buffer, :insert, [sessions]}) + {:ok, sessions} + end + + event1 = build(:event, name: "pageview") + event2 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) + event3 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) + + session_params = %{ + referrer: "ref", + referrer_source: "refsource", + utm_medium: "medium", + utm_source: "source", + utm_campaign: "campaign", + utm_content: "content", + utm_term: "term", + browser: "browser", + browser_version: "55", + country_code: "EE", + screen_size: "Desktop", + operating_system: "Mac", + operating_system_version: "11" + } + + async1 = + Task.async(fn -> + CacheStore.on_event(event1, session_params, nil, very_slow_buffer) + end) + + async2 = + Task.async(fn -> + CacheStore.on_event(event2, session_params, nil, buffer) + end) + + async3 = + Task.async(fn -> + CacheStore.on_event(event3, session_params, nil, buffer) + end) + + capture_log(fn -> + Task.await_many([async1, async2, async3]) + end) =~ "Timeout while executing with lock on key in ':sessions'" + + assert_receive({:very_slow_buffer, :insert, [[_session]]}) + refute_receive({:buffer, :insert, [[_updated_session]]}) + end + + test "exploding event processing is passed through by locking mechanism" do + crashing_buffer = fn _sessions -> + raise "boom" + end + + event = build(:event, name: "pageview") + + session_params = %{ + referrer: "ref", + referrer_source: "refsource", + utm_medium: "medium", + utm_source: "source", + utm_campaign: "campaign", + utm_term: "term", + utm_content: "content", + browser: "browser", + browser_version: "55", + country_code: "EE", + screen_size: "Desktop", + operating_system: "Mac", + operating_system_version: "11" + } + + assert_raise RuntimeError, "boom", fn -> + CacheStore.on_event(event, session_params, nil, crashing_buffer) + end + end + test "creates a session from an event", %{buffer: buffer} do event = build(:event, From d8b96df19c8b9f80452159cc38f53e302600a854 Mon Sep 17 00:00:00 2001 From: Adrian Gruntkowski Date: Sat, 31 Aug 2024 11:41:38 +0200 Subject: [PATCH 6/8] Improve slow lock cases tests --- test/plausible/session/cache_store_test.exs | 68 ++++++++++++++++++++- 1 file changed, 65 insertions(+), 3 deletions(-) diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index 50a6bdabbc1c..a788a36c6256 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -96,9 +96,6 @@ defmodule Plausible.Session.CacheStoreTest do @tag :slow test "in case of lock kicking in, the slow event finishes processing", %{buffer: buffer} do - # FIXME: for some reason sometimes `very_slow_buffer` is called twice, - # as if there was some implicit retry? Happens once per multiple runs - # of this test. current_pid = self() very_slow_buffer = fn sessions -> @@ -132,6 +129,9 @@ defmodule Plausible.Session.CacheStoreTest do CacheStore.on_event(event1, session_params, nil, very_slow_buffer) end) + # Ensure next events are executed after processing event1 starts + Process.sleep(100) + async2 = Task.async(fn -> CacheStore.on_event(event2, session_params, nil, buffer) @@ -150,6 +150,68 @@ defmodule Plausible.Session.CacheStoreTest do refute_receive({:buffer, :insert, [[_updated_session]]}) end + @tag :slow + test "lock on slow processing of one event does not affect unrelated events", %{buffer: buffer} do + current_pid = self() + + very_slow_buffer = fn sessions -> + Process.sleep(1000) + send(current_pid, {:very_slow_buffer, :insert, [sessions]}) + {:ok, sessions} + end + + event1 = build(:event, name: "pageview") + event2 = build(:event, name: "pageview") + event3 = build(:event, name: "pageview", user_id: event2.user_id, site_id: event2.site_id) + + session_params = %{ + referrer: "ref", + referrer_source: "refsource", + utm_medium: "medium", + utm_source: "source", + utm_campaign: "campaign", + utm_content: "content", + utm_term: "term", + browser: "browser", + browser_version: "55", + country_code: "EE", + screen_size: "Desktop", + operating_system: "Mac", + operating_system_version: "11" + } + + async1 = + Task.async(fn -> + CacheStore.on_event(event1, session_params, nil, very_slow_buffer) + end) + + # Ensure next events are executed after processing event1 starts + Process.sleep(100) + + async2 = + Task.async(fn -> + CacheStore.on_event(event2, session_params, nil, buffer) + end) + + Process.sleep(100) + + async3 = + Task.async(fn -> + CacheStore.on_event(event3, session_params, nil, buffer) + end) + + Task.await_many([async1, async2, async3]) + + assert_receive({:very_slow_buffer, :insert, [[_slow_session]]}) + assert_receive({:buffer, :insert, [[new_session1]]}) + assert_receive({:buffer, :insert, [[removed_session1, updated_session1]]}) + assert new_session1.sign == 1 + assert removed_session1.session_id == new_session1.session_id + assert removed_session1.sign == -1 + assert updated_session1.session_id == removed_session1.session_id + assert updated_session1.sign == 1 + end + test "exploding event processing is passed through by locking mechanism" do crashing_buffer = fn _sessions -> raise "boom" From 126d18c4b0242811aa22c54a6c9527b85f054c5d Mon Sep 17 00:00:00 2001 From: Adam Rutkowski Date: Mon, 2 Sep 2024 14:23:11 +0200 Subject: [PATCH 7/8] Reduce number of session cache locks and instrument them w/ telemetry --- lib/plausible/cache/adapter.ex | 8 ++++++-- lib/plausible/session/cache_store.ex | 10 +++++++++- lib/plausible/telemetry/plausible_metrics.ex | 9 +++++++++ test/plausible/session/cache_store_test.exs | 16 +++++++++++++++- 4 files changed, 39 insertions(+), 4 deletions(-) diff --git a/lib/plausible/cache/adapter.ex b/lib/plausible/cache/adapter.ex index 728142d7534d..5e821c4cf079 100644 --- a/lib/plausible/cache/adapter.ex +++ b/lib/plausible/cache/adapter.ex @@ -62,8 +62,12 @@ defmodule Plausible.Cache.Adapter do end @spec put(atom(), any(), any()) :: any() - def put(cache_name, key, value) do - :ok = ConCache.put(cache_name, key, value) + def put(cache_name, key, value, opts \\ []) do + if opts[:dirty?] do + :ok = ConCache.dirty_put(cache_name, key, value) + else + :ok = ConCache.put(cache_name, key, value) + end value catch :exit, _ -> diff --git a/lib/plausible/session/cache_store.ex b/lib/plausible/session/cache_store.ex index 0ef54cd59530..51bbe858a3be 100644 --- a/lib/plausible/session/cache_store.ex +++ b/lib/plausible/session/cache_store.ex @@ -4,12 +4,20 @@ defmodule Plausible.Session.CacheStore do @lock_timeout 500 + @lock_telemetry_event [:plausible, :sessions, :cache, :lock] + + def lock_telemetry_event, do: @lock_telemetry_event + def on_event(event, session_attributes, prev_user_id, buffer_insert \\ &WriteBuffer.insert/1) do + lock_requested_at = System.monotonic_time() + Plausible.Cache.Adapter.with_lock!( :sessions, {event.site_id, event.user_id}, @lock_timeout, fn -> + lock_duration = System.monotonic_time() - lock_requested_at + :telemetry.execute(@lock_telemetry_event, %{duration: lock_duration}, %{}) found_session = find_session(event, event.user_id) || find_session(event, prev_user_id) if found_session do @@ -43,7 +51,7 @@ defmodule Plausible.Session.CacheStore do defp persist_session(session) do key = {session.site_id, session.user_id} - Plausible.Cache.Adapter.put(:sessions, key, session) + Plausible.Cache.Adapter.put(:sessions, key, session, dirty?: true) end defp update_session(session, event) do diff --git a/lib/plausible/telemetry/plausible_metrics.ex b/lib/plausible/telemetry/plausible_metrics.ex index 17e24e33717f..b6f836b2f79a 100644 --- a/lib/plausible/telemetry/plausible_metrics.ex +++ b/lib/plausible/telemetry/plausible_metrics.ex @@ -57,6 +57,15 @@ defmodule Plausible.PromEx.Plugins.PlausibleMetrics do measurement: :duration, tags: [:step] ), + distribution( + metric_prefix ++ [:sessions, :cache, :register, :lock], + event_name: Plausible.Session.CacheStore.lock_telemetry_event(), + reporter_options: [ + buckets: [10, 50, 100, 250, 350, 500, 1000, 5000, 10_000, 100_000, 500_000] + ], + unit: {:native, :microsecond}, + measurement: :duration + ), counter( metric_prefix ++ [:ingest, :events, :buffered, :total], event_name: Ingestion.Event.telemetry_event_buffered() diff --git a/test/plausible/session/cache_store_test.exs b/test/plausible/session/cache_store_test.exs index a788a36c6256..b3423e84c15b 100644 --- a/test/plausible/session/cache_store_test.exs +++ b/test/plausible/session/cache_store_test.exs @@ -24,8 +24,20 @@ defmodule Plausible.Session.CacheStoreTest do test "event processing is sequential within session", %{ buffer: buffer, - slow_buffer: slow_buffer + slow_buffer: slow_buffer, + test: test } do + telemetry_event = CacheStore.lock_telemetry_event() + + :telemetry.attach( + "#{test}-telemetry-handler", + telemetry_event, + fn ^telemetry_event, %{duration: d}, _, _ when is_integer(d) -> + send(self(), {:telemetry_handled, d}) + end, + %{} + ) + event1 = build(:event, name: "pageview") event2 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) event3 = build(:event, name: "pageview", user_id: event1.user_id, site_id: event1.site_id) @@ -49,6 +61,8 @@ defmodule Plausible.Session.CacheStoreTest do CacheStore.on_event(event1, session_params, nil, buffer) assert_receive({:buffer, :insert, [[session1]]}) + assert_receive({:telemetry_handled, duration}) + assert is_integer(duration) [event2, event3] |> Enum.map(fn e -> From 7448a299febf992b6f8e851a923339717825cdd9 Mon Sep 17 00:00:00 2001 From: Adam Rutkowski Date: Mon, 2 Sep 2024 15:27:34 +0200 Subject: [PATCH 8/8] Format --- lib/plausible/cache/adapter.ex | 1 + 1 file changed, 1 insertion(+) diff --git a/lib/plausible/cache/adapter.ex b/lib/plausible/cache/adapter.ex index 5e821c4cf079..ae7937580774 100644 --- a/lib/plausible/cache/adapter.ex +++ b/lib/plausible/cache/adapter.ex @@ -68,6 +68,7 @@ defmodule Plausible.Cache.Adapter do else :ok = ConCache.put(cache_name, key, value) end + value catch :exit, _ ->