Parse command start

CHANGELOG.md

@@ -2,6 +2,10 @@
 
 ## New features
 
+* `log` and `stat` can now show emerge command start events
+  - Not end events, as `emerge.log` doesn't provide enough info to make this reliable
+* `--from` and `--to` now accept a command index as argument
+  - `--from=1command` or `-fc` is roughly equivalent to qlop's `--lastmerge`
 * `predict` now displays emerge proces tree instead of just top proces
   - Bevahvior configurable with `--pdepth`, `--pwidth`
   - Format is a bit nicer and more colorful

benches/emerge.log

@@ -100008,3 +100008,17 @@
 1602189661: >>> Syncing repository 'moltonel' into '/var/db/repos/moltonel'...
 1602189662: === Sync completed for moltonel
 1602189663:  *** terminating.
+1602190319: Started emerge on: Mar 10, 2019 15:55:18
+1602190319:  *** emerge --newuse --update --backtrack=100 --deep --quiet-build=y --verbose world
+1602190389:  >>> emerge (1 of 1) www-client/chromium-72.0.3626.121 to /
+1602190389:  === (1 of 1) Cleaning (www-client/chromium-72.0.3626.121::/usr/portage/www-client/chromium/chromium-72.0.3626.121.ebuild)
+1602190391:  === (1 of 1) Compiling/Merging (www-client/chromium-72.0.3626.121::/usr/portage/www-client/chromium/chromium-72.0.3626.121.ebuild)
+1602190620:  === (1 of 1) Merging (www-client/chromium-72.0.3626.121::/usr/portage/www-client/chromium/chromium-72.0.3626.121.ebuild)
+1602190624:  >>> AUTOCLEAN: www-client/chromium:0
+1602190624:  === Unmerging... (www-client/chromium-72.0.3626.96)
+1602190626:  >>> unmerge success: www-client/chromium-72.0.3626.96
+1602190635:  === (1 of 1) Post-Build Cleaning (www-client/chromium-72.0.3626.121::/usr/portage/www-client/chromium/chromium-72.0.3626.121.ebuild)
+1602190635:  ::: completed emerge (1 of 1) www-client/chromium-72.0.3626.121 to /
+1602190635:  *** Finished. Cleaning up...
+1602190636:  *** exiting successfully.
+1602190637:  *** terminating.

benches/exec_compare.rs

@@ -61,6 +61,8 @@ fn main() {
         ("ld2", "genlop", &["-f","{emerge.log}","-l", "--date","2020-10-01","--date","2020-10-31"], None),
         ("ld2", "qlop",   &["-f","{emerge.log}","-mv","--date","2020-10-01","--date","2020-10-31"], None),
         ("ld2", "emlop",  &["-F","{emerge.log}","l",  "--from","2020-10-01","--to",  "2020-10-31"], None),
+        ("ldl", "qlop",   &["-f","{emerge.log}","-mv","--lastmerge"], None),
+        ("ldl", "emlop",  &["-F","{emerge.log}","l","--from=1c"],   None),
         // Force/prevent color output
         ("lc", "qlop",   &["-f","{emerge.log}","-mv","--color"],   None),
         ("lc", "emlop",  &["-F","{emerge.log}","l","--color=y"],   None),

docs/COMPARISON.md

@@ -89,16 +89,16 @@ For relative dates, genlop accepts fancy strings like "last month" or "2 weeks a
 less flexible but less verbose (no "ago" needed), and emlop only accepts a number of days/weeks/etc
 which can be abbreviated (for example "1 week, 3 days" -> "1w3d").
 
-|                                          | genlop      | qlop  | emlop       |
-|:-----------------------------------------|:-----------:|:-----:|:-----------:|
-| Limit log parsing by date                | yes         | yes   | yes         |
-| Limit log to number fisrt/last n entries | no          | no    | yes         |
-| Limit log to last emerge operation       | no          | yes   | no          |
-| Filter by package categ/name             | yes         | yes   | yes         |
-| Filter by sync repo                      | no          | no    | yes         |
-| Read filter list from file               | no          | yes   | no          |
-| Search modes                             | plain/regex | plain | plain/regex |
-| Default search mode                      | plain       | plain | regex       |
+|                                          | genlop      | qlop      | emlop       |
+|:-----------------------------------------|:-----------:|:---------:|:-----------:|
+| Limit log parsing by date                | yes         | yes       | yes         |
+| Limit log to number fisrt/last n entries | no          | no        | yes         |
+| Limit log to nth emerge operation        | no          | last only | yes         |
+| Filter by package categ/name             | yes         | yes       | yes         |
+| Filter by sync repo                      | no          | no        | yes         |
+| Read filter list from file               | no          | yes       | no          |
+| Search modes                             | plain/regex | plain     | plain/regex |
+| Default search mode                      | plain       | plain     | regex       |
 
 ## Merge time prediction
 

src/commands.rs

@@ -10,13 +10,19 @@ pub fn cmd_log(gc: Conf, sc: ConfLog) -> Result<bool, Error> {
     let hist = get_hist(&gc.logfile, gc.from, gc.to, sc.show, &sc.search, sc.exact)?;
     let mut merges: HashMap<String, i64> = HashMap::new();
     let mut unmerges: HashMap<String, i64> = HashMap::new();
-    let mut found = 0;
     let mut sync_start: Option<i64> = None;
+    let mut found = 0;
     let h = ["Date", "Duration", "Package/Repo"];
     let mut tbl =
         Table::new(&gc).align_left(0).align_left(2).margin(2, " ").last(sc.last).header(h);
     for p in hist {
         match p {
+            Hist::CmdStart { ts, args, .. } => {
+                found += 1;
+                if found <= sc.first {
+                    tbl.row([&[&FmtDate(ts)], &[], &[&"Emerge ", &args]]);
+                }
+            },
             Hist::MergeStart { ts, key, .. } => {
                 // This'll overwrite any previous entry, if a merge started but never finished
                 merges.insert(key, ts);
@@ -137,12 +143,37 @@ impl Times {
     }
 }
 
+/// Classify emerge commands by looking at their args.
+///
+/// Note that some commands don't get logged at all, so this enum is quite limited.
+#[derive(PartialEq, Eq, PartialOrd, Ord)]
+enum ArgKind {
+    All,
+    Merge,
+    Clean,
+    Sync,
+}
+impl ArgKind {
+    fn new(args: &str) -> Self {
+        for arg in args.split_ascii_whitespace() {
+            match arg {
+                "--deselect" | "--unmerge" | "--clean" | "--depclean" => return Self::Clean,
+                "--sync" => return Self::Sync,
+                _ => (),
+            }
+        }
+        Self::Merge
+    }
+}
+
 /// Summary display of merge events
 ///
 /// First loop is like cmd_list but we store the merge time for each ebuild instead of printing it.
 /// Then we compute the stats per ebuild, and print that.
 pub fn cmd_stats(gc: Conf, sc: ConfStats) -> Result<bool, Error> {
     let hist = get_hist(&gc.logfile, gc.from, gc.to, sc.show, &sc.search, sc.exact)?;
+    let h = [sc.group.name(), "Logged emerges", "Install/Update", "Unmerge/Clean", "Sync"];
+    let mut tblc = Table::new(&gc).margin(1, " ").header(h);
     let h = [sc.group.name(), "Repo", "Syncs", "Total time", "Predict time"];
     let mut tbls = Table::new(&gc).align_left(0).align_left(1).margin(1, " ").header(h);
     let h = [sc.group.name(),
@@ -167,6 +198,7 @@ pub fn cmd_stats(gc: Conf, sc: ConfStats) -> Result<bool, Error> {
     let mut pkg_time: BTreeMap<String, (Times, Times)> = BTreeMap::new();
     let mut sync_start: Option<i64> = None;
     let mut sync_time: BTreeMap<String, Times> = BTreeMap::new();
+    let mut cmd_args: BTreeMap<ArgKind, usize> = BTreeMap::new();
     let mut nextts = 0;
     let mut curts = 0;
     for p in hist {
@@ -177,15 +209,20 @@ pub fn cmd_stats(gc: Conf, sc: ConfStats) -> Result<bool, Error> {
                 curts = t;
             } else if t > nextts {
                 let group = sc.group.at(curts, gc.date_offset);
-                cmd_stats_group(&gc, &sc, &mut tbls, &mut tblp, &mut tblt, group, &sync_time,
-                                &pkg_time);
+                cmd_stats_group(&gc, &sc, &mut tblc, &mut tbls, &mut tblp, &mut tblt, group,
+                                &cmd_args, &sync_time, &pkg_time);
                 sync_time.clear();
                 pkg_time.clear();
+                cmd_args.clear();
                 nextts = sc.group.next(t, gc.date_offset);
                 curts = t;
             }
         }
         match p {
+            Hist::CmdStart { args, .. } => {
+                *cmd_args.entry(ArgKind::All).or_insert(0) += 1;
+                *cmd_args.entry(ArgKind::new(&args)).or_insert(0) += 1;
+            },
             Hist::MergeStart { ts, key, .. } => {
                 merge_start.insert(key, ts);
             },
@@ -221,15 +258,20 @@ pub fn cmd_stats(gc: Conf, sc: ConfStats) -> Result<bool, Error> {
         }
     }
     let group = sc.group.at(curts, gc.date_offset);
-    cmd_stats_group(&gc, &sc, &mut tbls, &mut tblp, &mut tblt, group, &sync_time, &pkg_time);
+    cmd_stats_group(&gc, &sc, &mut tblc, &mut tbls, &mut tblp, &mut tblt, group, &cmd_args,
+                    &sync_time, &pkg_time);
     // Controlled drop to ensure table order and insert blank lines
-    let (es, ep, et) = (!tbls.is_empty(), !tblp.is_empty(), !tblt.is_empty());
+    let (ec, es, ep, et) = (!tblc.is_empty(), !tbls.is_empty(), !tblp.is_empty(), !tblt.is_empty());
+    drop(tblc);
+    if ec && es {
+        println!();
+    }
     drop(tbls);
-    if es && ep {
+    if (ec || es) && ep {
         println!();
     }
     drop(tblp);
-    if (es || ep) && et {
+    if (ec || es || ep) && et {
         println!();
     }
     drop(tblt);
@@ -240,12 +282,22 @@ pub fn cmd_stats(gc: Conf, sc: ConfStats) -> Result<bool, Error> {
 #[allow(clippy::too_many_arguments)]
 fn cmd_stats_group(gc: &Conf,
                    sc: &ConfStats,
+                   tblc: &mut Table<5>,
                    tbls: &mut Table<5>,
                    tblp: &mut Table<8>,
                    tblt: &mut Table<7>,
                    group: String,
+                   cmd_args: &BTreeMap<ArgKind, usize>,
                    sync_time: &BTreeMap<String, Times>,
                    pkg_time: &BTreeMap<String, (Times, Times)>) {
+    // Commands
+    if sc.show.cmd && !cmd_args.is_empty() {
+        tblc.row([&[&group],
+                  &[&gc.cnt, cmd_args.get(&ArgKind::All).unwrap_or(&0)],
+                  &[&gc.cnt, cmd_args.get(&ArgKind::Merge).unwrap_or(&0)],
+                  &[&gc.cnt, cmd_args.get(&ArgKind::Clean).unwrap_or(&0)],
+                  &[&gc.cnt, cmd_args.get(&ArgKind::Sync).unwrap_or(&0)]]);
+    }
     // Syncs
     if sc.show.sync && !sync_time.is_empty() {
         for (repo, time) in sync_time {

src/config.rs

@@ -37,8 +37,8 @@ pub struct Conf {
     pub date_fmt: DateStyle,
     pub out: OutStyle,
     pub logfile: String,
-    pub from: Option<i64>,
-    pub to: Option<i64>,
+    pub from: TimeBound,
+    pub to: TimeBound,
 }
 pub struct ConfLog {
     pub show: Show,
@@ -153,10 +153,11 @@ impl Conf {
         let outdef = if isterm { OutStyle::Columns } else { OutStyle::Tab };
         let offset = get_offset(sel!(cli, toml, utc, (), false)?);
         Ok(Self { logfile: sel!(cli, toml, logfile, (), String::from("/var/log/emerge.log"))?,
-                  from: cli.get_one("from")
-                           .map(|d| i64::parse(d, offset, "--from"))
-                           .transpose()?,
-                  to: cli.get_one("to").map(|d| i64::parse(d, offset, "--to")).transpose()?,
+                  from:
+                      cli.get_one("from")
+                         .map_or(Ok(TimeBound::None), |d| TimeBound::parse(d, offset, "--from"))?,
+                  to: cli.get_one("to")
+                         .map_or(Ok(TimeBound::None), |d| TimeBound::parse(d, offset, "--to"))?,
                   pkg: AnsiStr::from(if color { "\x1B[1;32m" } else { "" }),
                   merge: AnsiStr::from(if color { "\x1B[1;32m" } else { ">>> " }),
                   unmerge: AnsiStr::from(if color { "\x1B[1;31m" } else { "<<< " }),
@@ -181,7 +182,7 @@ impl Conf {
 
 impl ConfLog {
     fn try_new(cli: &ArgMatches, toml: &Toml) -> Result<Self, Error> {
-        Ok(Self { show: sel!(cli, toml, log, show, "musa", Show::m())?,
+        Ok(Self { show: sel!(cli, toml, log, show, "cmusa", Show::m())?,
                   search: cli.get_many("search").unwrap_or_default().cloned().collect(),
                   exact: cli.get_flag("exact"),
                   starttime: sel!(cli, toml, log, starttime, (), false)?,
@@ -220,7 +221,7 @@ impl ConfPred {
 
 impl ConfStats {
     fn try_new(cli: &ArgMatches, toml: &Toml) -> Result<Self, Error> {
-        Ok(Self { show: sel!(cli, toml, stats, show, "ptsa", Show::p())?,
+        Ok(Self { show: sel!(cli, toml, stats, show, "cptsa", Show::p())?,
                   search: cli.get_many("search").unwrap_or_default().cloned().collect(),
                   exact: cli.get_flag("exact"),
                   lim: sel!(cli, toml, stats, limit, 1..=65000, 10)? as u16,

src/config/cli.rs

@@ -30,28 +30,32 @@ pub fn build_cli() -> Command {
                                              virtual/rust: Matches only `virtual/rust`\n  \
                                              RuSt:         Matches nothing (case-sensitive)\n  \
                                              ru:           Matches nothing (whole name only)");
-    let show_l = Arg::new("show").short('s')
-                                 .long("show")
-                                 .value_name("m,u,s,a")
-                                 .display_order(3)
-                                 .help_heading("Filter")
-                                 .help("Show (m)erges, (u)nmerges, (s)yncs, and/or (a)ll")
-                                 .long_help("Show (any combination of)\n  \
-                                             m: Package merges\n  \
-                                             u: Package unmerges\n  \
-                                             s: Repository syncs\n  \
-                                             a: All of the above");
-    let show_s = Arg::new("show").short('s')
-                                 .long("show")
-                                 .value_name("p,t,s,a")
-                                 .display_order(3)
-                                 .help_heading("Filter")
-                                 .help("Show (p)ackages, (t)otals, (s)yncs, and/or (a)ll")
-                                 .long_help("Show (any combination of)\n  \
-                                             p: Individual package merges/unmerges\n  \
-                                             t: Total package merges/unmerges\n  \
-                                             s: Repository syncs\n  \
-                                             a: All of the above");
+    let show_l =
+        Arg::new("show").short('s')
+                        .long("show")
+                        .value_name("c,m,u,s,a")
+                        .display_order(3)
+                        .help_heading("Filter")
+                        .help("Show (c)commands, (m)erges, (u)nmerges, (s)yncs, and/or (a)ll")
+                        .long_help("Show (any combination of)\n  \
+                                    c: Emerge command\n  \
+                                    m: Package merges\n  \
+                                    u: Package unmerges\n  \
+                                    s: Repository syncs\n  \
+                                    a: All of the above");
+    let show_s =
+        Arg::new("show").short('s')
+                        .long("show")
+                        .value_name("c,p,t,s,a")
+                        .display_order(3)
+                        .help_heading("Filter")
+                        .help("Show (c)commands, (p)ackages, (t)otals, (s)yncs, and/or (a)ll")
+                        .long_help("Show (any combination of)\n  \
+                                    c: Emerge commands\n  \
+                                    p: Individual package merges/unmerges\n  \
+                                    t: Total package merges/unmerges\n  \
+                                    s: Repository syncs\n  \
+                                    a: All of the above");
     let show_p = Arg::new("show").short('s')
                                  .long("show")
                                  .value_name("e,m,t,a")
@@ -73,10 +77,11 @@ pub fn build_cli() -> Command {
                                              m: Package merges\n  \
                                              t: Totals\n  \
                                              a: All of the above");
-    let h = "Only parse log entries after <date>\n  \
+    let h = "Only parse log entries after <date/command>\n  \
              2018-03-04|2018-03-04 12:34:56|2018-03-04T12:34: Absolute ISO date\n  \
              123456789:                                       Absolute unix timestamp\n  \
-             1 year, 2 months|10d:                            Relative date";
+             1 year, 2 months|10d:                            Relative date\n  \
+             1c|2 commands|c                                  Nth emerge command";
     let from = Arg::new("from").short('f')
                                .long("from")
                                .value_name("date")
@@ -86,10 +91,11 @@ pub fn build_cli() -> Command {
                                .help_heading("Filter")
                                .help(h.split_once('\n').unwrap().0)
                                .long_help(h);
-    let h = "Only parse log entries before <date>\n  \
+    let h = "Only parse log entries before <date/command>\n  \
              2018-03-04|2018-03-04 12:34:56|2018-03-04T12:34: Absolute ISO date\n  \
              123456789:                                       Absolute unix timestamp\n  \
-             1 year, 2 months|10d:                            Relative date";
+             1 year, 2 months|10d:                            Relative date\n  \
+             1c|2 commands|c                                  Nth-last emerge command";
     let to = Arg::new("to").short('t')
                            .long("to")
                            .value_name("date")
@@ -136,7 +142,7 @@ pub fn build_cli() -> Command {
                                    .hide_possible_values(true)
                                    .num_args(..=1)
                                    .default_missing_value("either")
-                                   .display_order(8)
+                                   .display_order(9)
                                    .help_heading("Filter")
                                    .help(h.split_once('\n').unwrap().0)
                                    .long_help(h);