diff --git a/eden/mononoke/server/repo_listener/Cargo.toml b/eden/mononoke/server/repo_listener/Cargo.toml index c894a2a035e2d..cd037780ec75c 100644 --- 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 index 248613c657ae1..fcdbbcdc08e4f 100644 --- 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>, stdout: mpsc::Sender, stderr: mpsc::UnboundedSender, - logger: Logger, keep_alive: AbortHandle, join_handle: JoinHandle>, } @@ -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 index 9e14efdddb37e..b42d67d7828ae 100644 --- 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, - server_logger: Option, - 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, + 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 index 4b4c78adca882..e072cd957f3b8 100644 --- 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 index fc5f5a562c342..3e30868184d03 100644 --- 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 index ac9171f2a176e..57249f36ad33e 100644 --- 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 index bf96a04f22664..438dd3bea0666 100644 --- 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 index 5d779f71f3c73..9862e01c339a8 100644 --- 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 index fe0ba638f83e1..d2f588ed00476 100644 --- 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 index 8442bd717c74e..446b4191a8c35 100644 --- 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 index 80c1f23551d7d..4f77d01e4400b 100644 --- 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 index 3661698618bdd..3ccd94956346f 100644 --- 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 index e6903bba1a5c6..1d049d0fe9cad 100644 --- 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 index a8881c7061b60..bcb7fce7aa528 100644 --- 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