Mercurial > hg

changeset 44541:d880805d5442

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
hg-core: add function timing information This change makes use of the newly added logging infrastructure to trace the execution time of some important calls. This approach is very much complementary to using a profiler and will not guard against out-of-order execution or other kinds of compiler optimizations. That said, it is useful to get a rough high-level idea of where time is spent. Differential Revision: https://phab.mercurial-scm.org/D8253
author Raphaël Gomès <rgomes@octobus.net>
date Fri, 06 Mar 2020 18:08:23 +0100
parents 82f51ab7a2dd
children a2b49606a837
files rust/Cargo.lock rust/hg-core/Cargo.toml rust/hg-core/src/dirstate/parsers.rs rust/hg-core/src/dirstate/status.rs rust/hg-core/src/lib.rs rust/hg-core/src/matchers.rs
diffstat 6 files changed, 28 insertions(+), 0 deletions(-) [+]
line wrap: on
line diff
--- a/rust/Cargo.lock	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/Cargo.lock	Fri Mar 06 18:08:23 2020 +0100
@@ -235,6 +235,7 @@
  "log 0.4.8 (registry+https://github.com/rust-lang/crates.io-index)",
  "memchr 2.3.3 (registry+https://github.com/rust-lang/crates.io-index)",
  "memmap 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)",
+ "micro-timer 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)",
  "pretty_assertions 0.6.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "rand 0.6.5 (registry+https://github.com/rust-lang/crates.io-index)",
  "rand_pcg 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -301,6 +302,16 @@
 ]
 
 [[package]]
+name = "micro-timer"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+dependencies = [
+ "proc-macro2 1.0.9 (registry+https://github.com/rust-lang/crates.io-index)",
+ "quote 1.0.3 (registry+https://github.com/rust-lang/crates.io-index)",
+ "syn 1.0.16 (registry+https://github.com/rust-lang/crates.io-index)",
+]
+
+[[package]]
 name = "num-integer"
 version = "0.1.42"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -766,6 +777,7 @@
 "checksum memchr 2.3.3 (registry+https://github.com/rust-lang/crates.io-index)" = "3728d817d99e5ac407411fa471ff9800a778d88a24685968b36824eaf4bee400"
 "checksum memmap 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)" = "6585fd95e7bb50d6cc31e20d4cf9afb4e2ba16c5846fc76793f11218da9c475b"
 "checksum memoffset 0.5.3 (registry+https://github.com/rust-lang/crates.io-index)" = "75189eb85871ea5c2e2c15abbdd541185f63b408415e5051f5cac122d8c774b9"
+"checksum micro-timer 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "16439fea388f712c1df7737ceb8f784d407844624b4796faf1e1bf8bbaa97445"
 "checksum num-integer 0.1.42 (registry+https://github.com/rust-lang/crates.io-index)" = "3f6ea62e9d81a77cd3ee9a2a5b9b609447857f3d358704331e4ef39eb247fcba"
 "checksum num-traits 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)" = "c62be47e61d1842b9170f0fdeec8eba98e60e90e5446449a0545e5152acd7096"
 "checksum num_cpus 1.12.0 (registry+https://github.com/rust-lang/crates.io-index)" = "46203554f085ff89c235cd12f7075f3233af9b11ed7c9e16dfe2560d03313ce6"
--- a/rust/hg-core/Cargo.toml	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/hg-core/Cargo.toml	Fri Mar 06 18:08:23 2020 +0100
@@ -22,6 +22,7 @@
 twox-hash = "1.5.0"
 same-file = "1.0.6"
 crossbeam = "0.7.3"
+micro-timer = "0.1.2"
 log = "0.4.8"
 
 [dev-dependencies]
--- a/rust/hg-core/src/dirstate/parsers.rs	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/hg-core/src/dirstate/parsers.rs	Fri Mar 06 18:08:23 2020 +0100
@@ -9,6 +9,7 @@
     DirstateEntry, DirstatePackError, DirstateParents, DirstateParseError,
 };
 use byteorder::{BigEndian, ReadBytesExt, WriteBytesExt};
+use micro_timer::timed;
 use std::convert::{TryFrom, TryInto};
 use std::io::Cursor;
 use std::time::Duration;
@@ -20,6 +21,7 @@
 
 // TODO parse/pack: is mutate-on-loop better for performance?
 
+#[timed]
 pub fn parse_dirstate(
     state_map: &mut StateMap,
     copy_map: &mut CopyMap,
--- a/rust/hg-core/src/dirstate/status.rs	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/hg-core/src/dirstate/status.rs	Fri Mar 06 18:08:23 2020 +0100
@@ -25,6 +25,7 @@
     PatternError,
 };
 use lazy_static::lazy_static;
+use micro_timer::timed;
 use rayon::prelude::*;
 use std::{
     borrow::Cow,
@@ -211,6 +212,7 @@
 
 /// Get stat data about the files explicitly specified by match.
 /// TODO subrepos
+#[timed]
 fn walk_explicit<'a>(
     files: Option<&'a HashSet<&HgPath>>,
     dmap: &'a DirstateMap,
@@ -513,6 +515,7 @@
 ///
 /// This takes a mutable reference to the results to account for the `extend`
 /// in timings
+#[timed]
 fn traverse<'a>(
     matcher: &'a (impl Matcher + Sync),
     root_dir: impl AsRef<Path> + Sync + Send + Copy,
@@ -606,6 +609,7 @@
 
 /// This takes a mutable reference to the results to account for the `extend`
 /// in timings
+#[timed]
 fn extend_from_dmap<'a>(
     dmap: &'a DirstateMap,
     root_dir: impl AsRef<Path> + Sync + Send,
@@ -630,6 +634,7 @@
     pub bad: Vec<(Cow<'a, HgPath>, BadMatch)>,
 }
 
+#[timed]
 fn build_response<'a>(
     results: impl IntoIterator<Item = (Cow<'a, HgPath>, Dispatch)>,
 ) -> (Vec<Cow<'a, HgPath>>, DirstateStatus<'a>) {
@@ -710,6 +715,7 @@
 
 /// This takes a mutable reference to the results to account for the `extend`
 /// in timings
+#[timed]
 fn handle_unknowns<'a>(
     dmap: &'a DirstateMap,
     matcher: &(impl Matcher + Sync),
@@ -792,6 +798,7 @@
 /// This is the current entry-point for `hg-core` and is realistically unusable
 /// outside of a Python context because its arguments need to provide a lot of
 /// information that will not be necessary in the future.
+#[timed]
 pub fn status<'a: 'c, 'b: 'c, 'c>(
     dmap: &'a DirstateMap,
     matcher: &'b (impl Matcher + Sync),
--- a/rust/hg-core/src/lib.rs	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/hg-core/src/lib.rs	Fri Mar 06 18:08:23 2020 +0100
@@ -35,6 +35,10 @@
 use std::collections::HashMap;
 use twox_hash::RandomXxHashBuilder64;
 
+/// This is a contract between the `micro-timer` crate and us, to expose
+/// the `log` crate as `crate::log`.
+use log;
+
 pub type LineNumber = usize;
 
 /// Rust's default hasher is too slow because it tries to prevent collision
--- a/rust/hg-core/src/matchers.rs	Fri Mar 06 18:08:13 2020 +0100
+++ b/rust/hg-core/src/matchers.rs	Fri Mar 06 18:08:23 2020 +0100
@@ -24,6 +24,7 @@
     PatternSyntax,
 };
 
+use micro_timer::timed;
 use std::collections::HashSet;
 use std::fmt::{Display, Error, Formatter};
 use std::iter::FromIterator;
@@ -548,6 +549,7 @@
 /// Parses all "ignore" files with their recursive includes and returns a
 /// function that checks whether a given file (in the general sense) should be
 /// ignored.
+#[timed]
 pub fn get_ignore_function<'a>(
     all_pattern_files: &[impl AsRef<Path>],
     root_dir: impl AsRef<Path>,