Mercurial > public > mercurial-scm > hg
view rust/rhg/src/blackbox.rs @ 48178:f12a19d03d2c
fix: reduce number of tool executions
By grouping together (path, ctx) pairs according to the inputs they would
provide to fixer tools, we can deduplicate executions of fixer tools to
significantly reduce the amount of time spent running slow tools.
This change does not handle clean files in the working copy, which could still
be deduplicated against the files in the checked out commit. It's a little
harder to do that because the filerev is not available in the workingfilectx
(and it doesn't exist for added files).
Anecdotally, this change makes some real uses cases at Google 10x faster. I
think we were originally hesitant to do this because the benefits weren't
obvious, and implementing it efficiently is kind of tricky. If we simply
memoized the formatter execution function, we would be keeping tons of file
content in memory.
Also included is a regression test for a corner case that I broke with my first
attempt at optimizing this code.
Differential Revision: https://phab.mercurial-scm.org/D11280
author | Danny Hooper <hooper@google.com> |
---|---|
date | Thu, 02 Sep 2021 14:08:45 -0700 |
parents | 7284b524b441 |
children | abbecb5cd6f3 |
line wrap: on
line source
//! 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 { if invocation.config.get(b"extensions", b"blackbox").is_none() { // The extension is not enabled None } else { Some(ConfiguredBlackbox { repo, max_size: invocation .config .get_byte_size(b"blackbox", b"maxsize")? .unwrap_or(DEFAULT_MAX_SIZE), max_files: invocation .config .get_u32(b"blackbox", b"maxfiles")? .unwrap_or(DEFAULT_MAX_FILES), date_format: invocation .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 }