rhg: Add support for the blackbox extension
Only `command` and `commandfinish` events are logged.
The `dirty`, `logsource`, `track` and `ignore` configuration items
are not supported yet.
To indicate commands executed without Python, a `(rust) ` prefix is added
in corresponding log messages.
Differential Revision: https://phab.mercurial-scm.org/D10012
--- a/rust/Cargo.lock Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/Cargo.lock Tue Feb 16 13:08:37 2021 +0100
@@ -91,6 +91,18 @@
source = "registry+https://github.com/rust-lang/crates.io-index"
[[package]]
+name = "chrono"
+version = "0.4.19"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+dependencies = [
+ "libc 0.2.81 (registry+https://github.com/rust-lang/crates.io-index)",
+ "num-integer 0.1.44 (registry+https://github.com/rust-lang/crates.io-index)",
+ "num-traits 0.2.14 (registry+https://github.com/rust-lang/crates.io-index)",
+ "time 0.1.44 (registry+https://github.com/rust-lang/crates.io-index)",
+ "winapi 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
+[[package]]
name = "clap"
version = "2.33.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -467,6 +479,15 @@
]
[[package]]
+name = "num-integer"
+version = "0.1.44"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+dependencies = [
+ "autocfg 1.0.1 (registry+https://github.com/rust-lang/crates.io-index)",
+ "num-traits 0.2.14 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
+[[package]]
name = "num-traits"
version = "0.2.14"
source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -715,6 +736,7 @@
name = "rhg"
version = "0.1.0"
dependencies = [
+ "chrono 0.4.19 (registry+https://github.com/rust-lang/crates.io-index)",
"clap 2.33.3 (registry+https://github.com/rust-lang/crates.io-index)",
"derive_more 0.99.11 (registry+https://github.com/rust-lang/crates.io-index)",
"env_logger 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -722,6 +744,7 @@
"hg-core 0.1.0",
"log 0.4.11 (registry+https://github.com/rust-lang/crates.io-index)",
"micro-timer 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)",
+ "users 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)",
]
[[package]]
@@ -856,6 +879,15 @@
source = "registry+https://github.com/rust-lang/crates.io-index"
[[package]]
+name = "users"
+version = "0.11.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+dependencies = [
+ "libc 0.2.81 (registry+https://github.com/rust-lang/crates.io-index)",
+ "log 0.4.11 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
+[[package]]
name = "vcpkg"
version = "0.2.11"
source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -949,6 +981,7 @@
"checksum cc 1.0.66 (registry+https://github.com/rust-lang/crates.io-index)" = "4c0496836a84f8d0495758516b8621a622beb77c0fed418570e50764093ced48"
"checksum cfg-if 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)" = "4785bdd1c96b2a846b2bd7cc02e86b6b3dbf14e7e53446c4f54c92a361040822"
"checksum cfg-if 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)" = "baf1de4339761588bc0619e3cbc0120ee582ebb74b53b4efbf79117bd2da40fd"
+"checksum chrono 0.4.19 (registry+https://github.com/rust-lang/crates.io-index)" = "670ad68c9088c2a963aaa298cb369688cf3f9465ce5e2d4ca10e6e0098a1ce73"
"checksum clap 2.33.3 (registry+https://github.com/rust-lang/crates.io-index)" = "37e58ac78573c40708d45522f0d80fa2f01cc4f9b4e2bf749807255454312002"
"checksum const_fn 0.4.4 (registry+https://github.com/rust-lang/crates.io-index)" = "cd51eab21ab4fd6a3bf889e2d0958c0a6e3a61ad04260325e919e652a2a62826"
"checksum cpython 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)" = "bfaf3847ab963e40c4f6dd8d6be279bdf74007ae2413786a0dcbb28c52139a95"
@@ -988,6 +1021,7 @@
"checksum micro-timer 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "2620153e1d903d26b72b89f0e9c48d8c4756cba941c185461dddc234980c298c"
"checksum micro-timer-macros 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "e28a3473e6abd6e9aab36aaeef32ad22ae0bd34e79f376643594c2b152ec1c5d"
"checksum miniz_oxide 0.4.3 (registry+https://github.com/rust-lang/crates.io-index)" = "0f2d26ec3309788e423cfbf68ad1800f061638098d76a83681af979dc4eda19d"
+"checksum num-integer 0.1.44 (registry+https://github.com/rust-lang/crates.io-index)" = "d2cc698a63b549a70bc047073d2949cce27cd1c7b0a4a862d08a8031bc2801db"
"checksum num-traits 0.2.14 (registry+https://github.com/rust-lang/crates.io-index)" = "9a64b1ec5cda2586e284722486d802acf1f7dbdc623e2bfc57e65ca1cd099290"
"checksum num_cpus 1.13.0 (registry+https://github.com/rust-lang/crates.io-index)" = "05499f3756671c15885fee9034446956fff3f243d6077b91e5767df161f766b3"
"checksum output_vt100 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "53cdc5b785b7a58c5aad8216b3dfa114df64b0b06ae6e1501cef91df2fbdf8f9"
@@ -1035,6 +1069,7 @@
"checksum typenum 1.12.0 (registry+https://github.com/rust-lang/crates.io-index)" = "373c8a200f9e67a0c95e62a4f52fbf80c23b4381c05a17845531982fa99e6b33"
"checksum unicode-width 0.1.8 (registry+https://github.com/rust-lang/crates.io-index)" = "9337591893a19b88d8d87f2cec1e73fad5cdfd10e5a6f349f498ad6ea2ffb1e3"
"checksum unicode-xid 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "f7fe0bb3479651439c9112f72b6c505038574c9fbb575ed1bf3b797fa39dd564"
+"checksum users 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)" = "24cc0f6d6f267b73e5a2cadf007ba8f9bc39c6a6f9666f8cf25ea809a153b032"
"checksum vcpkg 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)" = "b00bca6106a5e23f3eee943593759b7fcddb00554332e856d990c893966879fb"
"checksum vec_map 0.8.2 (registry+https://github.com/rust-lang/crates.io-index)" = "f1bddf1187be692e79c5ffeab891132dfb0f236ed36a43c7ed39f1165ee20191"
"checksum version_check 0.9.2 (registry+https://github.com/rust-lang/crates.io-index)" = "b5a972e5669d67ba988ce3dc826706fb0a8b01471c088cb0b6110b805cc36aed"
--- a/rust/hg-core/src/dirstate/parsers.rs Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/hg-core/src/dirstate/parsers.rs Tue Feb 16 13:08:37 2021 +0100
@@ -26,6 +26,14 @@
Vec<(&'a HgPath, &'a HgPath)>,
);
+pub fn parse_dirstate_parents(
+ contents: &[u8],
+) -> Result<&DirstateParents, HgError> {
+ let (parents, _rest) = DirstateParents::from_bytes(contents)
+ .map_err(|_| HgError::corrupted("Too little data for dirstate."))?;
+ Ok(parents)
+}
+
#[timed]
pub fn parse_dirstate(mut contents: &[u8]) -> Result<ParseResult, HgError> {
let mut copies = Vec::new();
--- a/rust/hg-core/src/repo.rs Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/hg-core/src/repo.rs Tue Feb 16 13:08:37 2021 +0100
@@ -214,6 +214,15 @@
base: &self.working_directory,
}
}
+
+ pub fn dirstate_parents(
+ &self,
+ ) -> Result<crate::dirstate::DirstateParents, HgError> {
+ let dirstate = self.hg_vfs().mmap_open("dirstate")?;
+ let parents =
+ crate::dirstate::parsers::parse_dirstate_parents(&dirstate)?;
+ Ok(parents.clone())
+ }
}
impl Vfs<'_> {
--- a/rust/hg-core/src/utils.rs Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/hg-core/src/utils.rs Tue Feb 16 13:08:37 2021 +0100
@@ -188,6 +188,35 @@
}
}
+#[cfg(unix)]
+pub fn shell_quote(value: &[u8]) -> Vec<u8> {
+ // TODO: Use the `matches!` macro when we require Rust 1.42+
+ if value.iter().all(|&byte| match byte {
+ b'a'..=b'z'
+ | b'A'..=b'Z'
+ | b'0'..=b'9'
+ | b'.'
+ | b'_'
+ | b'/'
+ | b'+'
+ | b'-' => true,
+ _ => false,
+ }) {
+ value.to_owned()
+ } else {
+ let mut quoted = Vec::with_capacity(value.len() + 2);
+ quoted.push(b'\'');
+ for &byte in value {
+ if byte == b'\'' {
+ quoted.push(b'\\');
+ }
+ quoted.push(byte);
+ }
+ quoted.push(b'\'');
+ quoted
+ }
+}
+
pub fn current_dir() -> Result<std::path::PathBuf, HgError> {
std::env::current_dir().map_err(|error| HgError::IoError {
error,
--- a/rust/rhg/Cargo.toml Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/rhg/Cargo.toml Tue Feb 16 13:08:37 2021 +0100
@@ -9,9 +9,11 @@
[dependencies]
hg-core = { path = "../hg-core"}
+chrono = "0.4.19"
clap = "2.33.1"
derive_more = "0.99"
log = "0.4.11"
micro-timer = "0.3.1"
env_logger = "0.7.1"
format-bytes = "0.2.0"
+users = "0.11.0"
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/rust/rhg/src/blackbox.rs Tue Feb 16 13:08:37 2021 +0100
@@ -0,0 +1,161 @@
+//! Logging for repository events, including commands run in the repository.
+
+use crate::CliInvocation;
+use format_bytes::format_bytes;
+use hg::errors::HgError;
+use hg::repo::Repo;
+use hg::utils::{files::get_bytes_from_os_str, shell_quote};
+
+const ONE_MEBIBYTE: u64 = 1 << 20;
+
+// TODO: somehow keep defaults in sync with `configitem` in `hgext/blackbox.py`
+const DEFAULT_MAX_SIZE: u64 = ONE_MEBIBYTE;
+const DEFAULT_MAX_FILES: u32 = 7;
+
+// Python does not support %.3f, only %f
+const DEFAULT_DATE_FORMAT: &str = "%Y/%m/%d %H:%M:%S%.3f";
+
+type DateTime = chrono::DateTime<chrono::Local>;
+
+pub struct ProcessStartTime {
+ /// For measuring duration
+ monotonic_clock: std::time::Instant,
+ /// For formatting with year, month, day, etc.
+ calendar_based: DateTime,
+}
+
+impl ProcessStartTime {
+ pub fn now() -> Self {
+ Self {
+ monotonic_clock: std::time::Instant::now(),
+ calendar_based: chrono::Local::now(),
+ }
+ }
+}
+
+pub struct Blackbox<'a> {
+ process_start_time: &'a ProcessStartTime,
+ /// Do nothing if this is `None`
+ configured: Option<ConfiguredBlackbox<'a>>,
+}
+
+struct ConfiguredBlackbox<'a> {
+ repo: &'a Repo,
+ max_size: u64,
+ max_files: u32,
+ date_format: &'a str,
+}
+
+impl<'a> Blackbox<'a> {
+ pub fn new(
+ invocation: &'a CliInvocation<'a>,
+ process_start_time: &'a ProcessStartTime,
+ ) -> Result<Self, HgError> {
+ let configured = if let Ok(repo) = invocation.repo {
+ let config = invocation.config();
+ if config.get(b"extensions", b"blackbox").is_none() {
+ // The extension is not enabled
+ None
+ } else {
+ Some(ConfiguredBlackbox {
+ repo,
+ max_size: config
+ .get_byte_size(b"blackbox", b"maxsize")?
+ .unwrap_or(DEFAULT_MAX_SIZE),
+ max_files: config
+ .get_u32(b"blackbox", b"maxfiles")?
+ .unwrap_or(DEFAULT_MAX_FILES),
+ date_format: config
+ .get_str(b"blackbox", b"date-format")?
+ .unwrap_or(DEFAULT_DATE_FORMAT),
+ })
+ }
+ } else {
+ // Without a local repository there’s no `.hg/blackbox.log` to
+ // write to.
+ None
+ };
+ Ok(Self {
+ process_start_time,
+ configured,
+ })
+ }
+
+ pub fn log_command_start(&self) {
+ if let Some(configured) = &self.configured {
+ let message = format_bytes!(b"(rust) {}", format_cli_args());
+ configured.log(&self.process_start_time.calendar_based, &message);
+ }
+ }
+
+ pub fn log_command_end(&self, exit_code: i32) {
+ if let Some(configured) = &self.configured {
+ let now = chrono::Local::now();
+ let duration = self
+ .process_start_time
+ .monotonic_clock
+ .elapsed()
+ .as_secs_f64();
+ let message = format_bytes!(
+ b"(rust) {} exited {} after {} seconds",
+ format_cli_args(),
+ exit_code,
+ format_bytes::Utf8(format_args!("{:.03}", duration))
+ );
+ configured.log(&now, &message);
+ }
+ }
+}
+
+impl ConfiguredBlackbox<'_> {
+ fn log(&self, date_time: &DateTime, message: &[u8]) {
+ let date = format_bytes::Utf8(date_time.format(self.date_format));
+ let user = users::get_current_username().map(get_bytes_from_os_str);
+ let user = user.as_deref().unwrap_or(b"???");
+ let rev = format_bytes::Utf8(match self.repo.dirstate_parents() {
+ Ok(parents) if parents.p2 == hg::revlog::node::NULL_NODE => {
+ format!("{:x}", parents.p1)
+ }
+ Ok(parents) => format!("{:x}+{:x}", parents.p1, parents.p2),
+ Err(_dirstate_corruption_error) => {
+ // TODO: log a non-fatal warning to stderr
+ "???".to_owned()
+ }
+ });
+ let pid = std::process::id();
+ let line = format_bytes!(
+ b"{} {} @{} ({})> {}\n",
+ date,
+ user,
+ rev,
+ pid,
+ message
+ );
+ let result =
+ hg::logging::LogFile::new(self.repo.hg_vfs(), "blackbox.log")
+ .max_size(Some(self.max_size))
+ .max_files(self.max_files)
+ .write(&line);
+ match result {
+ Ok(()) => {}
+ Err(_io_error) => {
+ // TODO: log a non-fatal warning to stderr
+ }
+ }
+ }
+}
+
+fn format_cli_args() -> Vec<u8> {
+ let mut args = std::env::args_os();
+ let _ = args.next(); // Skip the first (or zeroth) arg, the name of the `rhg` executable
+ let mut args = args.map(|arg| shell_quote(&get_bytes_from_os_str(arg)));
+ let mut formatted = Vec::new();
+ if let Some(arg) = args.next() {
+ formatted.extend(arg)
+ }
+ for arg in args {
+ formatted.push(b' ');
+ formatted.extend(arg)
+ }
+ formatted
+}
--- a/rust/rhg/src/main.rs Wed Feb 17 13:00:25 2021 +0100
+++ b/rust/rhg/src/main.rs Tue Feb 16 13:08:37 2021 +0100
@@ -9,6 +9,7 @@
use hg::repo::{Repo, RepoError};
use std::path::{Path, PathBuf};
+mod blackbox;
mod error;
mod exitcode;
mod ui;
@@ -36,7 +37,10 @@
)
}
-fn main_with_result(ui: &ui::Ui) -> Result<(), CommandError> {
+fn main_with_result(
+ ui: &ui::Ui,
+ process_start_time: &blackbox::ProcessStartTime,
+) -> Result<(), CommandError> {
env_logger::init();
let app = App::new("rhg")
.setting(AppSettings::AllowInvalidUtf8)
@@ -83,35 +87,47 @@
Err(error) => return Err(error.into()),
};
- run(&CliInvocation {
+ let invocation = CliInvocation {
ui,
subcommand_args,
non_repo_config,
repo: repo.as_ref(),
- })
+ };
+ let blackbox = blackbox::Blackbox::new(&invocation, process_start_time)?;
+ blackbox.log_command_start();
+ let result = run(&invocation);
+ blackbox.log_command_end(exit_code(&result));
+ result
}
fn main() {
+ // Run this first, before we find out if the blackbox extension is even
+ // enabled, in order to include everything in-between in the duration
+ // measurements. Reading config files can be slow if they’re on NFS.
+ let process_start_time = blackbox::ProcessStartTime::now();
+
let ui = ui::Ui::new();
- let exit_code = match main_with_result(&ui) {
+ let result = main_with_result(&ui, &process_start_time);
+ if let Err(CommandError::Abort { message }) = &result {
+ if !message.is_empty() {
+ // Ignore errors when writing to stderr, we’re already exiting
+ // with failure code so there’s not much more we can do.
+ let _ = ui.write_stderr(&format_bytes!(b"abort: {}\n", message));
+ }
+ }
+ std::process::exit(exit_code(&result))
+}
+
+fn exit_code(result: &Result<(), CommandError>) -> i32 {
+ match result {
Ok(()) => exitcode::OK,
+ Err(CommandError::Abort { .. }) => exitcode::ABORT,
// Exit with a specific code and no error message to let a potential
// wrapper script fallback to Python-based Mercurial.
Err(CommandError::Unimplemented) => exitcode::UNIMPLEMENTED,
-
- Err(CommandError::Abort { message }) => {
- if !message.is_empty() {
- // Ignore errors when writing to stderr, we’re already exiting
- // with failure code so there’s not much more we can do.
- let _ =
- ui.write_stderr(&format_bytes!(b"abort: {}\n", message));
- }
- exitcode::ABORT
- }
- };
- std::process::exit(exit_code)
+ }
}
macro_rules! subcommands {
--- a/tests/test-rhg.t Wed Feb 17 13:00:25 2021 +0100
+++ b/tests/test-rhg.t Tue Feb 16 13:08:37 2021 +0100
@@ -261,3 +261,15 @@
$ rhg cat -r 0 a
a
+The blackbox extension is supported
+
+ $ echo "[extensions]" >> $HGRCPATH
+ $ echo "blackbox =" >> $HGRCPATH
+ $ echo "[blackbox]" >> $HGRCPATH
+ $ echo "maxsize = 1" >> $HGRCPATH
+ $ rhg files > /dev/null
+ $ cat .hg/blackbox.log
+ ????/??/?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files exited 0 after 0.??? seconds (glob)
+ $ cat .hg/blackbox.log.1
+ ????/??/?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files (glob)
+