From 78eee7dc9e98b0fbc6c52b11c36483afc696e359 Mon Sep 17 00:00:00 2001
From: Felix Ableitner <me@nutomic.com>
Date: Wed, 21 Apr 2021 14:42:33 +0200
Subject: [PATCH] Improved logging

---
 ansible/templates/docker-compose.yml           |  2 +-
 crates/apub/src/fetcher/fetch.rs               |  8 ++++++--
 .../apub_receive/src/inbox/community_inbox.rs  | 17 ++++++++++-------
 crates/apub_receive/src/inbox/person_inbox.rs  | 18 ++++++++++--------
 docker/dev/docker-compose.yml                  |  2 +-
 docker/federation/docker-compose.yml           | 10 +++++-----
 docker/prod/docker-compose.yml                 |  2 +-
 7 files changed, 34 insertions(+), 25 deletions(-)

diff --git a/ansible/templates/docker-compose.yml b/ansible/templates/docker-compose.yml
index b074d60f..412e5951 100644
--- a/ansible/templates/docker-compose.yml
+++ b/ansible/templates/docker-compose.yml
@@ -7,7 +7,7 @@ services:
       - "127.0.0.1:8536:8536"
     restart: always
     environment:
-      - RUST_LOG=error
+      - RUST_LOG="warn,lemmy_server=info,lemmy_api=info,lemmy_api_common=info,lemmy_api_crud=info,lemmy_apub=info,lemmy_apub_receive=info,lemmy_db_queries=info,lemmy_db_schema=info,lemmy_db_views=info,lemmy_db_views_actor=info,lemmy_db_views_moderator=info,lemmy_routes=info,lemmy_utils=info,lemmy_websocket=info"
     volumes:
       - ./lemmy.hjson:/config/config.hjson:ro
     depends_on:
diff --git a/crates/apub/src/fetcher/fetch.rs b/crates/apub/src/fetcher/fetch.rs
index 304d1cd1..27ea0fca 100644
--- a/crates/apub/src/fetcher/fetch.rs
+++ b/crates/apub/src/fetcher/fetch.rs
@@ -1,6 +1,7 @@
 use crate::{check_is_apub_id_valid, APUB_JSON_CONTENT_TYPE};
 use anyhow::anyhow;
 use lemmy_utils::{request::retry, LemmyError};
+use log::info;
 use reqwest::{Client, StatusCode};
 use serde::Deserialize;
 use std::time::Duration;
@@ -73,11 +74,14 @@ where
   .await?;
 
   if res.status() == StatusCode::GONE {
+    info!("Fetched remote object {} which was deleted", url);
     return Err(FetchError {
-      inner: anyhow!("Remote object {} was deleted", url),
+      inner: anyhow!("Fetched remote object {} which was deleted", url),
       status_code: Some(res.status()),
     });
   }
 
-  Ok(res.json().await?)
+  let object = res.json().await?;
+  info!("Fetched remote object {}", url);
+  Ok(object)
 }
diff --git a/crates/apub_receive/src/inbox/community_inbox.rs b/crates/apub_receive/src/inbox/community_inbox.rs
index 84b01699..dfea8605 100644
--- a/crates/apub_receive/src/inbox/community_inbox.rs
+++ b/crates/apub_receive/src/inbox/community_inbox.rs
@@ -96,13 +96,6 @@ pub async fn community_inbox(
   assert_activity_not_local(&activity)?;
   insert_activity(&activity_id, activity.clone(), false, true, context.pool()).await?;
 
-  info!(
-    "Community {} received activity {:?} from {}",
-    community.name,
-    &activity.id_unchecked(),
-    &actor.actor_id()
-  );
-
   community_receive_message(
     activity.clone(),
     community.clone(),
@@ -130,6 +123,16 @@ pub(crate) async fn community_receive_message(
   .await??;
   check_community_or_site_ban(&person, to_community.id, context.pool()).await?;
 
+  info!(
+    "Community {} received activity {} from {}",
+    to_community.name,
+    &activity
+      .id_unchecked()
+      .context(location_info!())?
+      .to_string(),
+    &person.actor_id().to_string()
+  );
+
   let any_base = activity.clone().into_any_base()?;
   let actor_url = actor.actor_id();
   let activity_kind = activity.kind().context(location_info!())?;
diff --git a/crates/apub_receive/src/inbox/person_inbox.rs b/crates/apub_receive/src/inbox/person_inbox.rs
index 66b6c95a..65e91299 100644
--- a/crates/apub_receive/src/inbox/person_inbox.rs
+++ b/crates/apub_receive/src/inbox/person_inbox.rs
@@ -61,7 +61,7 @@ use lemmy_db_schema::source::{
 };
 use lemmy_utils::{location_info, LemmyError};
 use lemmy_websocket::LemmyContext;
-use log::debug;
+use log::info;
 use serde::{Deserialize, Serialize};
 use std::fmt::Debug;
 use strum_macros::EnumString;
@@ -115,13 +115,6 @@ pub async fn person_inbox(
   assert_activity_not_local(&activity)?;
   insert_activity(&activity_id, activity.clone(), false, true, context.pool()).await?;
 
-  debug!(
-    "Person {} received activity {:?} from {}",
-    person.name,
-    &activity.id_unchecked(),
-    &actor.actor_id()
-  );
-
   person_receive_message(
     activity.clone(),
     Some(person.clone()),
@@ -142,6 +135,15 @@ pub(crate) async fn person_receive_message(
 ) -> Result<HttpResponse, LemmyError> {
   is_for_person_inbox(context, &activity).await?;
 
+  info!(
+    "User received activity {:?} from {}",
+    &activity
+      .id_unchecked()
+      .context(location_info!())?
+      .to_string(),
+    &actor.actor_id().to_string()
+  );
+
   let any_base = activity.clone().into_any_base()?;
   let kind = activity.kind().context(location_info!())?;
   let actor_url = actor.actor_id();
diff --git a/docker/dev/docker-compose.yml b/docker/dev/docker-compose.yml
index 7f8979fe..3beecd8e 100644
--- a/docker/dev/docker-compose.yml
+++ b/docker/dev/docker-compose.yml
@@ -8,7 +8,7 @@ services:
       - "8536:8536"
     restart: always
     environment:
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     volumes:
       - ../lemmy.hjson:/config/config.hjson
     depends_on: 
diff --git a/docker/federation/docker-compose.yml b/docker/federation/docker-compose.yml
index c13c89ea..d2fe496d 100644
--- a/docker/federation/docker-compose.yml
+++ b/docker/federation/docker-compose.yml
@@ -43,7 +43,7 @@ services:
     environment:
       - LEMMY_TEST_SEND_SYNC=1
       - RUST_BACKTRACE=1
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     depends_on:
       - postgres_alpha
     ports: 
@@ -72,7 +72,7 @@ services:
     environment:
       - LEMMY_TEST_SEND_SYNC=1
       - RUST_BACKTRACE=1
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     depends_on:
       - postgres_beta
     ports: 
@@ -101,7 +101,7 @@ services:
     environment:
       - LEMMY_TEST_SEND_SYNC=1
       - RUST_BACKTRACE=1
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     depends_on:
       - postgres_gamma
     ports: 
@@ -131,7 +131,7 @@ services:
     environment:
       - LEMMY_TEST_SEND_SYNC=1
       - RUST_BACKTRACE=1
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     depends_on:
       - postgres_delta
     ports: 
@@ -161,7 +161,7 @@ services:
     environment:
       - LEMMY_TEST_SEND_SYNC=1
       - RUST_BACKTRACE=1
-      - RUST_LOG=debug
+      - RUST_LOG="warn,lemmy_server=debug,lemmy_api=debug,lemmy_api_common=debug,lemmy_api_crud=debug,lemmy_apub=debug,lemmy_apub_receive=debug,lemmy_db_queries=debug,lemmy_db_schema=debug,lemmy_db_views=debug,lemmy_db_views_actor=debug,lemmy_db_views_moderator=debug,lemmy_routes=debug,lemmy_utils=debug,lemmy_websocket=debug"
     depends_on:
       - postgres_epsilon
     ports: 
diff --git a/docker/prod/docker-compose.yml b/docker/prod/docker-compose.yml
index 1024ecbc..4cec4277 100644
--- a/docker/prod/docker-compose.yml
+++ b/docker/prod/docker-compose.yml
@@ -17,7 +17,7 @@ services:
       - "127.0.0.1:8536:8536"
     restart: always
     environment:
-      - RUST_LOG=error
+      - RUST_LOG="warn,lemmy_server=info,lemmy_api=info,lemmy_api_common=info,lemmy_api_crud=info,lemmy_apub=info,lemmy_apub_receive=info,lemmy_db_queries=info,lemmy_db_schema=info,lemmy_db_views=info,lemmy_db_views_actor=info,lemmy_db_views_moderator=info,lemmy_routes=info,lemmy_utils=info,lemmy_websocket=info"
     volumes:
       - ./lemmy.hjson:/config/config.hjson
     depends_on:
-- 
2.44.1