hgcommands: start of "runlog" command tracking

Summary:
The runlog's purpose is to store live information for every hg invocations. Users/VSCode will access the runlog data to see details about active hg commands.

In this initial commit I've added basic start/end updates to the runlog. The only current storage option is JSON files written to ".hg/runlog/<random ID>". Cleanup of the files will be added later. In the future I may look at sqlite as an alternative.

Set runlog.enable=True to turn on the runlog.

Reviewed By: quark-zju

Differential Revision: D31065258

fbshipit-source-id: 3ff29e1b8473f7e0b6b0d02537d1f18c2c5026fb

eden/scm/lib/clidispatch/src/dispatch.rs

@@ -9,7 +9,7 @@ use crate::command::{CommandDefinition, CommandFunc, CommandTable};
 use crate::errors;
 use crate::global_flags::HgGlobalOpts;
 use crate::io::IO;
-use crate::repo::OptionalRepo;
+use crate::repo::{OptionalRepo, Repo};
 use anyhow::Error;
 use cliparser::alias::{expand_aliases, find_command_name};
 use cliparser::parser::{ParseError, ParseOptions, ParseOutput, StructFlags};
@@ -206,6 +206,13 @@ impl Dispatcher {
         &self.global_opts
     }
 
+    pub fn repo(&self) -> Option<&Repo> {
+        match &self.optional_repo {
+            OptionalRepo::Some(repo) => Some(repo),
+            _ => None,
+        }
+    }
+
     /// Run a command. Return exit code if the command completes.
     pub fn run_command(self, command_table: &CommandTable, io: &IO) -> Result<u8> {
         let args = &self.args;

eden/scm/lib/hgcommands/Cargo.toml

@@ -39,6 +39,7 @@ python3-sys = { version = "0.5", optional = true }
 pytracing = { path = "../../edenscmnative/bindings/modules/pytracing", default-features = false }
 rand = { version = "0.8", features = ["small_rng"] }
 revisionstore = { path = "../revisionstore" }
+runlog = { path = "../runlog" }
 taggederror = { path = "../taggederror" }
 terminal_size = "0.1"
 tracing = "0.1.27"

eden/scm/lib/hgcommands/src/run.rs

@@ -103,6 +103,8 @@ pub fn run_command(args: Vec<String>, io: &IO) -> i32 {
         Ok(dir) => dir,
     };
 
+    let mut run_logger: Option<Arc<runlog::Logger>> = None;
+
     let exit_code = {
         let _guard = span.enter();
         let in_scope = Arc::new(()); // Used to tell progress rendering thread to stop.
@@ -115,6 +117,8 @@ pub fn run_command(args: Vec<String>, io: &IO) -> i32 {
                 let config = dispatcher.config();
                 let global_opts = dispatcher.global_opts();
 
+                run_logger = Some(runlog::Logger::new(dispatcher.repo(), args[1..].to_vec())?);
+
                 setup_http(config, global_opts);
 
                 let _ = spawn_progress_thread(config, global_opts, io, Arc::downgrade(&in_scope));
@@ -174,6 +178,13 @@ pub fn run_command(args: Vec<String>, io: &IO) -> i32 {
     // so we need to flush now.
     blackbox::sync();
 
+    if let Some(rl) = run_logger {
+        if let Err(err) = rl.close(exit_code) {
+            // Command has already finished - not worth bailing due to this error.
+            let _ = write!(io.error(), "Error writing final runlog: {}\n", err);
+        }
+    }
+
     if let Some(scenario) = scenario {
         scenario.teardown();
         FAIL_SETUP.store(false, SeqCst);

eden/scm/lib/runlog/Cargo.toml

@@ -0,0 +1,16 @@
+# @generated by autocargo from //eden/scm/lib/runlog:runlog
+[package]
+name = "runlog"
+version = "0.1.0"
+edition = "2018"
+
+[dependencies]
+anyhow = "1.0"
+chrono = { version = "0.4", features = ["clock", "serde", "std"], default-features = false }
+clidispatch = { path = "../clidispatch" }
+libc = "0.2.98"
+parking_lot = "0.10.2"
+rand = { version = "0.8", features = ["small_rng"] }
+serde = { version = "1.0.126", features = ["derive", "rc"] }
+serde_json = { version = "1.0", features = ["float_roundtrip"] }
+tempfile = "3.1"

eden/scm/lib/runlog/src/filestore.rs

@@ -0,0 +1,73 @@
+/*
+ * Copyright (c) Facebook, Inc. and its affiliates.
+ *
+ * This software may be used and distributed according to the terms of the
+ * GNU General Public License version 2.
+ */
+
+use anyhow::{anyhow, Result};
+
+use std::{fs, io, path::PathBuf};
+
+use crate::Entry;
+
+#[derive(Clone)]
+pub struct FileStore(PathBuf);
+
+/// FileStore is a simple runlog storage that writes JSON entries to a
+/// specified directory.
+impl FileStore {
+    // Create a new FileStore that writes files to directory p. p is
+    // created automatically if it doesn't exist.
+    pub(crate) fn new(p: PathBuf) -> Result<Self> {
+        match fs::create_dir(&p) {
+            Err(err) if err.kind() == io::ErrorKind::AlreadyExists => {}
+            Err(err) => return Err(anyhow!(err)),
+            Ok(_) => {}
+        }
+        return Ok(FileStore(p));
+    }
+
+    pub(crate) fn save(&self, e: &Entry) -> Result<()> {
+        // Write to temp file and rename to avoid incomplete writes.
+        let mut tmp = tempfile::NamedTempFile::new_in(&self.0)?;
+        serde_json::to_writer_pretty(&tmp, e)?;
+        tmp.as_file_mut().sync_data()?;
+        tmp.persist(self.0.join(&e.id))?;
+        Ok(())
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use tempfile::tempdir;
+
+    use super::*;
+
+    #[test]
+    fn test_save() {
+        let td = tempdir().unwrap();
+
+        let fs_dir = td.path().join("banana");
+        let fs = FileStore::new(fs_dir.clone()).unwrap();
+        // Make sure FileStore creates directory automatically.
+        assert!(fs_dir.exists());
+
+        let mut entry = Entry::new(vec!["some_command".to_string()]);
+
+        let assert_entry = |e: &Entry| {
+            let f = fs::File::open(fs_dir.join(&e.id)).unwrap();
+            let got: Entry = serde_json::from_reader(&f).unwrap();
+            assert_eq!(&got, e);
+        };
+
+        // Can create new entry.
+        fs.save(&entry).unwrap();
+        assert_entry(&entry);
+
+        // Can update existing entry.
+        entry.pid = 1234;
+        fs.save(&entry).unwrap();
+        assert_entry(&entry);
+    }
+}

eden/scm/lib/runlog/src/lib.rs

@@ -0,0 +1,94 @@
+/*
+ * Copyright (c) Facebook, Inc. and its affiliates.
+ *
+ * This software may be used and distributed according to the terms of the
+ * GNU General Public License version 2.
+ */
+
+mod filestore;
+
+pub use filestore::FileStore;
+
+use anyhow::Result;
+use chrono;
+use parking_lot::Mutex;
+use rand::distributions::Alphanumeric;
+use rand::{thread_rng, Rng};
+use serde::{Deserialize, Serialize};
+
+use clidispatch::repo::Repo;
+
+use std::sync::Arc;
+
+/// Logger logs runtime information for a single hg command invocation.
+pub struct Logger {
+    entry: Mutex<Entry>,
+    storage: Option<Mutex<FileStore>>,
+}
+
+impl Logger {
+    /// Initialize a new logger and write out initial runlog entry.
+    /// Respects runlog.enable config field.
+    pub fn new(repo: Option<&Repo>, command: Vec<String>) -> Result<Arc<Self>> {
+        let mut logger = Self {
+            entry: Mutex::new(Entry::new(command)),
+            storage: None,
+        };
+
+        if let Some(repo) = repo {
+            if repo.config().get_or("runlog", "enable", || false)? {
+                logger.storage = Some(Mutex::new(FileStore::new(
+                    repo.shared_dot_hg_path().join("runlog"),
+                )?))
+            }
+        }
+
+        logger.write(&logger.entry.lock())?;
+
+        return Ok(Arc::new(logger));
+    }
+
+    pub fn close(&self, exit_code: i32) -> Result<()> {
+        let mut entry = self.entry.lock();
+        entry.exit_code = Some(exit_code);
+        entry.end_time = Some(chrono::Utc::now());
+
+        self.write(&entry)?;
+
+        Ok(())
+    }
+
+    fn write(&self, e: &Entry) -> Result<()> {
+        if let Some(storage) = &self.storage {
+            let storage = storage.lock();
+            storage.save(e)?;
+        }
+
+        Ok(())
+    }
+}
+
+/// Entry represents one runlog entry (i.e. a single hg command
+/// execution).
+#[derive(Serialize, Deserialize, Debug, Clone, PartialEq)]
+struct Entry {
+    id: String,
+    command: Vec<String>,
+    pid: u64,
+    start_time: chrono::DateTime<chrono::Utc>,
+    end_time: Option<chrono::DateTime<chrono::Utc>>,
+    exit_code: Option<i32>,
+}
+
+impl Entry {
+    fn new(command: Vec<String>) -> Self {
+        Self {
+            id: thread_rng().sample_iter(Alphanumeric).take(16).collect(),
+            command,
+            pid: unsafe { libc::getpid() } as u64,
+            start_time: chrono::Utc::now(),
+            end_time: None,
+            exit_code: None,
+        }
+    }
+}

eden/scm/tests/runlogtest.py

@@ -0,0 +1,43 @@
+# Copyright (c) Facebook, Inc. and its affiliates.
+#
+# This software may be used and distributed according to the terms of the
+# GNU General Public License version 2.
+
+from __future__ import absolute_import
+
+import os.path
+import time
+
+from edenscm.mercurial import registrar
+
+
+cmdtable = {}
+command = registrar.command(cmdtable)
+
+
+@command(
+    "basiccommandtest",
+    [
+        (
+            "",
+            "waitfile",
+            "",
+            "if set, wait for file before exitting",
+        ),
+    ],
+    "hg basiccommandtest exit_code",
+    norepo=True,
+)
+def basiccommandtest(ui, exit_code, **opts):
+    waitforfile(opts.get("waitfile"))
+    exit(int(exit_code))
+
+
+def waitforfile(path):
+    if not path:
+        return
+
+    while not os.path.exists(path):
+        time.sleep(0.001)
+
+    os.unlink(path)

eden/scm/tests/test-runlog.t

@@ -0,0 +1,45 @@
+#chg-compatible
+
+  $ enable progress
+  $ setconfig extensions.rustprogresstest="$TESTDIR/runlogtest.py" runlog.enable=True
+
+  $ waitforrunlog() {
+  >   while ! cat .hg/runlog/* 2> /dev/null; do
+  >     sleep 0.001
+  >   done
+  >   rm .hg/runlog/*
+  >   touch $TESTTMP/go
+  > }
+
+  $ hg init repo && cd repo
+
+Check basic command start/end.
+  $ hg basiccommandtest --waitfile=$TESTTMP/go 123 &
+
+  $ waitforrunlog
+  {
+    "id": ".*", (re)
+    "command": [
+      "basiccommandtest",
+      "--waitfile=$TESTTMP/go",
+      "123"
+    ],
+    "pid": \d+, (re)
+    "start_time": ".*", (re)
+    "end_time": null,
+    "exit_code": null
+  } (no-eol)
+
+  $ waitforrunlog
+  {
+    "id": ".*", (re)
+    "command": [
+      "basiccommandtest",
+      "--waitfile=$TESTTMP/go",
+      "123"
+    ],
+    "pid": \d+, (re)
+    "start_time": ".*", (re)
+    "end_time": ".*", (re)
+    "exit_code": 123
+  } (no-eol)