Log all incoming request errors

app/controllers/discourse_activity_pub/ap/objects_controller.rb

@@ -91,7 +91,9 @@ def ensure_object_exists
   end
 
   def render_activity_pub_error(key, status, opts = {})
-    render_json_error(I18n.t("discourse_activity_pub.request.error.#{key}", opts), status: status)
+    message = I18n.t("discourse_activity_pub.request.error.#{key}", opts)
+    log_request_error(message, status)
+    render_json_error(message, status: status)
   end
 
   def render_ordered_collection(stored, collection_for)
@@ -109,4 +111,16 @@ def render_ordered_collection(stored, collection_for)
   def set_raw_body
     @raw_body = request.body.read
   end
+
+  def log_request_error(message, status)
+    DiscourseActivityPub::Logger.warn(
+      I18n.t(
+        "discourse_activity_pub.request.error.request_from_failed",
+        method: request.method,
+        uri: request.url,
+        status: status,
+        message: message,
+      ),
+    )
+  end
 end

config/locales/server.en.yml

@@ -62,7 +62,8 @@ en:
         invalid_digest: "Invalid Digest value. Computed SHA-256 digest: %{computed}; given: %{digest}"
         invalid_signature_pseudo_header: 'Invalid Signature pseudo-header (%{header})'
         invalid_date_header: "Invalid Date header: %{reason}"
-        request_failed: "%{verb} request to %{uri} failed: %{message}"
+        request_to_failed: "%{method} request to %{uri} failed: %{message}"
+        request_from_failed: "%{method} request from %{uri} failed: %{status} %{message}"
     process:
       warning:
         failed_to_process: "Failed to process %{object_id}"

lib/discourse_activity_pub/request.rb

@@ -60,8 +60,8 @@ def perform(verb)
     rescue Excon::Error => e
       DiscourseActivityPub::Logger.warn(
         I18n.t(
-          "discourse_activity_pub.request.error.request_failed",
-          verb: verb.upcase,
+          "discourse_activity_pub.request.error.request_to_failed",
+          method: verb.upcase,
           uri: uri.to_s,
           message: e.message,
         ),

spec/plugin_helper.rb

@@ -44,8 +44,19 @@ def get_followers(object, url: nil, headers: {})
       headers: { "Accept" => DiscourseActivityPub::JsonLd.content_type_header }.merge(headers)
 end
 
-def activity_request_error(key)
-  { "errors" => [I18n.t("discourse_activity_pub.request.error.#{key}")] }
+def expect_request_error(response, key, status, opts = {})
+  expect(response.status).to eq(status)
+  message = I18n.t("discourse_activity_pub.request.error.#{key}", opts)
+  log =
+    I18n.t(
+      "discourse_activity_pub.request.error.request_from_failed",
+      method: response.request.method,
+      uri: response.request.url,
+      status: status,
+      message: message,
+    )
+  expect(@fake_logger.warnings).to include("[Discourse Activity Pub] #{log}")
+  expect(response.parsed_body).to eq({ "errors" => [message] })
 end
 
 def default_headers

spec/requests/discourse_activity_pub/ap/activities_controller_spec.rb

@@ -8,10 +8,12 @@
   before { SiteSetting.activity_pub_require_signed_requests = false }
 
   context "without a valid activity" do
+    before { setup_logging }
+    after { teardown_logging }
+
     it "returns a not found error" do
       get_object(activity, url: "/ap/activity/56")
-      expect(response.status).to eq(404)
-      expect(response.parsed_body).to eq(activity_request_error("not_found"))
+      expect_request_error(response, "not_found", 404)
     end
   end
 
@@ -23,12 +25,15 @@
       end
     end
 
-    before { activity.base_object.model.topic.update(category: staff_category) }
+    before do
+      activity.base_object.model.topic.update(category: staff_category)
+      setup_logging
+    end
+    after { teardown_logging }
 
     it "returns a not available error" do
       get_object(activity)
-      expect(response.status).to eq(401)
-      expect(response.parsed_body).to eq(activity_request_error("not_available"))
+      expect_request_error(response, "not_available", 401)
     end
   end
 
@@ -61,10 +66,12 @@
       before { SiteSetting.login_required = true }
 
       context "with a composition activity" do
+        before { setup_logging }
+        after { teardown_logging }
+
         it "returns a not available error" do
           get_object(activity)
-          expect(response.status).to eq(401)
-          expect(response.parsed_body).to eq(activity_request_error("not_available"))
+          expect_request_error(response, "not_available", 401)
         end
       end
 

spec/requests/discourse_activity_pub/ap/actors_controller_spec.rb

@@ -10,31 +10,36 @@
   before { SiteSetting.activity_pub_require_signed_requests = false }
 
   context "without a valid actor" do
+    before { setup_logging }
+    after { teardown_logging }
+
     it "returns a not found error" do
       get_object(group, url: "/ap/actor/56")
-      expect(response.status).to eq(404)
-      expect(response.parsed_body).to eq(activity_request_error("not_found"))
+      expect_request_error(response, "not_found", 404)
     end
   end
 
   context "without a public actor" do
     before do
       group.model.set_permissions(admins: :full)
       group.model.save!
+      setup_logging
     end
+    after { teardown_logging }
 
     it "returns a not available error" do
       get_object(group)
-      expect(response.status).to eq(401)
-      expect(response.parsed_body).to eq(activity_request_error("not_available"))
+      expect_request_error(response, "not_available", 401)
     end
   end
 
   context "without activity pub ready on actor model" do
+    before { setup_logging }
+    after { teardown_logging }
+
     it "returns a not available error" do
       get_object(group)
-      expect(response.status).to eq(403)
-      expect(response.parsed_body).to eq(activity_request_error("not_available"))
+      expect_request_error(response, "not_available", 403)
     end
   end
 
@@ -61,10 +66,12 @@
       end
 
       context "with a person actor" do
+        before { setup_logging }
+        after { teardown_logging }
+
         it "returns a not available error" do
           get_object(person)
-          expect(response.status).to eq(401)
-          expect(response.parsed_body).to eq(activity_request_error("not_available"))
+          expect_request_error(response, "not_available", 401)
         end
       end
     end

spec/requests/discourse_activity_pub/ap/collections_controller_spec.rb

@@ -8,10 +8,12 @@
   before { SiteSetting.activity_pub_require_signed_requests = false }
 
   context "without a valid collection" do
+    before { setup_logging }
+    after { teardown_logging }
+
     it "returns a not found error" do
       get_object(collection, url: "/ap/collection/56")
-      expect(response.status).to eq(404)
-      expect(response.parsed_body).to eq(activity_request_error("not_found"))
+      expect_request_error(response, "not_found", 404)
     end
   end
 
@@ -23,12 +25,15 @@
       end
     end
 
-    before { collection.model.update(category: staff_category) }
+    before do
+      collection.model.update(category: staff_category)
+      setup_logging
+    end
+    after { teardown_logging }
 
     it "returns a not available error" do
       get_object(collection)
-      expect(response.status).to eq(401)
-      expect(response.parsed_body).to eq(activity_request_error("not_available"))
+      expect_request_error(response, "not_available", 401)
     end
   end