From db0606e57b4cc7a1cd1835f937c14c81be9eb784 Mon Sep 17 00:00:00 2001 From: Vincent de Phily Date: Thu, 16 Jan 2025 15:36:39 +0000 Subject: [PATCH] qa/docs: Update changelog, add timing logs, demote debugs to traces Interestingly, parsing the mtimedb json takes 3x as long as parsing 65 update files. --- CHANGELOG.md | 12 ++++++++++-- src/parse/current.rs | 10 +++++++--- src/parse/history.rs | 23 +++++++++++++---------- 3 files changed, 30 insertions(+), 15 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4a76092..bca2584 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,11 +1,17 @@ # unreleased +Feature release: Binary merges, package moves, emerge arguments, process tree, configurable colors, +and other goodies. + ## New features * `log`, `stats` and `predict` now take binary merges into account - Track merge time stats separately - Display bin merges in a different color - The `unknown` config has been split into `unknownc` (compiled) and `unknownb` (binary) +* `stats` and `predict` now follow package moves + - Merge time predictions remain correct after a rename like `sys-devel/llvm` -> `llvm-core/llvm` + - `Stats` are aggregated using the latest name * `log` and `stat` can now show emerge (r)runs - Use `--show=r`/`-sr`/`-sa` to enable it - No duration given, as `emerge.log` doesn't provide enough info to make this reliable @@ -13,11 +19,12 @@ - New `command` keyword resolves to the time of the nth emerge command (`-fc` is roughly equivalent to qlop's `--lastmerge`) - A single span (`day`/`y`/`command`/etc) without a count now means that span with a count of 1 + (so `-fd` is equivalent to `-1d`) * `predict` now displays emerge proces tree instead of just top proces - - Bevahvior configurable with `--pdepth`, `--pwidth` + - Behavior configurable with `--pdepth`/`-D`/`--pwidth`/`-W` - Format is a bit nicer and more colorful - `--show=e` renamed `--show=r` (running emerge processes) for consistency -* Display a placeholder for skipped rows, configurable with `--showskip` +* Display a placeholder for skipped rows (`--first`/`--last`/`--pdepth`), configurable with `--showskip` * Colors are now configurable, to match your terminal's theme - Eg `theme = "count:0 duration:1;3;37"` in `emlop.toml` displays counts unstyled and durations in bright italic white. @@ -31,6 +38,7 @@ * Don't display child emerge processes as root ones * Fix off by one upper bound for some cli args * Allow alignment of wider columns +* Fix bright/dim terminal colors for stats counts # 0.7.1 2024-09-30 diff --git a/src/parse/current.rs b/src/parse/current.rs index b34e4e4..9b8875e 100644 --- a/src/parse/current.rs +++ b/src/parse/current.rs @@ -10,7 +10,8 @@ use serde_json::from_reader; use std::{collections::HashMap, fs::File, io::{BufRead, BufReader, Read}, - path::PathBuf}; + path::PathBuf, + time::Instant}; /// Package name and version #[derive(Debug, Clone, PartialEq, Eq, PartialOrd, Ord)] @@ -90,8 +91,11 @@ impl Mtimedb { Self::try_new("/var/cache/edb/mtimedb").unwrap_or_default() } fn try_new(file: &str) -> Option { + let now = Instant::now(); let reader = File::open(file).map_err(|e| warn!("Cannot open {file:?}: {e}")).ok()?; - from_reader(reader).map_err(|e| warn!("Cannot parse {file:?}: {e}")).ok() + let r = from_reader(reader).map_err(|e| warn!("Cannot parse {file:?}: {e}")).ok(); + debug!("Loaded {file} in {:?}", now.elapsed()); + r } } @@ -138,7 +142,7 @@ impl PkgMoves { } fn try_new(db: &Mtimedb) -> Option> { - let now = std::time::Instant::now(); + let now = Instant::now(); // Sort the files in reverse chronological order (compare year, then quarter) let mut files: Vec<_> = db.updates.as_ref()?.keys().collect(); files.sort_by(|a, b| match (a.rsplit_once('/'), b.rsplit_once('/')) { diff --git a/src/parse/history.rs b/src/parse/history.rs index b1da9f1..c07e0b8 100644 --- a/src/parse/history.rs +++ b/src/parse/history.rs @@ -11,7 +11,8 @@ use regex::{Regex, RegexBuilder, RegexSet, RegexSetBuilder}; use std::{fs::File, io::{BufRead, BufReader}, str::from_utf8, - thread}; + thread, + time::Instant}; /// Items sent on the channel returned by `new_hist()`. #[derive(Debug)] @@ -119,8 +120,9 @@ pub fn get_hist(file: &str, search_terms: &Vec, search_exact: bool) -> Result, Error> { - debug!("File: {file}"); - debug!("Show: {show}"); + trace!("Show: {show}"); + let now = Instant::now(); + let logfile = file.to_owned(); let (ts_min, ts_max) = filter_ts(file, min, max)?; let filter = FilterStr::try_new(search_terms, search_exact)?; let mut buf = open_any_buffered(file)?; @@ -139,7 +141,7 @@ pub fn get_hist(file: &str, Ok(_) => { if let Some((t, s)) = parse_ts(&line, ts_min, ts_max) { if prev_t > t { - warn!("logfile:{curline}: System clock jump: {} -> {}", + warn!("{logfile}:{curline}: System clock jump: {} -> {}", fmt_utctime(prev_t), fmt_utctime(t)); } @@ -181,11 +183,12 @@ pub fn get_hist(file: &str, } }, // Could be invalid UTF8, system read error... - Err(e) => warn!("logfile:{curline}: {e}"), + Err(e) => warn!("{logfile}:{curline}: {e}"), } line.clear(); curline += 1; } + debug!("Parsed {curline} {logfile} lines in {:?}", now.elapsed()); }); Ok(rx) } @@ -226,11 +229,11 @@ fn filter_ts(file: &str, min: TimeBound, max: TimeBound) -> Result<(i64, i64), E }; // Check and log bounds, return result match (min, max) { - (None, None) => debug!("Date: None"), - (Some(a), None) => debug!("Date: after {}", fmt_utctime(a)), - (None, Some(b)) => debug!("Date: before {}", fmt_utctime(b)), + (None, None) => trace!("Date: None"), + (Some(a), None) => trace!("Date: after {}", fmt_utctime(a)), + (None, Some(b)) => trace!("Date: before {}", fmt_utctime(b)), (Some(a), Some(b)) if a < b => { - debug!("Date: between {} and {}", fmt_utctime(a), fmt_utctime(b)) + trace!("Date: between {} and {}", fmt_utctime(a), fmt_utctime(b)) }, (Some(a), Some(b)) => { bail!("Invalid date filter: {} <= {}, did you swap --to and --from ?", @@ -250,7 +253,7 @@ enum FilterStr { } impl FilterStr { fn try_new(terms: &Vec, exact: bool) -> Result { - debug!("Search: {terms:?} {exact}"); + trace!("Search: {terms:?} {exact}"); Ok(match (terms.len(), exact) { (0, _) => Self::True, (_, true) => {