wireproto: Don't depend on very specific slog idioms

Summary: We want to migrate from `slog` to `tracing`. Code that uses advanced `slog` features such as customizing Loggers to duplex information across multiple drains and setting KV filters makes that more difficult. Instead, use much simpler rust to achieve the intended effect: In some cases, we want to send the errors back to the client by writing it to a mpsc channel of Bytes. Reviewed By: markbt Differential Revision: D68902095 fbshipit-source-id: 378336b7c2d13f7fb0f8a8027b181487992228fd
facebook · Jan 31, 2025 · bbbe702 · bbbe702
1 parent 309e937
commit bbbe702
Show file tree

Hide file tree

Showing 14 changed files with 47 additions and 91 deletions.
diff --git a/eden/mononoke/server/repo_listener/Cargo.toml b/eden/mononoke/server/repo_listener/Cargo.toml
@@ -30,7 +30,6 @@ http = "0.2"
 hyper = { version = "0.14.26", features = ["client", "http1", "http2", "stream"] }
 justknobs = { version = "0.1.0", git = "https://github.com/facebookexperimental/rust-shed.git", branch = "main" }
 lazy_static = "1.4"
-maplit = "1.0"
 metaconfig_types = { version = "0.1.0", path = "../../metaconfig/types" }
 metadata = { version = "0.1.0", path = "../metadata" }
 mononoke_api = { version = "0.1.0", path = "../../mononoke_api" }
@@ -54,11 +53,9 @@ serde_json = { version = "1.0.132", features = ["float_roundtrip", "unbounded_de
 session_id = { version = "0.1.0", path = "../session_id" }
 sha1 = "0.10.5"
 slog = { version = "2.7", features = ["max_level_trace", "nested-values"] }
-slog-kvfilter = "0.7"
-slog-term = "2.8"
-slog_ext = { version = "0.1.0", path = "../../common/rust/slog_ext" }
 sshrelay = { version = "0.1.0", path = "../../sshrelay" }
 stats = { version = "0.1.0", git = "https://github.com/facebookexperimental/rust-shed.git", branch = "main" }
+textwrap = { version = "0.16.0", features = ["terminal_size"] }
 thiserror = "2"
 time_ext = { version = "0.1.0", git = "https://github.com/facebookexperimental/rust-shed.git", branch = "main" }
 tokio = { version = "1.41.0", features = ["full", "test-util", "tracing"] }

diff --git a/eden/mononoke/server/repo_listener/src/connection_acceptor.rs b/eden/mononoke/server/repo_listener/src/connection_acceptor.rs
@@ -57,7 +57,6 @@ use scribe_ext::Scribe;
 use scuba_ext::MononokeScubaSampleBuilder;
 use slog::debug;
 use slog::error;
-use slog::info;
 use slog::warn;
 use slog::Logger;
 use sshrelay::IoStream;
@@ -77,7 +76,6 @@ use tokio_util::codec::FramedWrite;
 
 use crate::errors::ErrorKind;
 use crate::http_service::MononokeHttpService;
-use crate::request_handler::create_conn_logger;
 use crate::request_handler::request_handler;
 use crate::wireproto_sink::WireprotoSink;
 
@@ -345,19 +343,14 @@ where
         stdin,
         stdout,
         stderr,
-        logger,
         keep_alive,
         join_handle,
     } = ChannelConn::setup(framed, conn.clone(), metadata.clone());
 
     if metadata.client_debug() {
-        info!(&logger, "{:#?}", metadata; "remote" => "true");
+        let _ = stderr.unbounded_send(Bytes::from(format!("{metadata:#?}")));
     }
 
-    // Don't let the logger hold onto the channel. This is a bit fragile (but at least it breaks
-    // tests deterministically).
-    drop(logger);
-
     let stdio = Stdio {
         metadata,
         stdin,
@@ -415,7 +408,6 @@ pub struct ChannelConn {
     stdin: BoxStream<'static, Result<Bytes, io::Error>>,
     stdout: mpsc::Sender<Bytes>,
     stderr: mpsc::UnboundedSender<Bytes>,
-    logger: Logger,
     keep_alive: AbortHandle,
     join_handle: JoinHandle<Result<(), io::Error>>,
 }
@@ -528,13 +520,10 @@ impl ChannelConn {
             (otx, etx, keep_alive_abort, join_handle)
         };
 
-        let logger = create_conn_logger(stderr.clone(), None, None);
-
         ChannelConn {
             stdin,
             stdout,
             stderr,
-            logger,
             keep_alive,
             join_handle,
         }

diff --git a/eden/mononoke/server/repo_listener/src/request_handler.rs b/eden/mononoke/server/repo_listener/src/request_handler.rs
@@ -26,8 +26,6 @@ use futures::stream::TryStreamExt;
 use futures_stats::TimedFutureExt;
 use hgproto::sshproto;
 use hgproto::HgProtoHandler;
-use maplit::hashmap;
-use maplit::hashset;
 use mononoke_api::Mononoke;
 use mononoke_api::Repo;
 use mononoke_configs::MononokeConfigs;
@@ -40,15 +38,9 @@ use repo_client::RepoClient;
 use repo_permission_checker::RepoPermissionCheckerRef;
 use scribe_ext::Scribe;
 use slog::error;
-use slog::o;
-use slog::Drain;
-use slog::Level;
-use slog::Logger;
-use slog_ext::SimpleFormatWithError;
-use slog_kvfilter::KVFilter;
-use sshrelay::SenderBytesWrite;
 use sshrelay::Stdio;
 use stats::prelude::*;
+use textwrap::indent;
 use time_ext::DurationExt;
 
 use crate::errors::ErrorKind;
@@ -83,16 +75,12 @@ pub async fn request_handler(
         metadata,
     } = stdio;
 
-    let session_id = metadata.session_id();
-
-    // We don't have a repository yet, so create without server drain
-    let conn_log = create_conn_logger(stderr.clone(), None, Some(session_id));
-
     let handler = repo_handler(mononoke, &reponame).with_context(|| {
-        error!(
-            conn_log,
-            "Requested repo \"{}\" does not exist or is disabled", &reponame;
-            "remote" => "true"
+        // We don't have a logger yet as the repo hasn't been created yet, so only log to client
+        log_error_to_client(
+            stderr.clone(),
+            "Unknown Repo:",
+            &format!("Requested repo \"{reponame}\" does not exist or is disabled"),
         );
 
         anyhow!("Unknown Repo: {}", &reponame)
@@ -108,8 +96,6 @@ pub async fn request_handler(
     } = handler;
 
     // Upgrade log to include server drain
-    let conn_log = create_conn_logger(stderr.clone(), Some(logger), Some(session_id));
-
     scuba = scuba.with_seq("seq");
     scuba.add("repo", reponame);
     if let Some(config_info) = configs.config_info().as_ref() {
@@ -133,7 +119,12 @@ pub async fn request_handler(
             )
         } {
             scuba.log_with_msg("Request rejected due to load shedding", format!("{}", err));
-            error!(conn_log, "Request rejected due to load shedding: {}", err; "remote" => "true");
+            error!(logger, "Request rejected due to load shedding: {}", err);
+            log_error_to_client(
+                stderr,
+                "Request rejected due to load shedding:",
+                &format!("{err}"),
+            );
 
             return Err(err.into());
         }
@@ -147,7 +138,8 @@ pub async fn request_handler(
     if !is_allowed_to_repo {
         let err: Error = ErrorKind::AuthorizationFailed.into();
         scuba.log_with_msg("Authorization failed", format!("{}", err));
-        error!(conn_log, "Authorization failed: {}", err; "remote" => "true");
+        error!(logger, "Authorization failed: {}", err);
+        log_error_to_client(stderr, "Authoization failed:", &format!("{err}"));
 
         return Err(err);
     }
@@ -164,7 +156,7 @@ pub async fn request_handler(
 
     let session = session_builder.build();
 
-    let mut logging = LoggingContainer::new(fb, conn_log.clone(), scuba.clone());
+    let mut logging = LoggingContainer::new(fb, logger.clone(), scuba.clone());
     logging.with_scribe(scribe);
 
     let repo_client = RepoClient::new(
@@ -179,7 +171,7 @@ pub async fn request_handler(
 
     // Construct a hg protocol handler
     let proto_handler = HgProtoHandler::new(
-        conn_log.clone(),
+        logger.clone(),
         stdin,
         repo_client,
         sshproto::HgSshCommandDecode,
@@ -242,48 +234,22 @@ pub async fn request_handler(
     }
 
     if let Err(err) = result {
-        error!(&conn_log, "Command failed";
+        error!(logger, "Command failed";
             "error" => ?err,
-            "remote" => "true"
         );
+        // log to client
+        log_error_to_client(stderr, "Command failed", &format!("{err:?}"));
     }
 
     Ok(())
 }
 
-pub fn create_conn_logger(
-    stderr: mpsc::UnboundedSender<Bytes>,
-    server_logger: Option<Logger>,
-    session_id: Option<&SessionId>,
-) -> Logger {
-    let session_id = match session_id {
-        Some(session_id) => session_id.to_string(),
-        None => "".to_string(),
-    };
-    let decorator = o!("session_uuid" => format!("{}", session_id));
-
-    let stderr_write = SenderBytesWrite { chan: stderr };
-    let client_drain = slog_term::PlainSyncDecorator::new(stderr_write);
-    let client_drain = SimpleFormatWithError::new(client_drain);
-    let client_drain = KVFilter::new(client_drain, Level::Critical).only_pass_any_on_all_keys(
-        (hashmap! {
-            "remote".into() => hashset!["true".into(), "remote_only".into()],
-        })
-        .into(),
-    );
-
-    if let Some(logger) = server_logger {
-        let server_drain = KVFilter::new(logger, Level::Critical).always_suppress_any(
-            (hashmap! {
-                "remote".into() => hashset!["remote_only".into()],
-            })
-            .into(),
-        );
-
-        // Don't fail logging if the client goes away
-        let drain = slog::Duplicate::new(client_drain, server_drain).ignore_res();
-        Logger::root(drain, decorator)
-    } else {
-        Logger::root(client_drain.ignore_res(), decorator)
-    }
+pub fn log_error_to_client(
+    client: mpsc::UnboundedSender<Bytes>,
+    description: &'static str,
+    error_msg: &str,
+) {
+    let msg = indent(error_msg, "    ");
+    let error_msg = Bytes::from(format!("{description}\n  Error:\n{msg}"));
+    let _ = client.unbounded_send(error_msg);
 }
diff --git a/eden/mononoke/tests/integration/cross_repo/test-cross-repo-empty-backsync.t b/eden/mononoke/tests/integration/cross_repo/test-cross-repo-empty-backsync.t
@@ -70,7 +70,7 @@ Pushrebase of empty commit via small repo errors out as the commit rewrites into
 nothingness. (But it succeeds in the end.)
   $ hg commit --config ui.allowemptycommit=True -m "Empty3"
   $ hg push -r . --to master_bookmark -q
-  abort: failed reading from pipe: The read operation timed out
+  abort: * (glob)
   [255]
   $ log -r master_bookmark -r .
   @  Empty3 [draft;*] (glob)

diff --git a/eden/mononoke/tests/integration/hooks/test-hooks-plain-push.t b/eden/mononoke/tests/integration/hooks/test-hooks-plain-push.t
@@ -82,7 +82,7 @@ attempt a non-fast-forward move, it should fail
   remote: Command failed
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to fast-forward bookmark (set pushvar NON_FAST_FORWARD=true for a non-fast-forward move)
   remote:         1: Non fast-forward bookmark move of 'master_bookmark' from cbe5624248da659ef8f938baaf65796e68252a0a735e885a814b94f38b901d5b to 2b7843b3fb41a99743420b26286cc5e7bc94ebf7576eaf1bbceb70cd36ffe8b0

diff --git a/eden/mononoke/tests/integration/server/test-push-bookmarks.t b/eden/mononoke/tests/integration/server/test-push-bookmarks.t
@@ -76,7 +76,7 @@ Try non fastforward moves (backwards and across branches)
   remote: Command failed
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to move bookmark
   remote:         1: Non fast-forward bookmark move of 'master_bookmark' from 9b9805995990bb9a787f5290e75bd7926146098df1f2ce3420e91063d41789b7 to aa53d24251ff3f54b1b2c29ae02826701b2abeb0079f1bb13b8434b54cd87675
@@ -89,7 +89,7 @@ Try non fastforward moves (backwards and across branches)
   remote: Command failed
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to move bookmark
   remote:         1: Non fast-forward bookmark move of 'master_bookmark' from 9b9805995990bb9a787f5290e75bd7926146098df1f2ce3420e91063d41789b7 to 99853792aa9e4c9ab4519940c25bd2c840dd7af70f1b2f8aaf5e52beec5fc372
@@ -115,7 +115,7 @@ Try non fastfoward moves on regex bookmark
   remote: Command failed
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to move bookmark
   remote:         1: Non fast-forward bookmark move of 'ffonly_bookmark' from 9b9805995990bb9a787f5290e75bd7926146098df1f2ce3420e91063d41789b7 to aa53d24251ff3f54b1b2c29ae02826701b2abeb0079f1bb13b8434b54cd87675
@@ -131,7 +131,7 @@ Try to delete master
   remote: Command failed
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to delete bookmark
   remote:         1: Deletion of 'master_bookmark' is prohibited

diff --git a/eden/mononoke/tests/integration/server/test-push-disallowed.t b/eden/mononoke/tests/integration/server/test-push-disallowed.t
@@ -54,7 +54,7 @@ try doing a non-pushrebase push with the new commits
   remote: Command failed
   remote:   Error:
   remote:     bundle2_resolver error
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: While resolving Changegroup
   remote:         1: Pure pushes are disallowed in this repo

diff --git a/eden/mononoke/tests/integration/server/test-push-limit-num-of-commits.t b/eden/mononoke/tests/integration/server/test-push-limit-num-of-commits.t
@@ -66,7 +66,7 @@ create new commit in repo2 and check that push fails
   remote: Command failed
   remote:   Error:
   remote:     bundle2_resolver error
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: While resolving Changegroup
   remote:         1: Trying to push too many commits! Limit is 2, tried to push 3

diff --git a/eden/mononoke/tests/integration/server/test-push-readonly.t b/eden/mononoke/tests/integration/server/test-push-readonly.t
@@ -73,7 +73,7 @@ create new commit in repo2 and check that push to a bookmark fails
   remote: * (glob)
   remote:   Error:
   remote:     While doing a push
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: Failed to fast-forward bookmark (set pushvar NON_FAST_FORWARD=true for a non-fast-forward move)
   remote:         1: Repo is locked: Set by config option

diff --git a/eden/mononoke/tests/integration/server/test-server-inconsistent-hash.t b/eden/mononoke/tests/integration/server/test-server-inconsistent-hash.t
@@ -67,7 +67,7 @@ filenode won't be send at all
   remote: Command failed
   remote:   Error:
   remote:     Error while uploading data for changesets, hashes: [HgChangesetId(HgNodeHash(Sha1(cb67355f234869bb9bf94787d5a69e21e23a8c9b)))]
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: While creating Changeset Some(HgNodeHash(Sha1(cb67355f234869bb9bf94787d5a69e21e23a8c9b))), uuid: * (glob)
   remote:         1: While creating and verifying Changeset for blobstore

diff --git a/eden/mononoke/tests/integration/server/test-server-init.t b/eden/mononoke/tests/integration/server/test-server-init.t
@@ -111,7 +111,9 @@ start mononoke
 
   $ start_and_wait_for_mononoke_server
   $ hg debugwireargs mono:disabled_repo one two --three three
-  remote: Requested repo "disabled_repo" does not exist or is disabled
+  remote: Unknown Repo:
+  remote:   Error:
+  remote:     Requested repo "disabled_repo" does not exist or is disabled
   abort: unexpected EOL, expected netstring digit
   [255]
   $ hg debugwireargs mono:repo one two --three three

diff --git a/eden/mononoke/tests/integration/server/test-server-sqlblob.t b/eden/mononoke/tests/integration/server/test-server-sqlblob.t
@@ -110,7 +110,9 @@ start mononoke
 
   $ start_and_wait_for_mononoke_server
   $ hg debugwireargs mono:disabled_repo one two --three three
-  remote: Requested repo "disabled_repo" does not exist or is disabled
+  remote: Unknown Repo:
+  remote:   Error:
+  remote:     Requested repo "disabled_repo" does not exist or is disabled
   abort: unexpected EOL, expected netstring digit
   [255]
   $ hg debugwireargs mono:repo one two --three three

diff --git a/eden/mononoke/tests/integration/test-lfs-to-mononoke.t b/eden/mononoke/tests/integration/test-lfs-to-mononoke.t
@@ -99,7 +99,7 @@ Verify that if we fail to upload LFS blobs first, the push fails
   remote: Command failed
   remote:   Error:
   remote:     While resolving Changegroup
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: While uploading File Blobs
   remote:         1: While decoding delta cache for file id ff714056cdbb88eef0578934980d740a05be8384, path f

diff --git a/eden/mononoke/tests/integration/test-remotefilelog-lfs.t b/eden/mononoke/tests/integration/test-remotefilelog-lfs.t
@@ -104,7 +104,7 @@ Verify that if we fail to upload LFS blobs first, the push fails
   remote: Command failed
   remote:   Error:
   remote:     While resolving Changegroup
-  remote:     
+  remote: 
   remote:     Caused by:
   remote:         0: While uploading File Blobs
   remote:         1: While decoding delta cache for file id ff714056cdbb88eef0578934980d740a05be8384, path f