diff --git a/lib/pleroma/workers/signature_retry_worker.ex b/lib/pleroma/workers/signature_retry_worker.ex index 56673a514..2c4c097dd 100644 --- a/lib/pleroma/workers/signature_retry_worker.ex +++ b/lib/pleroma/workers/signature_retry_worker.ex @@ -10,6 +10,8 @@ defmodule Pleroma.Workers.SignatureRetryWorker do alias Pleroma.Web.Federator alias Pleroma.Web.Plugs.MappedSignatureToIdentityPlug + require Logger + use Oban.Worker, queue: :federator_incoming, max_attempts: 5, unique: [period: :infinity] @impl true @@ -25,37 +27,55 @@ defmodule Pleroma.Workers.SignatureRetryWorker do }) when is_binary(method) and is_map(params) and is_list(req_headers) and is_binary(request_path) and is_binary(query_string) do - with {:ok, req_headers} <- normalize_req_headers(req_headers), - conn_data = %Plug.Conn{ - assigns: %{valid_signature: true}, - method: method, - params: params, - req_headers: req_headers, - request_path: request_path, - query_string: query_string - }, - actor_id = Utils.get_ap_id(params["actor"]), - {:signature_actor, {:ok, signature_actor_id}} <- - {:signature_actor, signature_actor_id(conn_data)}, - {:same_actor, true} <- {:same_actor, signature_actor_id == actor_id}, - {:ok, %User{}} <- User.get_or_fetch_by_ap_id(actor_id), - {:ok, _public_key} <- Signature.refetch_public_key(conn_data), - {:signature, true} <- {:signature, validate_signature(conn_data)}, - {:same_actor, true} <- {:same_actor, validate_same_actor(conn_data)}, - {:ok, res} <- Federator.perform(:incoming_ap_doc, params) do - unless Instances.reachable?(params["actor"]) do - domain = URI.parse(params["actor"]).host - Oban.insert(Pleroma.Workers.ReachabilityWorker.new(%{"domain" => domain})) - end + case normalize_req_headers(req_headers) do + {:ok, req_headers} -> + conn_data = %Plug.Conn{ + assigns: %{valid_signature: true}, + method: method, + params: params, + req_headers: req_headers, + request_path: request_path, + query_string: query_string + } - {:ok, res} - else - e -> process_errors(e) + signature_actor_result = signature_actor_id(conn_data) + + with actor_id = Utils.get_ap_id(params["actor"]), + {:signature_actor, {:ok, signature_actor_id}} <- + {:signature_actor, signature_actor_result}, + {:same_actor, true} <- {:same_actor, signature_actor_id == actor_id}, + {:ok, %User{}} <- User.get_or_fetch_by_ap_id(actor_id), + {:ok, _public_key} <- Signature.refetch_public_key(conn_data), + {:signature, true} <- {:signature, validate_signature(conn_data)}, + {:same_actor, true} <- {:same_actor, validate_same_actor(conn_data)}, + {:ok, res} <- Federator.perform(:incoming_ap_doc, params) do + unless Instances.reachable?(params["actor"]) do + domain = URI.parse(params["actor"]).host + Oban.insert(Pleroma.Workers.ReachabilityWorker.new(%{"domain" => domain})) + end + + {:ok, res} + else + e -> process_errors(e, retry_log_context(params, request_path, signature_actor_result)) + end + + e -> + process_errors(e, retry_log_context(params, request_path, nil)) end end - def perform(%Job{args: %{"op" => "incoming_failed_signature_ap_doc"}}) do - process_errors(:missing_signature_retry_metadata) + def perform(%Job{args: %{"op" => "incoming_failed_signature_ap_doc"} = args}) do + process_errors( + :missing_signature_retry_metadata, + retry_log_context(Map.get(args, "params"), Map.get(args, "request_path"), nil) + ) + end + + def perform(%Job{args: args}) when is_map(args) do + process_errors( + :missing_signature_retry_metadata, + retry_log_context(Map.get(args, "params"), Map.get(args, "request_path"), nil) + ) end def perform(%Job{}), do: process_errors(:missing_signature_retry_metadata) @@ -109,36 +129,126 @@ defmodule Pleroma.Workers.SignatureRetryWorker do _, _ -> {:error, :invalid_signature} end - defp process_errors({:error, {:error, _} = error}), do: process_errors(error) + defp process_errors(errors, context \\ %{}) - defp process_errors(errors) do - case errors do - # User fetch failures - {:error, :not_found} = reason -> {:cancel, reason} - {:error, :forbidden} = reason -> {:cancel, reason} - # Inactive user - {:error, {:user_active, false} = reason} -> {:cancel, reason} - # Validator will error and return a changeset error - # e.g., duplicate activities or if the object was deleted - {:error, {:validate, {:error, _changeset} = reason}} -> {:cancel, reason} - # Duplicate detection during Normalization - {:error, :already_present} -> {:cancel, :already_present} - # MRFs will return a reject - {:error, {:reject, _} = reason} -> {:cancel, reason} - # HTTP Sigs - {:signature_actor, {:error, _}} -> {:cancel, :invalid_signature} - {:signature, false} -> {:cancel, :invalid_signature} - {:same_actor, false} -> {:cancel, :actor_signature_mismatch} - # Origin / URL validation failed somewhere possibly due to spoofing - {:error, :origin_containment_failed} -> {:cancel, :origin_containment_failed} - # Unclear if this can be reached - {:error, {:side_effects, {:error, :no_object_actor}} = reason} -> {:cancel, reason} - # Fail closed if the retry cannot reconstruct the original request. - :missing_signature_retry_metadata -> {:cancel, :missing_signature_retry_metadata} - {:error, :invalid_signature_retry_metadata} -> {:cancel, :invalid_signature_retry_metadata} - # Catchall - {:error, _} = e -> e - e -> {:error, e} - end + defp process_errors({:error, {:error, _} = error}, context), do: process_errors(error, context) + + defp process_errors(errors, context) do + result = + case errors do + # User fetch failures + {:error, :not_found} = reason -> + {:cancel, reason} + + {:error, :forbidden} = reason -> + {:cancel, reason} + + # Inactive user + {:error, {:user_active, false} = reason} -> + {:cancel, reason} + + # Validator will error and return a changeset error + # e.g., duplicate activities or if the object was deleted + {:error, {:validate, {:error, _changeset} = reason}} -> + {:cancel, reason} + + # Duplicate detection during Normalization + {:error, :already_present} -> + {:cancel, :already_present} + + # MRFs will return a reject + {:error, {:reject, _} = reason} -> + {:cancel, reason} + + # HTTP Sigs + {:signature_actor, {:error, _}} -> + {:cancel, :invalid_signature} + + {:signature, false} -> + {:cancel, :invalid_signature} + + {:same_actor, false} -> + {:cancel, :actor_signature_mismatch} + + # Origin / URL validation failed somewhere possibly due to spoofing + {:error, :origin_containment_failed} -> + {:cancel, :origin_containment_failed} + + # Unclear if this can be reached + {:error, {:side_effects, {:error, :no_object_actor}} = reason} -> + {:cancel, reason} + + # Fail closed if the retry cannot reconstruct the original request. + :missing_signature_retry_metadata -> + {:cancel, :missing_signature_retry_metadata} + + {:error, :invalid_signature_retry_metadata} -> + {:cancel, :invalid_signature_retry_metadata} + + # Catchall + {:error, _} = e -> + e + + e -> + {:error, e} + end + + log_signature_retry_rejection(result, context) + result end + + defp retry_log_context(params, request_path, signature_actor_result) when is_map(params) do + signature_actor = + case signature_actor_result do + {:ok, actor} when is_binary(actor) -> actor + actor when is_binary(actor) -> actor + _ -> nil + end + + %{ + activity_id: params["id"], + payload_actor: Utils.get_ap_id(params["actor"]), + request_path: request_path, + signature_actor: signature_actor, + type: params["type"] + } + end + + defp retry_log_context(_params, request_path, signature_actor_result) do + signature_actor = + case signature_actor_result do + {:ok, actor} when is_binary(actor) -> actor + actor when is_binary(actor) -> actor + _ -> nil + end + + %{ + activity_id: nil, + payload_actor: nil, + request_path: request_path, + signature_actor: signature_actor, + type: nil + } + end + + defp log_signature_retry_rejection({:cancel, reason}, context) + when reason in [ + :actor_signature_mismatch, + :invalid_signature, + :invalid_signature_retry_metadata, + :missing_signature_retry_metadata, + :origin_containment_failed + ] do + Logger.warning( + "Failed-signature inbox retry rejected " <> + "reason=#{inspect(reason)} " <> + "payload_actor=#{inspect(context[:payload_actor])} " <> + "signature_actor=#{inspect(context[:signature_actor])} " <> + "activity_id=#{inspect(context[:activity_id])} " <> + "type=#{inspect(context[:type])} " <> + "request_path=#{inspect(context[:request_path])}" + ) + end + + defp log_signature_retry_rejection(_result, _context), do: :ok end diff --git a/test/pleroma/workers/signature_retry_worker_test.exs b/test/pleroma/workers/signature_retry_worker_test.exs index 02706ebad..f4ec0e2e3 100644 --- a/test/pleroma/workers/signature_retry_worker_test.exs +++ b/test/pleroma/workers/signature_retry_worker_test.exs @@ -6,8 +6,11 @@ defmodule Pleroma.Workers.SignatureRetryWorkerTest do use Pleroma.DataCase, async: false use Oban.Testing, repo: Pleroma.Repo + import ExUnit.CaptureLog import Pleroma.Factory + @moduletag capture_log: true + alias Pleroma.Activity alias Pleroma.Object alias Pleroma.Signature @@ -73,7 +76,9 @@ defmodule Pleroma.Workers.SignatureRetryWorkerTest do defp assert_mismatched_signature_cancelled(params, signer) do assert {:ok, oban_job} = enqueue_failed_signature(params, signer) - assert {:cancel, :actor_signature_mismatch} = SignatureRetryWorker.perform(oban_job) + capture_log([level: :warning], fn -> + assert {:cancel, :actor_signature_mismatch} = SignatureRetryWorker.perform(oban_job) + end) end test "Federator preserves request metadata for failed-signature retry jobs" do @@ -108,25 +113,54 @@ defmodule Pleroma.Workers.SignatureRetryWorkerTest do test "cancels retry jobs without request metadata" do params = insert(:note_activity).data - assert {:cancel, :missing_signature_retry_metadata} = - SignatureRetryWorker.perform(%Oban.Job{ - args: %{"op" => "incoming_failed_signature_ap_doc", "params" => params} - }) + log = + capture_log([level: :warning], fn -> + assert {:cancel, :missing_signature_retry_metadata} = + SignatureRetryWorker.perform(%Oban.Job{ + args: %{"op" => "incoming_failed_signature_ap_doc", "params" => params} + }) + end) + + assert log =~ "Failed-signature inbox retry rejected" + assert log =~ "reason=:missing_signature_retry_metadata" + assert log =~ "payload_actor=#{inspect(params["actor"])}" + assert log =~ "activity_id=#{inspect(params["id"])}" + assert log =~ "type=#{inspect(params["type"])}" + assert log =~ "request_path=nil" end test "cancels retry jobs with malformed serialized request headers" do params = insert(:note_activity).data - assert {:cancel, :invalid_signature_retry_metadata} = - SignatureRetryWorker.perform(failed_signature_job(params, [["signature"]])) + log = + capture_log([level: :warning], fn -> + assert {:cancel, :invalid_signature_retry_metadata} = + SignatureRetryWorker.perform(failed_signature_job(params, [["signature"]])) + end) + + assert log =~ "Failed-signature inbox retry rejected" + assert log =~ "reason=:invalid_signature_retry_metadata" + assert log =~ "signature_actor=nil" + assert log =~ "request_path=\"/inbox\"" end test "cancels retry jobs without a signature header" do alice = insert(:user, local: false, ap_id: "https://one.com/users/alice") params = insert(:note_activity, user: alice).data - assert {:cancel, :invalid_signature} = - SignatureRetryWorker.perform(failed_signature_job(params, [{"host", "local.test"}])) + log = + capture_log([level: :warning], fn -> + assert {:cancel, :invalid_signature} = + SignatureRetryWorker.perform( + failed_signature_job(params, [{"host", "local.test"}]) + ) + end) + + assert log =~ "Failed-signature inbox retry rejected" + assert log =~ "reason=:invalid_signature" + assert log =~ "payload_actor=#{inspect(params["actor"])}" + assert log =~ "signature_actor=nil" + assert log =~ "request_path=\"/inbox\"" end test "cancels missing signature before fetching an unavailable payload actor" do @@ -194,7 +228,20 @@ defmodule Pleroma.Workers.SignatureRetryWorkerTest do stub_actor_fetch(alice) assert {:ok, oban_job} = enqueue_failed_signature(create, alice) - assert {:cancel, :invalid_signature} = SignatureRetryWorker.perform(oban_job) + + log = + capture_log([level: :warning], fn -> + assert {:cancel, :invalid_signature} = SignatureRetryWorker.perform(oban_job) + end) + + assert log =~ "Failed-signature inbox retry rejected" + assert log =~ "reason=:invalid_signature" + assert log =~ "payload_actor=\"https://one.com/users/alice\"" + assert log =~ "signature_actor=\"https://one.com/users/alice\"" + assert log =~ "activity_id=\"https://one.com/activities/invalid-signature-create\"" + assert log =~ "type=\"Create\"" + assert log =~ "request_path=\"/inbox\"" + refute Activity.get_by_ap_id(create["id"]) end @@ -352,6 +399,39 @@ defmodule Pleroma.Workers.SignatureRetryWorkerTest do assert_mismatched_signature_cancelled(create, alice) end + test "logs signature actor mismatch retry rejections" do + alice = insert(:user, local: false, ap_id: "https://one.com/users/alice") + bob = insert(:user, local: false, ap_id: "https://two.com/users/bob") + + create = %{ + "type" => "Create", + "actor" => bob.ap_id, + "id" => "https://two.com/activities/logged-forged-create", + "to" => ["https://www.w3.org/ns/activitystreams#Public"], + "cc" => [], + "object" => %{ + "type" => "Note", + "id" => "https://two.com/objects/logged-forged-note", + "actor" => bob.ap_id, + "attributedTo" => bob.ap_id, + "content" => "forged post", + "published" => "2024-07-25T13:33:31Z", + "to" => ["https://www.w3.org/ns/activitystreams#Public"], + "cc" => [] + } + } + + log = assert_mismatched_signature_cancelled(create, alice) + + assert log =~ "Failed-signature inbox retry rejected" + assert log =~ "reason=:actor_signature_mismatch" + assert log =~ "payload_actor=\"https://two.com/users/bob\"" + assert log =~ "signature_actor=\"https://one.com/users/alice\"" + assert log =~ "activity_id=\"https://two.com/activities/logged-forged-create\"" + assert log =~ "type=\"Create\"" + assert log =~ "request_path=\"/inbox\"" + end + test "cancels signature actor mismatch before actually creating a forged post" do alice = insert(:user, local: false, ap_id: "https://one.com/users/alice") bob = insert(:user, local: false, ap_id: "https://two.com/users/bob")