Fix PR #1749 review follow-ups — fetch/3 :unidentified collapse and log attribution

Two review-driven follow-ups on the preference dispatcher.

Fix 1: fetch/3 now collapses {:error, :unidentified} to :error — matching
the adapter behaviour's "treat as not found" semantics. No warning is
logged for that case because it is the expected path for anonymous
visitors / background jobs. Other {:error, reason} tuples still surface
unchanged, so a genuine adapter failure remains distinguishable.

Fix 2: Every dispatcher-originated Logger.warning now carries the adapter
module in the message — "adapter \#{inspect(module)} returned error on
get/3 ..." — so operators running multi-adapter routing (global.* →
Session, resource.* → EctoAdapter) can tell which backend failed. The
dispatch helpers now return {module, result} tuples so callers can
attribute; identity-resolver warnings say "resolving identity via
\#{resolver}" instead, since no adapter is involved.

Author: Flo0807

lib/backpex/preferences.ex

@@ -81,16 +81,16 @@ defmodule Backpex.Preferences do
     default = Keyword.get(opts, :default)
 
     case dispatch_get(ctx_or_session, key, opts) do
-      {:ok, :not_found} ->
+      {_module, {:ok, :not_found}} ->
         default
 
-      {:ok, value} ->
+      {_module, {:ok, value}} ->
         value
 
-      {:error, reason} ->
+      {module, {:error, reason}} ->
         Logger.warning(
-          "[Backpex.Preferences] adapter returned error on get/3 for key #{inspect(key)}: " <>
-            inspect(reason) <> "; falling back to default"
+          "Backpex.Preferences: adapter #{inspect(module)} returned error on get/3 for key " <>
+            "#{inspect(key)}: #{inspect(reason)}; falling back to default"
         )
 
         default
@@ -110,10 +110,13 @@ defmodule Backpex.Preferences do
 
     * `{:ok, value}` — the adapter returned a stored value.
     * `:error` — the adapter successfully determined nothing is stored
-      (`{:ok, :not_found}` from the adapter).
-    * `{:error, reason}` — the adapter failed (e.g. `:unidentified`, a raised
-      exception swallowed by the dispatcher, or any other adapter-level
-      error). Also logs a warning — same behavior as `get/3`.
+      (`{:ok, :not_found}` from the adapter), **or** the adapter returned
+      `{:error, :unidentified}`. Per the
+      `Backpex.Preferences.Adapter` behaviour, `:unidentified` on reads is
+      defined as "treat as not found" — no warning is logged for that case
+      because it is expected (anonymous visitors, background jobs, etc.).
+    * `{:error, reason}` — any other adapter failure (e.g. a raised
+      exception swallowed by the dispatcher). A warning is also logged.
 
   ## Examples
 
@@ -128,16 +131,23 @@ defmodule Backpex.Preferences do
           {:ok, term()} | :error | {:error, term()}
   def fetch(ctx_or_session, key, opts \\ []) do
     case dispatch_get(ctx_or_session, key, opts) do
-      {:ok, :not_found} ->
+      {_module, {:ok, :not_found}} ->
         :error
 
-      {:ok, value} ->
+      {_module, {:ok, value}} ->
         {:ok, value}
 
-      {:error, reason} = err ->
+      {_module, {:error, :unidentified}} ->
+        # Per the adapter behaviour, `:unidentified` on reads means "treat as
+        # not found" — collapse to `:error` without logging. This matches the
+        # expected path for anonymous visitors / background jobs that have no
+        # resolved identity.
+        :error
+
+      {module, {:error, reason} = err} ->
         Logger.warning(
-          "[Backpex.Preferences] adapter returned error on fetch/3 for key #{inspect(key)}: " <>
-            inspect(reason)
+          "Backpex.Preferences: adapter #{inspect(module)} returned error on fetch/3 for key " <>
+            "#{inspect(key)}: #{inspect(reason)}"
         )
 
         err
@@ -179,8 +189,8 @@ defmodule Backpex.Preferences do
 
       {:error, reason} ->
         Logger.warning(
-          "[Backpex.Preferences] adapter returned error on get_map/3 for prefix " <>
-            inspect(prefix) <> ": " <> inspect(reason) <> "; falling back to %{}"
+          "Backpex.Preferences: adapter #{inspect(module)} returned error on get_map/3 for prefix " <>
+            "#{inspect(prefix)}: #{inspect(reason)}; falling back to %{}"
         )
 
         %{}
@@ -226,13 +236,13 @@ defmodule Backpex.Preferences do
     ctx = conn |> Context.from_conn() |> resolve_identity()
 
     case dispatch_put(ctx, key, value, opts) do
-      {:ok, effects} ->
+      {_module, {:ok, effects}} ->
         {:ok, apply_effects_on_conn(conn, effects)}
 
-      {:error, reason} = err ->
+      {module, {:error, reason} = err} ->
         Logger.warning(
-          "[Backpex.Preferences] adapter refused put/4 for key #{inspect(key)} " <>
-            "on conn origin: " <> inspect(reason)
+          "Backpex.Preferences: adapter #{inspect(module)} refused put/4 for key " <>
+            "#{inspect(key)} on conn origin: #{inspect(reason)}"
         )
 
         err
@@ -246,16 +256,16 @@ defmodule Backpex.Preferences do
       |> resolve_identity()
 
     case dispatch_put(ctx, key, value, opts) do
-      {:ok, effects} ->
-        {:ok, apply_effects_on_socket(socket, key, value, effects)}
+      {module, {:ok, effects}} ->
+        {:ok, apply_effects_on_socket(socket, module, key, value, effects)}
 
-      {:error, :requires_http} ->
+      {_module, {:error, :requires_http}} ->
         {:ok, push_event_fallback(socket, key, value)}
 
-      {:error, reason} = err ->
+      {module, {:error, reason} = err} ->
         Logger.warning(
-          "[Backpex.Preferences] adapter refused put/4 for key #{inspect(key)} " <>
-            "on socket origin: " <> inspect(reason)
+          "Backpex.Preferences: adapter #{inspect(module)} refused put/4 for key " <>
+            "#{inspect(key)} on socket origin: #{inspect(reason)}"
         )
 
         err
@@ -368,28 +378,34 @@ defmodule Backpex.Preferences do
   defp dispatch_get(ctx_or_session, key, opts) do
     ctx = resolve_identity(Context.coerce(ctx_or_session))
     {module, adapter_opts} = Router.resolve(key)
-    module.get(ctx, key, merge_opts(adapter_opts, opts))
-  rescue
-    reason ->
-      Logger.warning(
-        "[Backpex.Preferences] adapter raised in get/3 for key #{inspect(key)}: " <>
-          Exception.format(:error, reason, __STACKTRACE__)
-      )
 
-      {:error, {:exception, reason}}
+    try do
+      {module, module.get(ctx, key, merge_opts(adapter_opts, opts))}
+    rescue
+      reason ->
+        Logger.warning(
+          "Backpex.Preferences: adapter #{inspect(module)} raised in get/3 for key " <>
+            "#{inspect(key)}: #{Exception.format(:error, reason, __STACKTRACE__)}"
+        )
+
+        {module, {:error, {:exception, reason}}}
+    end
   end
 
   defp dispatch_put(%Context{} = ctx, key, value, opts) do
     {module, adapter_opts} = Router.resolve(key)
-    module.put(ctx, key, value, merge_opts(adapter_opts, opts))
-  rescue
-    reason ->
-      Logger.warning(
-        "[Backpex.Preferences] adapter raised in put/4 for key #{inspect(key)}: " <>
-          Exception.format(:error, reason, __STACKTRACE__)
-      )
 
-      {:error, {:exception, reason}}
+    try do
+      {module, module.put(ctx, key, value, merge_opts(adapter_opts, opts))}
+    rescue
+      reason ->
+        Logger.warning(
+          "Backpex.Preferences: adapter #{inspect(module)} raised in put/4 for key " <>
+            "#{inspect(key)}: #{Exception.format(:error, reason, __STACKTRACE__)}"
+        )
+
+        {module, {:error, {:exception, reason}}}
+    end
   end
 
   # Socket-origin put accepted by the adapter: consume the returned side
@@ -400,15 +416,15 @@ defmodule Backpex.Preferences do
   # adapter could still emit it. Rather than silently dropping the write,
   # log a warning and fall back to `push_event/3` so the browser can retry
   # via the preferences controller.
-  defp apply_effects_on_socket(socket, key, value, effects) do
+  defp apply_effects_on_socket(socket, module, key, value, effects) do
     Enum.reduce(effects, socket, fn
       :noop, s ->
         s
 
       {:put_session, _k, _v}, s ->
         Logger.warning(
-          "[Backpex.Preferences] adapter emitted {:put_session, _, _} from a socket origin " <>
-            "for key #{inspect(key)}; routing through push_event fallback. " <>
+          "Backpex.Preferences: adapter #{inspect(module)} emitted {:put_session, _, _} from a " <>
+            "socket origin for key #{inspect(key)}; routing through push_event fallback. " <>
             "Adapters should return :requires_http instead when called outside a controller."
         )
 
@@ -439,16 +455,16 @@ defmodule Backpex.Preferences do
   rescue
     reason ->
       Logger.warning(
-        "[Backpex.Preferences] identity resolver #{inspect(mod)}.#{fun}/#{length(args)} raised: " <>
-          Exception.format(:error, reason, __STACKTRACE__) <> "; falling back to :unidentified"
+        "Backpex.Preferences: resolving identity via #{inspect({mod, fun, length(args)})} raised: " <>
+          "#{Exception.format(:error, reason, __STACKTRACE__)}; falling back to :unidentified"
       )
 
       :unidentified
   catch
     kind, reason ->
       Logger.warning(
-        "[Backpex.Preferences] identity resolver #{inspect(mod)}.#{fun}/#{length(args)} " <>
-          "threw #{inspect(kind)}: " <> inspect(reason) <> "; falling back to :unidentified"
+        "Backpex.Preferences: resolving identity via #{inspect({mod, fun, length(args)})} " <>
+          "threw #{inspect(kind)}: #{inspect(reason)}; falling back to :unidentified"
       )
 
       :unidentified

test/preferences_test.exs

@@ -228,6 +228,22 @@ defmodule Backpex.PreferencesTest do
         assert log =~ "fetch/3"
       end)
     end
+
+    test "collapses {:error, :unidentified} to :error without logging" do
+      # Per Backpex.Preferences.Adapter, `:unidentified` on reads means
+      # "treat as not found" — fetch/3 must return :error (matching the
+      # stored-but-missing case) and must NOT log a warning, because the
+      # condition is expected (anonymous visitors, background jobs, etc.).
+      with_adapters([{:default, Backpex.PreferencesTest.UnidentifiedAdapter, []}], fn ->
+        log =
+          capture_log(fn ->
+            assert Preferences.fetch(%{}, Keys.theme()) == :error
+          end)
+
+        refute log =~ "Backpex.Preferences"
+        refute log =~ ":unidentified"
+      end)
+    end
   end
 
   describe "get/3 logs warnings on adapter error (m6 + M4)" do