Add debug logs to timeline rendering to assist debugging

lib/pleroma/activity.ex

@@ -284,7 +284,6 @@ def get_local_create_by_object_ap_id(ap_id) when is_binary(ap_id) do
     |> Repo.one()
   end
 
-
   @spec create_by_id_with_object(String.t()) :: t() | nil
   def create_by_id_with_object(id) do
     get_by_id_with_opts(id, preload: [:object], filter: [type: "Create"])

lib/pleroma/user.ex

@@ -374,7 +374,7 @@ def banner_url(user, options \\ []) do
     do_optional_url(user.banner, "#{Endpoint.url()}/images/banner.png", options)
   end
 
-  defp do_optional_url(field, default, options \\ []) do
+  defp do_optional_url(field, default, options) do
     case field do
       %{"url" => [%{"href" => href} | _]} when is_binary(href) ->
         href

lib/pleroma/web/mastodon_api/controllers/timeline_controller.ex

@@ -37,10 +37,16 @@ defmodule Pleroma.Web.MastodonAPI.TimelineController do
     when action in [:public, :hashtag, :bubble]
   )
 
+  require Logger
+
   defdelegate open_api_operation(action), to: Pleroma.Web.ApiSpec.TimelineOperation
 
   # GET /api/v1/timelines/home
   def home(%{assigns: %{user: user}} = conn, params) do
+    %{nickname: nickname} = user
+
+    Logger.debug("TimelineController.home: #{nickname}")
+
     followed_hashtags =
       user
       |> User.followed_hashtags()
@@ -58,11 +64,15 @@ def home(%{assigns: %{user: user}} = conn, params) do
       |> Map.put(:followed_hashtags, followed_hashtags)
       |> Map.delete(:local)
 
+    Logger.debug("TimelineController.home: #{nickname} - fetching activities")
+
     activities =
       [user.ap_id | User.following(user)]
       |> ActivityPub.fetch_activities(params)
       |> Enum.reverse()
 
+    Logger.debug("TimelineController.home: #{nickname} - rendering")
+
     conn
     |> add_link_headers(activities)
     |> render("index.json",
@@ -75,6 +85,8 @@ def home(%{assigns: %{user: user}} = conn, params) do
 
   # GET /api/v1/timelines/direct
   def direct(%{assigns: %{user: user}} = conn, params) do
+    Logger.debug("TimelineController.direct: #{user.nickname}")
+
     params =
       params
       |> Map.put(:type, "Create")
@@ -82,11 +94,15 @@ def direct(%{assigns: %{user: user}} = conn, params) do
       |> Map.put(:user, user)
       |> Map.put(:visibility, "direct")
 
+    Logger.debug("TimelineController.direct: #{user.nickname} - fetching activities")
+
     activities =
       [user.ap_id]
       |> ActivityPub.fetch_activities_query(params)
       |> Pagination.fetch_paginated(params)
 
+    Logger.debug("TimelineController.direct: #{user.nickname} - rendering")
+
     conn
     |> add_link_headers(activities)
     |> render("index.json",
@@ -102,6 +118,7 @@ defp restrict_unauthenticated?(type) do
 
   # GET /api/v1/timelines/public
   def public(%{assigns: %{user: user}} = conn, params) do
+    Logger.debug("TimelineController.public")
     local_only = params[:local]
     timeline_type = if local_only, do: :local, else: :federated
 
@@ -109,6 +126,8 @@ def public(%{assigns: %{user: user}} = conn, params) do
            {:enabled, local_only || Config.get([:instance, :federated_timeline_available], true)},
          {:authenticated, true} <-
            {:authenticated, !(is_nil(user) and restrict_unauthenticated?(timeline_type))} do
+      Logger.debug("TimelineController.public: fetching activities")
+
       activities =
         params
         |> Map.put(:type, ["Create"])
@@ -121,6 +140,8 @@ def public(%{assigns: %{user: user}} = conn, params) do
         |> Map.put(:includes_local_public, not is_nil(user))
         |> ActivityPub.fetch_public_activities()
 
+      Logger.debug("TimelineController.public: rendering")
+
       conn
       |> add_link_headers(activities, %{"local" => local_only})
       |> render("index.json",
@@ -142,6 +163,8 @@ def public(%{assigns: %{user: user}} = conn, params) do
 
   # GET /api/v1/timelines/bubble
   def bubble(%{assigns: %{user: user}} = conn, params) do
+    Logger.debug("TimelineController.bubble")
+
     if is_nil(user) and restrict_unauthenticated?(:bubble) do
       fail_on_bad_auth(conn)
     else
@@ -151,6 +174,8 @@ def bubble(%{assigns: %{user: user}} = conn, params) do
             [Pleroma.Web.Endpoint.host()]
         )
 
+      Logger.debug("TimelineController.bubble: fetching activities")
+
       activities =
         params
         |> Map.put(:type, ["Create"])
@@ -160,6 +185,8 @@ def bubble(%{assigns: %{user: user}} = conn, params) do
         |> Map.put(:instance, bubble_instances)
         |> ActivityPub.fetch_public_activities()
 
+      Logger.debug("TimelineController.bubble: rendering")
+
       conn
       |> add_link_headers(activities)
       |> render("index.json",

lib/pleroma/web/mastodon_api/views/status_view.ex

@@ -21,6 +21,7 @@ defmodule Pleroma.Web.MastodonAPI.StatusView do
   alias Pleroma.Web.MastodonAPI.StatusView
   alias Pleroma.Web.MediaProxy
   alias Pleroma.Web.PleromaAPI.EmojiReactionController
+  require Logger
 
   import Pleroma.Web.ActivityPub.Visibility, only: [get_visibility: 1, visible_for_user?: 2]
 
@@ -87,6 +88,7 @@ defp reblogged?(activity, %User{ap_id: ap_id}) do
   defp reblogged?(_activity, _user), do: false
 
   def render("index.json", opts) do
+    Logger.debug("Rendering index")
     reading_user = opts[:for]
     # To do: check AdminAPIControllerTest on the reasons behind nil activities in the list
     activities = Enum.filter(opts.activities, & &1)
@@ -136,8 +138,10 @@ def render("index.json", opts) do
 
   def render(
         "show.json",
-        %{activity: %{data: %{"type" => "Announce", "object" => _object}} = activity} = opts
+        %{activity: %{id: id, data: %{"type" => "Announce", "object" => _object}} = activity} =
+          opts
       ) do
+    Logger.debug("Rendering reblog #{id}")
     user = CommonAPI.get_user(activity.data["actor"])
     created_at = Utils.to_masto_date(activity.data["published"])
     object = Object.normalize(activity, fetch: false)
@@ -209,7 +213,9 @@ def render(
     }
   end
 
-  def render("show.json", %{activity: %{data: %{"object" => _object}} = activity} = opts) do
+  def render("show.json", %{activity: %{id: id, data: %{"object" => _object}} = activity} = opts) do
+    Logger.debug("Rendering status #{id}")
+
     with %Object{} = object <- Object.normalize(activity, fetch: false) do
       user = CommonAPI.get_user(activity.data["actor"])
       user_follower_address = user.follower_address
@@ -428,6 +434,7 @@ def render("show.json", _) do
   end
 
   def render("history.json", %{activity: %{data: %{"object" => _object}} = activity} = opts) do
+    Logger.debug("Rendering history for #{activity.id}")
     object = Object.normalize(activity, fetch: false)
 
     hashtags = Object.hashtags(object)
@@ -614,6 +621,8 @@ def render("attachment_meta.json", %{
   def render("attachment_meta.json", _), do: nil
 
   def render("context.json", %{activity: activity, activities: activities, user: user}) do
+    Logger.debug("Rendering context for #{activity.id}")
+
     %{ancestors: ancestors, descendants: descendants} =
       activities
       |> Enum.reverse()