From 422b6ca8719bc6642ecd2d30e7bb2d917680a8f1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Radek=20V=C3=ADt?= Date: Sat, 19 Sep 2020 19:13:14 +0200 Subject: [PATCH] Add system, user and idle times to benchmark command (#2571) * Add system, user and idle times to benchmark command * Feature-gate dependency on heim in benchmark * Reorder let bindings in benchmark * Fully feature-gate rich-benchmark and print 0sec on zero duration --- Cargo.lock | 2 + Cargo.toml | 2 + crates/nu-cli/Cargo.toml | 3 + crates/nu-cli/src/commands/benchmark.rs | 94 +++++++++++++++++++---- crates/nu-protocol/src/value/primitive.rs | 5 +- 5 files changed, 91 insertions(+), 15 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index f8b59f9e33..480a89744a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2916,6 +2916,7 @@ dependencies = [ "getset", "git2", "glob", + "heim", "htmlescape", "ical", "ichwh", @@ -2969,6 +2970,7 @@ dependencies = [ "trash", "umask", "unicode-segmentation", + "uom 0.28.0", "url 2.1.1", "users", "uuid 0.8.1", diff --git a/Cargo.toml b/Cargo.toml index f13d75cc99..5402c69022 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -79,6 +79,7 @@ default = [ "match", "post", "fetch", + "rich-benchmark", ] extra = ["default", "binaryview", "tree", "clipboard-cli", "trash-support", "start", "bson", "sqlite", "s3"] stable = ["default"] @@ -106,6 +107,7 @@ ctrlc-support = ["nu-cli/ctrlc"] directories-support = ["nu-cli/directories", "nu-cli/dirs", "nu-data/directories", "nu-data/dirs"] git-support = ["nu-cli/git2"] ptree-support = ["nu-cli/ptree"] +rich-benchmark = ["nu-cli/rich-benchmark"] rustyline-support = ["nu-cli/rustyline-support"] term-support = ["nu-cli/term"] trash-support = ["nu-cli/trash-support"] diff --git a/crates/nu-cli/Cargo.toml b/crates/nu-cli/Cargo.toml index 644f82aa47..3d30a03e8b 100644 --- a/crates/nu-cli/Cargo.toml +++ b/crates/nu-cli/Cargo.toml @@ -47,6 +47,7 @@ futures_codec = "0.4.1" getset = "0.1.1" git2 = {version = "0.13.11", default_features = false, optional = true} glob = "0.3.0" +heim = {version = "0.1.0-beta.3", optional = true } htmlescape = "0.3.1" ical = "0.6.0" ichwh = {version = "0.3.4", optional = true} @@ -84,6 +85,7 @@ term_size = "0.3.2" termcolor = "1.1.0" toml = "0.5.6" unicode-segmentation = "1.6.0" +uom = {version = "0.28.0", features = ["f64", "try-from"]} uuid_crate = {package = "uuid", version = "0.8.1", features = ["v4"], optional = true} which = {version = "4.0.2", optional = true} zip = {version = "0.5.7", optional = true} @@ -123,3 +125,4 @@ clipboard-cli = ["clipboard"] rustyline-support = ["rustyline"] stable = [] trash-support = ["trash"] +rich-benchmark = ["heim"] diff --git a/crates/nu-cli/src/commands/benchmark.rs b/crates/nu-cli/src/commands/benchmark.rs index d66354950f..1a6c408867 100644 --- a/crates/nu-cli/src/commands/benchmark.rs +++ b/crates/nu-cli/src/commands/benchmark.rs @@ -1,12 +1,12 @@ use crate::commands::classified::block::run_block; use crate::commands::WholeStreamCommand; use crate::prelude::*; +#[cfg(feature = "rich-benchmark")] +use heim::cpu::time; use nu_errors::ShellError; -use nu_protocol::{ - hir::Block, Primitive, ReturnSuccess, Signature, SyntaxShape, UntaggedValue, Value, -}; - -use chrono::prelude::*; +use nu_protocol::{hir::Block, Dictionary, Signature, SyntaxShape, UntaggedValue, Value}; +use std::convert::TryInto; +use std::time::{Duration, Instant}; pub struct Benchmark; @@ -50,17 +50,21 @@ impl WholeStreamCommand for Benchmark { } } +#[cfg(feature = "rich-benchmark")] async fn benchmark( raw_args: CommandArgs, registry: &CommandRegistry, ) -> Result { let registry = registry.clone(); + let tag = raw_args.call_info.args.span; let mut context = Context::from_raw(&raw_args, ®istry); let scope = raw_args.call_info.scope.clone(); let (BenchmarkArgs { block }, input) = raw_args.process(®istry).await?; - let start_time: chrono::DateTime<_> = Utc::now(); + let start_time = Instant::now(); + + let start = time().await; let result = run_block( &block, @@ -71,16 +75,80 @@ async fn benchmark( &scope.env, ) .await; - let _ = result?.drain_vec().await; - let run_duration: chrono::Duration = Utc::now().signed_duration_since(start_time); + let end = time().await; + + let end_time = Instant::now(); context.clear_errors(); - let output = Ok(ReturnSuccess::Value(Value { - value: UntaggedValue::Primitive(Primitive::from(run_duration)), - tag: Tag::from(block.span), - })); + if let (Ok(start), Ok(end)) = (start, end) { + let mut indexmap = IndexMap::with_capacity(4); - Ok(OutputStream::from(vec![output])) + let real_time = into_value(end_time - start_time, &tag); + indexmap.insert("real time".to_string(), real_time); + + let user_time = into_value(end.user() - start.user(), &tag); + indexmap.insert("user time".to_string(), user_time); + + let system_time = into_value(end.system() - start.system(), &tag); + indexmap.insert("system time".to_string(), system_time); + + let idle_time = into_value(end.idle() - start.idle(), &tag); + indexmap.insert("idle time".to_string(), idle_time); + + let value = UntaggedValue::Row(Dictionary::from(indexmap)).into_value(&tag); + Ok(OutputStream::one(value)) + } else { + Err(ShellError::untagged_runtime_error( + "Could not retreive CPU time", + )) + } +} + +#[cfg(not(feature = "rich-benchmark"))] +async fn benchmark( + raw_args: CommandArgs, + registry: &CommandRegistry, +) -> Result { + let registry = registry.clone(); + + let tag = raw_args.call_info.args.span; + let mut context = Context::from_raw(&raw_args, ®istry); + let scope = raw_args.call_info.scope.clone(); + let (BenchmarkArgs { block }, input) = raw_args.process(®istry).await?; + + let start_time = Instant::now(); + + let result = run_block( + &block, + &mut context, + input, + &scope.it, + &scope.vars, + &scope.env, + ) + .await; + let _ = result?.drain_vec().await; + + let end_time = Instant::now(); + context.clear_errors(); + + let mut indexmap = IndexMap::with_capacity(4); + + let real_time = into_value(end_time - start_time, &tag); + indexmap.insert("real time".to_string(), real_time); + + let value = UntaggedValue::Row(Dictionary::from(indexmap)).into_value(&tag); + Ok(OutputStream::one(value)) +} + +fn into_value>(time: T, tag: &Span) -> Value { + UntaggedValue::duration( + time.try_into() + .unwrap_or_else(|_| Duration::new(0, 0)) + .as_nanos() + .into(), + ) + .into_value(tag) } diff --git a/crates/nu-protocol/src/value/primitive.rs b/crates/nu-protocol/src/value/primitive.rs index 2aad1ec629..607319e669 100644 --- a/crates/nu-protocol/src/value/primitive.rs +++ b/crates/nu-protocol/src/value/primitive.rs @@ -297,6 +297,7 @@ pub fn format_primitive(primitive: &Primitive, field_name: Option<&String>) -> S /// Format a duration in nanoseconds into a string pub fn format_duration(duration: &BigInt) -> String { + let is_zero = duration.is_zero(); // FIXME: This involves a lot of allocation, but it seems inevitable with BigInt. let big_int_1000 = BigInt::from(1000); let big_int_60 = BigInt::from(60); @@ -327,8 +328,8 @@ pub fn format_duration(duration: &BigInt) -> String { if !mins.is_zero() { output_prep.push(format!("{}min", mins)); } - - if !secs.is_zero() { + // output 0sec for zero duration + if is_zero || !secs.is_zero() { output_prep.push(format!("{}sec", secs)); }