annotate rust/rhg/src/blackbox.rs @ 46601:755c31a1caf9

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

//! 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
}