Supervise user agent parsing (#5243)

* Supervise user agent parsing

* Instrument UA parse timeout with a counter

* Test

Author: aerosol

lib/plausible/application.ex

@@ -15,6 +15,7 @@ defmodule Plausible.Application do
 
     children =
       [
+        {Task.Supervisor, name: Plausible.UserAgentParseTaskSupervisor},
         Plausible.Session.BalancerSupervisor,
         Plausible.Cache.Stats,
         Plausible.PromEx,

lib/plausible/ingestion/event.ex

@@ -88,10 +88,21 @@ defmodule Plausible.Ingestion.Event do
     [:plausible, :ingest, :event, :dropped]
   end
 
+  @spec telemetry_pipeline_step_duration() :: [atom()]
   def telemetry_pipeline_step_duration() do
     [:plausible, :ingest, :pipeline, :step]
   end
 
+  @spec telemetry_ua_parse_timeout() :: [atom()]
+  def telemetry_ua_parse_timeout() do
+    [:plausible, :ingest, :user_agent_parse, :timeout]
+  end
+
+  @spec emit_telemetry_ua_parse_timeout() :: :ok
+  def emit_telemetry_ua_parse_timeout() do
+    :telemetry.execute(telemetry_ua_parse_timeout(), %{}, %{})
+  end
+
   @spec emit_telemetry_buffered(t()) :: :ok
   def emit_telemetry_buffered(event) do
     :telemetry.execute(telemetry_event_buffered(), %{}, %{
@@ -238,13 +249,13 @@ defmodule Plausible.Ingestion.Event do
 
   defp put_user_agent(%__MODULE__{} = event, _context) do
     case parse_user_agent(event.request) do
-      %UAInspector.Result{client: %UAInspector.Result.Client{name: "Headless Chrome"}} ->
+      {:ok, %UAInspector.Result{client: %UAInspector.Result.Client{name: "Headless Chrome"}}} ->
         drop(event, :bot)
 
-      %UAInspector.Result.Bot{} ->
+      {:ok, %UAInspector.Result.Bot{}} ->
         drop(event, :bot)
 
-      %UAInspector.Result{} = user_agent ->
+      {:ok, %UAInspector.Result{} = user_agent} ->
         update_session_attrs(event, %{
           operating_system: os_name(user_agent),
           operating_system_version: os_version(user_agent),
@@ -430,14 +441,31 @@ defmodule Plausible.Ingestion.Event do
     |> Enum.find(fn param_name -> Map.has_key?(query_params, param_name) end)
   end
 
+  @parse_user_agent_timeout 200
   defp parse_user_agent(%Request{user_agent: user_agent}) when is_binary(user_agent) do
-    Plausible.Cache.Adapter.get(:user_agents, user_agent, fn ->
-      UAInspector.parse(user_agent)
+    Plausible.Cache.Adapter.fetch(:user_agents, user_agent, fn ->
+      parse_user_agent_safe(user_agent)
     end)
   end
 
   defp parse_user_agent(request), do: request
 
+  defp parse_user_agent_safe(user_agent) do
+    task =
+      Task.Supervisor.async_nolink(Plausible.UserAgentParseTaskSupervisor, fn ->
+        UAInspector.parse(user_agent)
+      end)
+
+    case Task.yield(task, @parse_user_agent_timeout) || Task.shutdown(task) do
+      {:ok, result} ->
+        {:ok, result}
+
+      nil ->
+        emit_telemetry_ua_parse_timeout()
+        {:error, :timeout}
+    end
+  end
+
   defp browser_name(ua) do
     case ua.client do
       :unknown -> ""

lib/plausible/telemetry/plausible_metrics.ex

@@ -74,6 +74,10 @@ defmodule Plausible.PromEx.Plugins.PlausibleMetrics do
           metric_prefix ++ [:ingest, :events, :dropped, :total],
           event_name: Ingestion.Event.telemetry_event_dropped(),
           tags: [:reason]
+        ),
+        counter(
+          metric_prefix ++ [:ingest, :user_agent_parse, :timeout, :total],
+          event_name: Ingestion.Event.telemetry_ua_parse_timeout()
         )
       ]
     )

test/plausible/ingestion/event_test.exs

@@ -45,6 +45,41 @@ defmodule Plausible.Ingestion.EventTest do
     end
   end
 
+  test "times out parsing user agent", %{test: test} do
+    on_exit(:detach, fn ->
+      :telemetry.detach("ua-timeout-#{test}")
+    end)
+
+    test_pid = self()
+    event = Event.telemetry_ua_parse_timeout()
+
+    :telemetry.attach(
+      "ua-timeout-#{test}",
+      event,
+      fn ^event, _, _, _ ->
+        send(test_pid, :telemetry_handled)
+      end,
+      %{}
+    )
+
+    site = new_site()
+
+    payload = %{
+      name: "pageview",
+      url: "http://#{site.domain}"
+    }
+
+    conn =
+      :post
+      |> build_conn("/api/events", payload)
+      |> Plug.Conn.put_req_header("user-agent", :binary.copy("a", 1024 * 8))
+
+    assert {:ok, request} = Request.build(conn)
+
+    assert {:ok, %{buffered: [_], dropped: []}} = Event.build_and_buffer(request)
+    assert_receive :telemetry_handled
+  end
+
   test "drops verification agent" do
     site = new_site()