add --perf cli param (#4391)

* add `--perf` cli param

* clippy

* fixed 2 `cp` tests on windows
This commit is contained in:
Darren Schroeder 2022-02-09 16:08:16 -06:00 committed by GitHub
parent fc88a8538b
commit f275644e13
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
11 changed files with 301 additions and 73 deletions

1
Cargo.lock generated
View File

@ -2094,6 +2094,7 @@ name = "nu"
version = "0.59.0"
dependencies = [
"assert_cmd",
"chrono",
"crossterm",
"crossterm_winapi",
"ctrlc",

View File

@ -30,37 +30,35 @@ members = [
]
[dependencies]
reedline = { git = "https://github.com/nushell/reedline", branch = "main" }
chrono = "0.4.19"
crossterm = "0.22.*"
crossterm_winapi = "0.9.0"
ctrlc = "3.2.1"
# lazy_static = "1.4.0"
log = "0.4"
miette = "3.0.0"
nu-ansi-term = "0.42.0"
nu-cli = { path="./crates/nu-cli", version = "0.59.0" }
nu-color-config = { path = "./crates/nu-color-config", version = "0.59.0" }
nu-command = { path="./crates/nu-command", version = "0.59.0" }
nu-engine = { path="./crates/nu-engine", version = "0.59.0" }
nu-json = { path="./crates/nu-json", version = "0.59.0" }
nu-parser = { path="./crates/nu-parser", version = "0.59.0" }
nu-path = { path="./crates/nu-path", version = "0.59.0" }
nu-plugin = { path = "./crates/nu-plugin", optional = true, version = "0.59.0" }
nu-pretty-hex = { path = "./crates/nu-pretty-hex", version = "0.59.0" }
nu-protocol = { path = "./crates/nu-protocol", version = "0.59.0" }
nu-plugin = { path = "./crates/nu-plugin", optional = true, version = "0.59.0" }
nu-system = { path = "./crates/nu-system", version = "0.59.0" }
nu-table = { path = "./crates/nu-table", version = "0.59.0" }
nu-term-grid = { path = "./crates/nu-term-grid", version = "0.59.0" }
# nu-ansi-term = { path = "./crates/nu-ansi-term", version = "0.59.0" }
nu-ansi-term = "0.42.0"
nu-color-config = { path = "./crates/nu-color-config", version = "0.59.0" }
miette = "3.0.0"
ctrlc = "3.2.1"
crossterm_winapi = "0.9.0"
log = "0.4"
pretty_env_logger = "0.4.0"
reedline = { git = "https://github.com/nushell/reedline", branch = "main" }
# mimalloc = { version = "*", default-features = false }
nu_plugin_inc = { version = "0.59.0", path = "./crates/nu_plugin_inc", optional = true }
# Plugins
nu_plugin_example = { version = "0.59.0", path = "./crates/nu_plugin_example", optional = true }
nu_plugin_gstat = { version = "0.59.0", path = "./crates/nu_plugin_gstat", optional = true }
nu_plugin_inc = { version = "0.59.0", path = "./crates/nu_plugin_inc", optional = true }
nu_plugin_query = { version = "0.59.0", path = "./crates/nu_plugin_query", optional = true }
[dev-dependencies]
@ -75,23 +73,9 @@ itertools = "0.10.3"
[features]
plugin = ["nu-plugin", "nu-parser/plugin", "nu-command/plugin", "nu-protocol/plugin", "nu-engine/plugin"]
default = [
"plugin",
"inc",
"example",
"which"
]
default = ["plugin", "inc", "example", "which"]
stable = ["default"]
extra = [
"default",
"dataframe",
"gstat",
"zip-support",
"query",
]
extra = [ "default", "dataframe", "gstat", "zip-support", "query", ]
wasi = ["inc"]
# Stable (Default)

View File

@ -127,7 +127,7 @@ fn copies_using_path_with_wildcard() {
Playground::setup("cp_test_6", |dirs, _| {
nu!(
cwd: dirs.formats(),
"cp ../formats/* {}", dirs.test()
"cp -r ../formats/* {}", dirs.test()
);
assert!(files_exist_at(
@ -149,7 +149,7 @@ fn copies_using_a_glob() {
Playground::setup("cp_test_7", |dirs, _| {
nu!(
cwd: dirs.formats(),
"cp * {}", dirs.test()
"cp -r * {}", dirs.test()
);
assert!(files_exist_at(

View File

@ -1,14 +1,14 @@
use crate::is_perf_true;
use crate::utils::{gather_parent_env_vars, report_error};
use log::info;
use miette::Result;
use nu_engine::{convert_env_values, eval_block};
use std::path::Path;
use nu_parser::{lex, lite_parse, parse_block, trim_quotes};
use nu_protocol::{
engine::{EngineState, StateDelta, StateWorkingSet},
Config, PipelineData, Span, Spanned, Value, CONFIG_VARIABLE_ID,
};
use crate::utils::{gather_parent_env_vars, report_error};
use std::path::Path;
pub(crate) fn evaluate(
commands: &Spanned<String>,
@ -123,5 +123,9 @@ pub(crate) fn evaluate(
}
}
if is_perf_true() {
info!("evaluate {}:{}:{}", file!(), line!(), column!());
}
Ok(())
}

View File

@ -1,4 +1,6 @@
use crate::is_perf_true;
use crate::utils::{eval_source, report_error};
use log::info;
use nu_protocol::engine::{EngineState, Stack, StateDelta, StateWorkingSet};
use std::path::PathBuf;
@ -22,6 +24,9 @@ pub(crate) fn read_plugin_file(engine_state: &mut EngineState, stack: &mut Stack
eval_source(engine_state, stack, &contents, &plugin_filename);
}
}
if is_perf_true() {
info!("read_plugin_file {}:{}:{}", file!(), line!(), column!());
}
}
pub(crate) fn read_config_file(engine_state: &mut EngineState, stack: &mut Stack) {
@ -63,6 +68,9 @@ pub(crate) fn read_config_file(engine_state: &mut EngineState, stack: &mut Stack
}
}
}
if is_perf_true() {
info!("read_config_file {}:{}:{}", file!(), line!(), column!());
}
}
pub(crate) fn create_history_path() -> Option<PathBuf> {

View File

@ -1,3 +1,6 @@
use crate::is_perf_true;
use crate::utils::{gather_parent_env_vars, report_error};
use log::info;
use log::trace;
use miette::{IntoDiagnostic, Result};
use nu_engine::{convert_env_values, eval_block};
@ -9,8 +12,6 @@ use nu_protocol::{
};
use std::{io::Write, path::PathBuf};
use crate::utils::{gather_parent_env_vars, report_error};
/// Main function used when a file path is found as argument for nu
pub(crate) fn evaluate(
path: String,
@ -135,6 +136,10 @@ pub(crate) fn evaluate(
}
}
if is_perf_true() {
info!("evaluate {}:{}:{}", file!(), line!(), column!());
}
Ok(())
}

View File

@ -1,14 +1,50 @@
use chrono::{DateTime, FixedOffset, Utc};
use core::fmt;
use log::Level;
use log::LevelFilter;
use nu_protocol::ShellError;
use pretty_env_logger::env_logger::fmt::Color;
use pretty_env_logger::env_logger::Builder;
use std::io::Write;
use std::sync::atomic::{AtomicUsize, Ordering};
pub fn logger(f: impl FnOnce(&mut Builder) -> Result<(), ShellError>) -> Result<(), ShellError> {
let mut builder = pretty_env_logger::formatted_builder();
let mut builder = my_formatted_timed_builder();
f(&mut builder)?;
let _ = builder.try_init();
Ok(())
}
pub fn my_formatted_timed_builder() -> Builder {
let mut builder = Builder::new();
builder.format(|f, record| {
let target = record.target();
let max_width = max_target_width(target);
let mut style = f.style();
let level = colored_level(&mut style, record.level());
let mut style = f.style();
let target = style.set_bold(true).value(Padded {
value: target,
width: max_width,
});
let dt = match DateTime::parse_from_rfc3339(&f.timestamp_millis().to_string()) {
Ok(d) => d,
Err(_) => {
let n = Utc::now();
DateTime::<FixedOffset>::from(n)
}
};
let time = dt.format("%Y-%m-%d %I:%M:%S%.3f %p");
writeln!(f, "{}|{}|{}|{}", time, level, target, record.args(),)
});
builder
}
pub fn configure(level: &str, logger: &mut Builder) -> Result<(), ShellError> {
let level = match level {
"error" => LevelFilter::Error,
@ -47,3 +83,39 @@ pub fn configure(level: &str, logger: &mut Builder) -> Result<(), ShellError> {
// Ok(())
// }
fn colored_level<'a>(
style: &'a mut pretty_env_logger::env_logger::fmt::Style,
level: Level,
) -> pretty_env_logger::env_logger::fmt::StyledValue<'a, &'static str> {
match level {
Level::Trace => style.set_color(Color::Magenta).value("TRACE"),
Level::Debug => style.set_color(Color::Blue).value("DEBUG"),
Level::Info => style.set_color(Color::Green).value("INFO "),
Level::Warn => style.set_color(Color::Yellow).value("WARN "),
Level::Error => style.set_color(Color::Red).value("ERROR"),
}
}
static MAX_MODULE_WIDTH: AtomicUsize = AtomicUsize::new(0);
fn max_target_width(target: &str) -> usize {
let max_width = MAX_MODULE_WIDTH.load(Ordering::Relaxed);
if max_width < target.len() {
MAX_MODULE_WIDTH.store(target.len(), Ordering::Relaxed);
target.len()
} else {
max_width
}
}
struct Padded<T> {
value: T,
width: usize,
}
impl<T: fmt::Display> fmt::Display for Padded<T> {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
write!(f, "{: <width$}", self.value, width = self.width)
}
}

View File

@ -5,13 +5,13 @@ mod logger;
mod prompt_update;
mod reedline_config;
mod repl;
mod utils;
mod test_bins;
#[cfg(test)]
mod tests;
mod utils;
mod test_bins;
use crate::logger::{configure, logger};
use log::info;
use miette::Result;
use nu_command::{create_default_context, BufferedReader};
use nu_engine::get_full_help;
@ -22,6 +22,7 @@ use nu_protocol::{
Category, Example, IntoPipelineData, PipelineData, RawStream, ShellError, Signature, Span,
Spanned, SyntaxShape, Value, CONFIG_VARIABLE_ID,
};
use std::cell::RefCell;
use std::{
io::{BufReader, Write},
path::Path,
@ -32,6 +33,8 @@ use std::{
};
use utils::report_error;
thread_local! { static IS_PERF: RefCell<bool> = RefCell::new(false) }
fn main() -> Result<()> {
// miette::set_panic_hook();
let miette_hook = std::panic::take_hook();
@ -99,6 +102,7 @@ fn main() -> Result<()> {
|| arg == "--debug"
|| arg == "--loglevel"
|| arg == "--config-file"
|| arg == "--perf"
{
collect_arg_nushell = true;
}
@ -113,12 +117,24 @@ fn main() -> Result<()> {
let nushell_commandline_args = args_to_nushell.join(" ");
let nushell_config =
let parsed_nu_cli_args =
parse_commandline_args(&nushell_commandline_args, &init_cwd, &mut engine_state);
match nushell_config {
Ok(nushell_config) => {
if let Some(testbin) = &nushell_config.testbin {
match parsed_nu_cli_args {
Ok(binary_args) => {
set_is_perf_value(binary_args.perf);
if binary_args.perf {
// if we started in perf mode show only the info logs
// TODO: what happens when the config log_level is read?
logger(|builder| {
configure("info", builder)?;
Ok(())
})?;
info!("start logging {}:{}:{}", file!(), line!(), column!());
}
if let Some(testbin) = &binary_args.testbin {
// Call out to the correct testbin
match testbin.item.as_str() {
"echo_env" => test_bins::echo_env(),
@ -133,7 +149,7 @@ fn main() -> Result<()> {
}
std::process::exit(0)
}
let input = if let Some(redirect_stdin) = &nushell_config.redirect_stdin {
let input = if let Some(redirect_stdin) = &binary_args.redirect_stdin {
let stdin = std::io::stdin();
let buf_reader = BufReader::new(stdin);
@ -150,18 +166,37 @@ fn main() -> Result<()> {
PipelineData::new(Span::new(0, 0))
};
if let Some(commands) = &nushell_config.commands {
commands::evaluate(commands, &init_cwd, &mut engine_state, input)
} else if !script_name.is_empty() && nushell_config.interactive_shell.is_none() {
eval_file::evaluate(
if is_perf_true() {
info!("redirect_stdin {}:{}:{}", file!(), line!(), column!());
}
if let Some(commands) = &binary_args.commands {
let ret_val = commands::evaluate(commands, &init_cwd, &mut engine_state, input);
if is_perf_true() {
info!("-c command execution {}:{}:{}", file!(), line!(), column!());
}
ret_val
} else if !script_name.is_empty() && binary_args.interactive_shell.is_none() {
let ret_val = eval_file::evaluate(
script_name,
&args_to_script,
init_cwd,
&mut engine_state,
input,
)
);
if is_perf_true() {
info!("eval_file execution {}:{}:{}", file!(), line!(), column!());
}
ret_val
} else {
repl::evaluate(&mut engine_state)
let ret_val = repl::evaluate(&mut engine_state);
if is_perf_true() {
info!("repl eval {}:{}:{}", file!(), line!(), column!());
}
ret_val
}
}
Err(_) => std::process::exit(1),
@ -172,7 +207,7 @@ fn parse_commandline_args(
commandline_args: &str,
init_cwd: &Path,
engine_state: &mut EngineState,
) -> Result<NushellConfig, ShellError> {
) -> Result<NushellCliArgs, ShellError> {
let (block, delta) = {
let mut working_set = StateWorkingSet::new(engine_state);
working_set.add_decl(Box::new(Nu));
@ -212,6 +247,7 @@ fn parse_commandline_args(
let interactive_shell = call.get_named_arg("interactive");
let commands: Option<Expression> = call.get_flag_expr("commands");
let testbin: Option<Expression> = call.get_flag_expr("testbin");
let perf = call.has_flag("perf");
let commands = if let Some(expression) = commands {
let contents = engine_state.get_span_contents(&expression.span);
@ -250,12 +286,13 @@ fn parse_commandline_args(
std::process::exit(1);
}
return Ok(NushellConfig {
return Ok(NushellCliArgs {
redirect_stdin,
login_shell,
interactive_shell,
commands,
testbin,
perf,
});
}
}
@ -266,13 +303,14 @@ fn parse_commandline_args(
std::process::exit(1);
}
struct NushellConfig {
struct NushellCliArgs {
redirect_stdin: Option<Spanned<String>>,
#[allow(dead_code)]
login_shell: Option<Spanned<String>>,
interactive_shell: Option<Spanned<String>>,
commands: Option<Spanned<String>>,
testbin: Option<Spanned<String>>,
perf: bool,
}
#[derive(Clone)]
@ -289,6 +327,11 @@ impl Command for Nu {
.switch("stdin", "redirect the stdin", None)
.switch("login", "start as a login shell", Some('l'))
.switch("interactive", "start as an interactive shell", Some('i'))
.switch(
"perf",
"start and print performance metrics during startup",
Some('p'),
)
.named(
"testbin",
SyntaxShape::String,
@ -347,3 +390,18 @@ impl Command for Nu {
]
}
}
pub fn is_perf_true() -> bool {
IS_PERF.with(|value| *value.borrow())
}
// #[allow(dead_code)]
// fn is_perf_value() -> bool {
// IS_PERF.with(|value| *value.borrow())
// }
fn set_is_perf_value(value: bool) {
IS_PERF.with(|new_value| {
*new_value.borrow_mut() = value;
});
}

View File

@ -1,3 +1,5 @@
use crate::is_perf_true;
use log::info;
use nu_cli::NushellPrompt;
use nu_engine::eval_subexpression;
use nu_parser::parse;
@ -40,6 +42,15 @@ pub(crate) fn get_prompt_indicators(
None => "::: ".to_string(),
};
if is_perf_true() {
info!(
"get_prompt_indicators {}:{}:{}",
file!(),
line!(),
column!()
);
}
(
prompt_indicator,
prompt_vi_insert,
@ -60,25 +71,45 @@ fn get_prompt_string(
Value::Block { val: block_id, .. } => {
let block = engine_state.get_block(block_id);
// Use eval_subexpression to force a redirection of output, so we can use everything in prompt
eval_subexpression(
let ret_val = eval_subexpression(
engine_state,
stack,
block,
PipelineData::new(Span::new(0, 0)), // Don't try this at home, 0 span is ignored
)
.ok()
.ok();
if is_perf_true() {
info!(
"get_prompt_string (block) {}:{}:{}",
file!(),
line!(),
column!()
);
}
ret_val
}
Value::String { val: source, .. } => {
let mut working_set = StateWorkingSet::new(engine_state);
let (block, _) = parse(&mut working_set, None, source.as_bytes(), true);
// Use eval_subexpression to force a redirection of output, so we can use everything in prompt
eval_subexpression(
let ret_val = eval_subexpression(
engine_state,
stack,
&block,
PipelineData::new(Span::new(0, 0)), // Don't try this at home, 0 span is ignored
)
.ok()
.ok();
if is_perf_true() {
info!(
"get_prompt_string (string) {}:{}:{}",
file!(),
line!(),
column!()
);
}
ret_val
}
_ => None,
})
@ -127,5 +158,10 @@ pub(crate) fn update_prompt<'prompt>(
(prompt_vi_insert_string, prompt_vi_normal_string),
);
nu_prompt as &dyn Prompt
let ret_val = nu_prompt as &dyn Prompt;
if is_perf_true() {
info!("update_prompt {}:{}:{}", file!(), line!(), column!());
}
ret_val
}

View File

@ -1,4 +1,6 @@
use crate::is_perf_true;
use crossterm::event::{KeyCode, KeyModifiers};
use log::info;
use nu_color_config::lookup_ansi_color_style;
use nu_protocol::{extract_value, Config, ParsedKeybinding, ShellError, Span, Type, Value};
use reedline::{
@ -64,7 +66,12 @@ pub(crate) fn add_completion_menu(line_editor: Reedline, config: &Config) -> Ree
None => completion_menu,
};
line_editor.with_menu(Box::new(completion_menu))
let ret_val = line_editor.with_menu(Box::new(completion_menu));
if is_perf_true() {
info!("add_completion_menu {}:{}:{}", file!(), line!(), column!());
}
ret_val
}
// Creates an input object for the history menu based on the dictionary
@ -120,7 +127,12 @@ pub(crate) fn add_history_menu(line_editor: Reedline, config: &Config) -> Reedli
None => history_menu,
};
line_editor.with_menu(Box::new(history_menu))
let ret_val = line_editor.with_menu(Box::new(history_menu));
if is_perf_true() {
info!("add_history_menu {}:{}:{}", file!(), line!(), column!());
}
ret_val
}
fn add_menu_keybindings(keybindings: &mut Keybindings) {
@ -153,6 +165,10 @@ fn add_menu_keybindings(keybindings: &mut Keybindings) {
KeyCode::BackTab,
ReedlineEvent::MenuPrevious,
);
if is_perf_true() {
info!("add_menu_keybindings {}:{}:{}", file!(), line!(), column!());
}
}
pub enum KeybindingsMode {
@ -186,6 +202,15 @@ pub(crate) fn create_keybindings(config: &Config) -> Result<KeybindingsMode, She
}
}
if is_perf_true() {
info!(
"create_keybindings (emacs) {}:{}:{}",
file!(),
line!(),
column!()
);
}
Ok(KeybindingsMode::Emacs(keybindings))
}
_ => {
@ -203,6 +228,15 @@ pub(crate) fn create_keybindings(config: &Config) -> Result<KeybindingsMode, She
}
}
if is_perf_true() {
info!(
"create_keybindings (vi) {}:{}:{}",
file!(),
line!(),
column!()
);
}
Ok(KeybindingsMode::Vi {
insert_keybindings,
normal_keybindings,
@ -301,6 +335,10 @@ fn add_keybinding(
keybindings.add_binding(modifier, keycode, event);
if is_perf_true() {
info!("add_keybinding {}:{}:{}", file!(), line!(), column!());
}
Ok(())
}
@ -368,6 +406,10 @@ fn parse_event(value: Value, config: &Config) -> Result<ReedlineEvent, ShellErro
}
};
if is_perf_true() {
info!("parse_event (record) {}:{}:{}", file!(), line!(), column!());
}
Ok(event)
}
Value::List { vals, .. } => {
@ -381,6 +423,10 @@ fn parse_event(value: Value, config: &Config) -> Result<ReedlineEvent, ShellErro
.map(|value| parse_event(value, config))
.collect::<Result<Vec<ReedlineEvent>, ShellError>>()?;
if is_perf_true() {
info!("parse_event (list) {}:{}:{}", file!(), line!(), column!());
}
if until_found {
Ok(ReedlineEvent::UntilFound(events))
} else {

View File

@ -1,11 +1,11 @@
use std::{sync::atomic::Ordering, time::Instant};
use crate::is_perf_true;
use crate::reedline_config::{add_completion_menu, add_history_menu};
use crate::{config_files, prompt_update, reedline_config};
use crate::{
reedline_config::KeybindingsMode,
utils::{eval_source, gather_parent_env_vars, report_error},
};
use log::info;
use log::trace;
use miette::{IntoDiagnostic, Result};
use nu_cli::{NuCompleter, NuHighlighter, NuValidator, NushellPrompt};
@ -17,9 +17,10 @@ use nu_protocol::{
Config, ShellError, Span, Value, CONFIG_VARIABLE_ID,
};
use reedline::{DefaultHinter, Emacs, Vi};
use std::{sync::atomic::Ordering, time::Instant};
pub(crate) fn evaluate(engine_state: &mut EngineState) -> Result<()> {
use crate::logger::{configure, logger};
// use crate::logger::{configure, logger};
use reedline::{FileBackedHistory, Reedline, Signal};
let mut entry_num = 0;
@ -57,13 +58,13 @@ pub(crate) fn evaluate(engine_state: &mut EngineState) -> Result<()> {
}
};
logger(|builder| {
configure(&config.log_level, builder)?;
// trace_filters(self, builder)?;
// debug_filters(self, builder)?;
// logger(|builder| {
// configure(&config.log_level, builder)?;
// // trace_filters(self, builder)?;
// // debug_filters(self, builder)?;
Ok(())
})?;
// Ok(())
// })?;
// Translate environment variables from Strings to Values
if let Some(e) = convert_env_values(engine_state, &stack, &config) {
@ -162,8 +163,21 @@ pub(crate) fn evaluate(engine_state: &mut EngineState) -> Result<()> {
}
};
if is_perf_true() {
info!("setup line editor {}:{}:{}", file!(), line!(), column!());
}
let prompt = prompt_update::update_prompt(&config, engine_state, &stack, &mut nu_prompt);
if is_perf_true() {
info!(
"finished prompt update {}:{}:{}",
file!(),
line!(),
column!()
);
}
entry_num += 1;
let input = line_editor.read_line(prompt);