diff --git a/Cargo.lock b/Cargo.lock index cd7fe99800..712986b8b6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1330,6 +1330,16 @@ dependencies = [ "syn 2.0.60", ] +[[package]] +name = "env_filter" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a009aa4810eb158359dda09d0c87378e4bbb89b5a801f016885a4707ba24f7ea" +dependencies = [ + "log", + "regex", +] + [[package]] name = "env_logger" version = "0.8.4" @@ -1340,6 +1350,19 @@ dependencies = [ "regex", ] +[[package]] +name = "env_logger" +version = "0.11.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "38b35839ba51819680ba087cd351788c9a3c476841207e0b8cee0b04722343b9" +dependencies = [ + "anstream", + "anstyle", + "env_filter", + "humantime", + "log", +] + [[package]] name = "equivalent" version = "1.0.1" @@ -1906,6 +1929,12 @@ dependencies = [ "thiserror", ] +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "hyper" version = "0.14.28" @@ -3391,8 +3420,10 @@ version = "0.95.1" dependencies = [ "chrono", "chrono-tz 0.9.0", + "env_logger 0.11.3", "fancy-regex", "indexmap", + "log", "mimalloc", "nu-cmd-lang", "nu-command", @@ -3402,6 +3433,7 @@ dependencies = [ "nu-plugin", "nu-plugin-test-support", "nu-protocol", + "nu-utils", "num", "polars", "polars-arrow", @@ -4667,7 +4699,7 @@ version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "588f6378e4dd99458b60ec275b4477add41ce4fa9f64dcba6f15adccb19b50d6" dependencies = [ - "env_logger", + "env_logger 0.8.4", "log", "rand", ] diff --git a/crates/nu-cli/src/config_files.rs b/crates/nu-cli/src/config_files.rs index 6cf4735c46..3a02f75e86 100644 --- a/crates/nu-cli/src/config_files.rs +++ b/crates/nu-cli/src/config_files.rs @@ -8,7 +8,7 @@ use nu_protocol::{ report_error_new, HistoryFileFormat, PipelineData, }; #[cfg(feature = "plugin")] -use nu_utils::utils::perf; +use nu_utils::perf; use std::path::PathBuf; #[cfg(feature = "plugin")] @@ -53,13 +53,10 @@ pub fn read_plugin_file( // Reading signatures from plugin registry file // The plugin.msgpackz file stores the parsed signature collected from each registered plugin add_plugin_file(engine_state, plugin_file.clone(), storage_path); - perf( + perf!( "add plugin file to engine_state", start_time, - file!(), - line!(), - column!(), - engine_state.get_config().use_ansi_coloring, + engine_state.get_config().use_ansi_coloring ); start_time = std::time::Instant::now(); @@ -137,13 +134,10 @@ pub fn read_plugin_file( } }; - perf( + perf!( &format!("read plugin file {}", plugin_path.display()), start_time, - file!(), - line!(), - column!(), - engine_state.get_config().use_ansi_coloring, + engine_state.get_config().use_ansi_coloring ); start_time = std::time::Instant::now(); @@ -156,13 +150,10 @@ pub fn read_plugin_file( return; } - perf( + perf!( &format!("load plugin file {}", plugin_path.display()), start_time, - file!(), - line!(), - column!(), - engine_state.get_config().use_ansi_coloring, + engine_state.get_config().use_ansi_coloring ); } } @@ -381,13 +372,10 @@ pub fn migrate_old_plugin_file(engine_state: &EngineState, storage_path: &str) - ); } - perf( + perf!( "migrate old plugin file", start_time, - file!(), - line!(), - column!(), - engine_state.get_config().use_ansi_coloring, + engine_state.get_config().use_ansi_coloring ); true } diff --git a/crates/nu-cli/src/repl.rs b/crates/nu-cli/src/repl.rs index d9aef32bbb..251876022a 100644 --- a/crates/nu-cli/src/repl.rs +++ b/crates/nu-cli/src/repl.rs @@ -31,7 +31,7 @@ use nu_protocol::{ }; use nu_utils::{ filesystem::{have_permission, PermissionResult}, - utils::perf, + perf, }; use reedline::{ CursorConfig, CwdAwareHinter, DefaultCompleter, EditCommand, Emacs, FileBackedHistory, @@ -89,14 +89,7 @@ pub fn evaluate_repl( if let Err(e) = convert_env_values(engine_state, &unique_stack) { report_error_new(engine_state, &e); } - perf( - "translate env vars", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("translate env vars", start_time, use_color); // seed env vars unique_stack.add_env_var( @@ -225,28 +218,14 @@ fn get_line_editor( // Now that reedline is created, get the history session id and store it in engine_state store_history_id_in_engine(engine_state, &line_editor); - perf( - "setup reedline", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("setup reedline", start_time, use_color); if let Some(history) = engine_state.history_config() { start_time = std::time::Instant::now(); line_editor = setup_history(nushell_path, engine_state, line_editor, history)?; - perf( - "setup history", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("setup history", start_time, use_color); } Ok(line_editor) } @@ -289,28 +268,14 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { if let Err(err) = engine_state.merge_env(&mut stack, cwd) { report_error_new(engine_state, &err); } - perf( - "merge env", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("merge env", start_time, use_color); start_time = std::time::Instant::now(); // Reset the ctrl-c handler if let Some(ctrlc) = &mut engine_state.ctrlc { ctrlc.store(false, Ordering::SeqCst); } - perf( - "reset ctrlc", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("reset ctrlc", start_time, use_color); start_time = std::time::Instant::now(); // Right before we start our prompt and take input from the user, @@ -320,14 +285,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { report_error_new(engine_state, &err); } } - perf( - "pre-prompt hook", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("pre-prompt hook", start_time, use_color); start_time = std::time::Instant::now(); // Next, check all the environment variables they ask for @@ -336,14 +294,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { if let Err(error) = hook::eval_env_change_hook(env_change, engine_state, &mut stack) { report_error_new(engine_state, &error) } - perf( - "env-change hook", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("env-change hook", start_time, use_color); let engine_reference = Arc::new(engine_state.clone()); let config = engine_state.get_config(); @@ -355,14 +306,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { vi_normal: map_nucursorshape_to_cursorshape(config.cursor_shape_vi_normal), emacs: map_nucursorshape_to_cursorshape(config.cursor_shape_emacs), }; - perf( - "get config/cursor config", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("get config/cursor config", start_time, use_color); start_time = std::time::Instant::now(); // at this line we have cloned the state for the completer and the transient prompt @@ -394,14 +338,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { .with_ansi_colors(config.use_ansi_coloring) .with_cursor_config(cursor_config); - perf( - "reedline builder", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("reedline builder", start_time, use_color); let style_computer = StyleComputer::from_config(engine_state, &stack_arc); @@ -416,14 +353,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { line_editor.disable_hints() }; - perf( - "reedline coloring/style_computer", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("reedline coloring/style_computer", start_time, use_color); start_time = std::time::Instant::now(); trace!("adding menus"); @@ -433,14 +363,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { Reedline::create() }); - perf( - "reedline adding menus", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("reedline adding menus", start_time, use_color); start_time = std::time::Instant::now(); let buffer_editor = get_editor(engine_state, &stack_arc, Span::unknown()); @@ -457,14 +380,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { line_editor }; - perf( - "reedline buffer_editor", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("reedline buffer_editor", start_time, use_color); if let Some(history) = engine_state.history_config() { start_time = std::time::Instant::now(); @@ -474,28 +390,14 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { } } - perf( - "sync_history", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("sync_history", start_time, use_color); } start_time = std::time::Instant::now(); // Changing the line editor based on the found keybindings line_editor = setup_keybindings(engine_state, line_editor); - perf( - "keybindings", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("keybindings", start_time, use_color); start_time = std::time::Instant::now(); let config = &engine_state.get_config().clone(); @@ -512,14 +414,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { nu_prompt, ); - perf( - "update_prompt", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("update_prompt", start_time, use_color); *entry_num += 1; @@ -546,14 +441,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { // so we should avoid it or making stack cheaper to clone. let mut stack = Arc::unwrap_or_clone(stack_arc); - perf( - "line_editor setup", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("line_editor setup", start_time, use_color); let line_editor_input_time = std::time::Instant::now(); match input { @@ -590,14 +478,7 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { } } - perf( - "pre_execution_hook", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("pre_execution_hook", start_time, use_color); let mut repl = engine_state.repl_state.lock().expect("repl state mutex"); repl.cursor_pos = line_editor.current_insertion_point(); @@ -612,26 +493,20 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { run_ansi_sequence(VSCODE_PRE_EXECUTION_MARKER); - perf( + perf!( "pre_execute_marker (633;C) ansi escape sequence", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } else if shell_integration_osc133 { start_time = Instant::now(); run_ansi_sequence(PRE_EXECUTION_MARKER); - perf( + perf!( "pre_execute_marker (133;C) ansi escape sequence", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } else if shell_integration_osc133 { @@ -639,13 +514,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { run_ansi_sequence(PRE_EXECUTION_MARKER); - perf( + perf!( "pre_execute_marker (133;C) ansi escape sequence", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } @@ -769,22 +641,16 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) { ); } } - perf( + perf!( "processing line editor input", line_editor_input_time, - file!(), - line!(), - column!(), - use_color, + use_color ); - perf( + perf!( "time between prompts in line editor loop", loop_start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); (true, stack, line_editor) @@ -1061,14 +927,7 @@ fn run_shell_integration_osc2( // ESC]2;stringBEL -- Set window title to string run_ansi_sequence(&format!("\x1b]2;{title}\x07")); - perf( - "set title with command osc2", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("set title with command osc2", start_time, use_color); } } @@ -1093,13 +952,10 @@ fn run_shell_integration_osc7( percent_encoding::utf8_percent_encode(&path, percent_encoding::CONTROLS) )); - perf( + perf!( "communicate path to terminal with osc7", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } @@ -1116,13 +972,10 @@ fn run_shell_integration_osc9_9(engine_state: &EngineState, stack: &mut Stack, u percent_encoding::utf8_percent_encode(&path, percent_encoding::CONTROLS) )); - perf( + perf!( "communicate path to terminal with osc9;9", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } @@ -1142,13 +995,10 @@ fn run_shell_integration_osc633(engine_state: &EngineState, stack: &mut Stack, u VSCODE_CWD_PROPERTY_MARKER_PREFIX, path, VSCODE_CWD_PROPERTY_MARKER_SUFFIX )); - perf( + perf!( "communicate path to terminal with osc633;P", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } @@ -1371,13 +1221,10 @@ fn run_finaliziation_ansi_sequence( shell_integration_osc133, )); - perf( + perf!( "post_execute_marker (633;D) ansi escape sequences", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } else if shell_integration_osc133 { let start_time = Instant::now(); @@ -1389,13 +1236,10 @@ fn run_finaliziation_ansi_sequence( shell_integration_osc133, )); - perf( + perf!( "post_execute_marker (133;D) ansi escape sequences", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } else if shell_integration_osc133 { @@ -1408,13 +1252,10 @@ fn run_finaliziation_ansi_sequence( shell_integration_osc133, )); - perf( + perf!( "post_execute_marker (133;D) ansi escape sequences", start_time, - file!(), - line!(), - column!(), - use_color, + use_color ); } } diff --git a/crates/nu-cli/src/util.rs b/crates/nu-cli/src/util.rs index e4912e012f..d3cf73056f 100644 --- a/crates/nu-cli/src/util.rs +++ b/crates/nu-cli/src/util.rs @@ -8,7 +8,7 @@ use nu_protocol::{ }; #[cfg(windows)] use nu_utils::enable_vt_processing; -use nu_utils::utils::perf; +use nu_utils::perf; use std::path::Path; // This will collect environment variables from std::env and adds them to a stack. @@ -228,13 +228,10 @@ pub fn eval_source( let _ = enable_vt_processing(); } - perf( + perf!( &format!("eval_source {}", &fname), start_time, - file!(), - line!(), - column!(), - engine_state.get_config().use_ansi_coloring, + engine_state.get_config().use_ansi_coloring ); exit_code diff --git a/crates/nu-utils/src/utils.rs b/crates/nu-utils/src/utils.rs index 7a368f5cf7..8baf674075 100644 --- a/crates/nu-utils/src/utils.rs +++ b/crates/nu-utils/src/utils.rs @@ -1,4 +1,3 @@ -use log::info; use lscolors::LsColors; use std::io::{Result, Write}; @@ -393,31 +392,27 @@ pub fn get_ls_colors(lscolors_env_string: Option) -> LsColors { } // Log some performance metrics (green text with yellow timings) -pub fn perf( - msg: &str, - dur: std::time::Instant, - file: &str, - line: u32, - column: u32, - use_color: bool, -) { - if use_color { - info!( - "perf: {}:{}:{} \x1b[32m{}\x1b[0m took \x1b[33m{:?}\x1b[0m", - file, - line, - column, - msg, - dur.elapsed(), - ); - } else { - info!( - "perf: {}:{}:{} {} took {:?}", - file, - line, - column, - msg, - dur.elapsed(), - ); - } +#[macro_export] +macro_rules! perf { + ($msg:expr, $dur:expr, $use_color:expr) => { + if $use_color { + log::info!( + "perf: {}:{}:{} \x1b[32m{}\x1b[0m took \x1b[33m{:?}\x1b[0m", + file!(), + line!(), + column!(), + $msg, + $dur.elapsed(), + ); + } else { + log::info!( + "perf: {}:{}:{} {} took {:?}", + file!(), + line!(), + column!(), + $msg, + $dur.elapsed(), + ); + } + }; } diff --git a/crates/nu_plugin_polars/Cargo.toml b/crates/nu_plugin_polars/Cargo.toml index 09906732b7..285046381e 100644 --- a/crates/nu_plugin_polars/Cargo.toml +++ b/crates/nu_plugin_polars/Cargo.toml @@ -20,6 +20,7 @@ bench = false nu-protocol = { path = "../nu-protocol", version = "0.95.1" } nu-plugin = { path = "../nu-plugin", version = "0.95.1" } nu-path = { path = "../nu-path", version = "0.95.1" } +nu-utils = { path = "../nu-utils", version = "0.95.1" } # Potential dependencies for extras chrono = { workspace = true, features = ["std", "unstable-locales"], default-features = false } @@ -36,6 +37,8 @@ polars-ops = { version = "0.40"} polars-plan = { version = "0.40", features = ["regex"]} polars-utils = { version = "0.40"} typetag = "0.2" +env_logger = "0.11.3" +log.workspace = true uuid = { version = "1.9", features = ["v4", "serde"] } [dependencies.polars] @@ -78,4 +81,4 @@ nu-engine = { path = "../nu-engine", version = "0.95.1" } nu-parser = { path = "../nu-parser", version = "0.95.1" } nu-command = { path = "../nu-command", version = "0.95.1" } nu-plugin-test-support = { path = "../nu-plugin-test-support", version = "0.95.1" } -tempfile.workspace = true \ No newline at end of file +tempfile.workspace = true diff --git a/crates/nu_plugin_polars/src/cache/mod.rs b/crates/nu_plugin_polars/src/cache/mod.rs index 08a7a9d7f7..a7e566d327 100644 --- a/crates/nu_plugin_polars/src/cache/mod.rs +++ b/crates/nu_plugin_polars/src/cache/mod.rs @@ -13,7 +13,9 @@ use nu_plugin::{EngineInterface, PluginCommand}; use nu_protocol::{LabeledError, ShellError, Span}; use uuid::Uuid; -use crate::{plugin_debug, values::PolarsPluginObject, EngineWrapper, PolarsPlugin}; +use crate::{values::PolarsPluginObject, EngineWrapper, PolarsPlugin}; + +use log::debug; #[derive(Debug, Clone)] pub struct CacheValue { @@ -60,22 +62,16 @@ impl Cache { let removed = if force || reference_count.unwrap_or_default() < 1 { let removed = lock.remove(key); - plugin_debug!( - engine, - "PolarsPlugin: removing {key} from cache: {removed:?}" - ); + debug!("PolarsPlugin: removing {key} from cache: {removed:?}"); removed } else { - plugin_debug!( - engine, - "PolarsPlugin: decrementing reference count for {key}" - ); + debug!("PolarsPlugin: decrementing reference count for {key}"); None }; // Once there are no more entries in the cache // we can turn plugin gc back on - plugin_debug!(engine, "PolarsPlugin: Cache is empty enabling GC"); + debug!("PolarsPlugin: Cache is empty enabling GC"); engine.set_gc_disabled(false).map_err(LabeledError::from)?; drop(lock); Ok(removed) @@ -91,14 +87,11 @@ impl Cache { span: Span, ) -> Result, ShellError> { let mut lock = self.lock()?; - plugin_debug!( - engine, - "PolarsPlugin: Inserting {uuid} into cache: {value:?}" - ); + debug!("PolarsPlugin: Inserting {uuid} into cache: {value:?}"); // turn off plugin gc the first time an entry is added to the cache // as we don't want the plugin to be garbage collected if there // is any live data - plugin_debug!(engine, "PolarsPlugin: Cache has values disabling GC"); + debug!("PolarsPlugin: Cache has values disabling GC"); engine.set_gc_disabled(true).map_err(LabeledError::from)?; let cache_value = CacheValue { uuid, diff --git a/crates/nu_plugin_polars/src/dataframe/eager/open.rs b/crates/nu_plugin_polars/src/dataframe/eager/open.rs index f7ee467877..116e6c3b8f 100644 --- a/crates/nu_plugin_polars/src/dataframe/eager/open.rs +++ b/crates/nu_plugin_polars/src/dataframe/eager/open.rs @@ -1,10 +1,10 @@ use crate::{ dataframe::values::NuSchema, - perf, values::{CustomValueSupport, NuLazyFrame}, - PolarsPlugin, + EngineWrapper, PolarsPlugin, }; use nu_path::expand_path_with; +use nu_utils::perf; use super::super::values::NuDataFrame; use nu_plugin::PluginCommand; @@ -399,13 +399,10 @@ fn from_jsonl( inner: vec![], })?; - perf( - engine, + perf!( "Lazy json lines dataframe open", start_time, - file!(), - line!(), - column!(), + engine.use_color() ); let df = NuLazyFrame::new(false, df); @@ -441,13 +438,10 @@ fn from_jsonl( })? .into(); - perf( - engine, + perf!( "Eager json lines dataframe open", start_time, - file!(), - line!(), - column!(), + engine.use_color() ); df.cache_and_to_value(plugin, engine, call.head) @@ -524,14 +518,7 @@ fn from_csv( })? .into(); - perf( - engine, - "Lazy CSV dataframe open", - start_time, - file!(), - line!(), - column!(), - ); + perf!("Lazy CSV dataframe open", start_time, engine.use_color()); df.cache_and_to_value(plugin, engine, call.head) } else { @@ -569,14 +556,7 @@ fn from_csv( inner: vec![], })?; - perf( - engine, - "Eager CSV dataframe open", - start_time, - file!(), - line!(), - column!(), - ); + perf!("Eager CSV dataframe open", start_time, engine.use_color()); let df = NuDataFrame::new(false, df); df.cache_and_to_value(plugin, engine, call.head) diff --git a/crates/nu_plugin_polars/src/lib.rs b/crates/nu_plugin_polars/src/lib.rs index 9fc9a7ab2d..b5868e13d6 100644 --- a/crates/nu_plugin_polars/src/lib.rs +++ b/crates/nu_plugin_polars/src/lib.rs @@ -45,52 +45,6 @@ impl EngineWrapper for &EngineInterface { } } -#[macro_export] -macro_rules! plugin_debug { - ($env_var_provider:tt, $($arg:tt)*) => {{ - if $env_var_provider.get_env_var("POLARS_PLUGIN_DEBUG") - .filter(|s| s == "1" || s == "true") - .is_some() { - eprintln!($($arg)*); - } - }}; -} - -pub fn perf( - env: impl EngineWrapper, - msg: &str, - dur: std::time::Instant, - file: &str, - line: u32, - column: u32, -) { - if env - .get_env_var("POLARS_PLUGIN_PERF") - .filter(|s| s == "1" || s == "true") - .is_some() - { - if env.use_color() { - eprintln!( - "perf: {}:{}:{} \x1b[32m{}\x1b[0m took \x1b[33m{:?}\x1b[0m", - file, - line, - column, - msg, - dur.elapsed(), - ); - } else { - eprintln!( - "perf: {}:{}:{} {} took {:?}", - file, - line, - column, - msg, - dur.elapsed(), - ); - } - } -} - #[derive(Default)] pub struct PolarsPlugin { pub(crate) cache: Cache, diff --git a/crates/nu_plugin_polars/src/main.rs b/crates/nu_plugin_polars/src/main.rs index 4a757701ad..a930c5caab 100644 --- a/crates/nu_plugin_polars/src/main.rs +++ b/crates/nu_plugin_polars/src/main.rs @@ -5,5 +5,6 @@ use nu_plugin_polars::PolarsPlugin; static GLOBAL: mimalloc::MiMalloc = mimalloc::MiMalloc; fn main() { + env_logger::init(); serve_plugin(&PolarsPlugin::default(), MsgPackSerializer {}) } diff --git a/src/main.rs b/src/main.rs index c74fd7641d..6eb65276b9 100644 --- a/src/main.rs +++ b/src/main.rs @@ -29,7 +29,7 @@ use nu_protocol::{ Value, }; use nu_std::load_standard_library; -use nu_utils::utils::perf; +use nu_utils::perf; use run::{run_commands, run_file, run_repl}; use signals::ctrlc_protection; use std::{ @@ -219,14 +219,7 @@ fn main() -> Result<()> { logger(|builder| configure(&level, &target, filters, builder))?; // info!("start logging {}:{}:{}", file!(), line!(), column!()); - perf( - "start logging", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("start logging", start_time, use_color); } start_time = std::time::Instant::now(); @@ -245,27 +238,13 @@ fn main() -> Result<()> { "env-path", parsed_nu_cli_args.env_file.as_ref(), ); - perf( - "set_config_path", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("set_config_path", start_time, use_color); #[cfg(unix)] { start_time = std::time::Instant::now(); terminal::acquire(engine_state.is_interactive); - perf( - "acquire_terminal", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("acquire_terminal", start_time, use_color); } start_time = std::time::Instant::now(); @@ -279,26 +258,12 @@ fn main() -> Result<()> { engine_state.add_env_var("NU_LIB_DIRS".into(), Value::list(vals, span)); } - perf( - "NU_LIB_DIRS setup", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("NU_LIB_DIRS setup", start_time, use_color); start_time = std::time::Instant::now(); // First, set up env vars as strings only gather_parent_env_vars(&mut engine_state, &init_cwd); - perf( - "gather env vars", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("gather env vars", start_time, use_color); engine_state.add_env_var( "NU_VERSION".to_string(), @@ -359,14 +324,7 @@ fn main() -> Result<()> { } std::process::exit(0) } - perf( - "run test_bins", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("run test_bins", start_time, use_color); start_time = std::time::Instant::now(); let input = if let Some(redirect_stdin) = &parsed_nu_cli_args.redirect_stdin { @@ -376,26 +334,12 @@ fn main() -> Result<()> { trace!("not redirecting stdin"); PipelineData::empty() }; - perf( - "redirect stdin", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("redirect stdin", start_time, use_color); start_time = std::time::Instant::now(); // Set up the $nu constant before evaluating config files (need to have $nu available in them) engine_state.generate_nu_constant(); - perf( - "create_nu_constant", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("create_nu_constant", start_time, use_color); #[cfg(feature = "plugin")] if let Some(plugins) = &parsed_nu_cli_args.plugins { @@ -433,26 +377,12 @@ fn main() -> Result<()> { } engine_state.merge_delta(working_set.render())?; - perf( - "load plugins specified in --plugins", - start_time, - file!(), - line!(), - column!(), - use_color, - ) + perf!("load plugins specified in --plugins", start_time, use_color) } start_time = std::time::Instant::now(); if parsed_nu_cli_args.lsp { - perf( - "lsp starting", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("lsp starting", start_time, use_color); if parsed_nu_cli_args.no_config_file.is_none() { let mut stack = nu_protocol::engine::Stack::new(); diff --git a/src/run.rs b/src/run.rs index db779b0058..6bb02451b9 100644 --- a/src/run.rs +++ b/src/run.rs @@ -12,7 +12,7 @@ use nu_protocol::{ engine::{EngineState, Stack}, report_error_new, PipelineData, Spanned, }; -use nu_utils::utils::perf; +use nu_utils::perf; pub(crate) fn run_commands( engine_state: &mut EngineState, @@ -35,14 +35,7 @@ pub(crate) fn run_commands( #[cfg(feature = "plugin")] read_plugin_file(engine_state, parsed_nu_cli_args.plugin_file, NUSHELL_FOLDER); - perf( - "read plugins", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read plugins", start_time, use_color); let start_time = std::time::Instant::now(); // If we have a env file parameter *OR* we have a login shell parameter, read the env file @@ -57,14 +50,7 @@ pub(crate) fn run_commands( config_files::read_default_env_file(engine_state, &mut stack) } - perf( - "read env.nu", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read env.nu", start_time, use_color); let start_time = std::time::Instant::now(); // If we have a config file parameter *OR* we have a login shell parameter, read the config file @@ -77,14 +63,7 @@ pub(crate) fn run_commands( ); } - perf( - "read config.nu", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read config.nu", start_time, use_color); // If we have a login shell parameter, read the login file let start_time = std::time::Instant::now(); @@ -92,14 +71,7 @@ pub(crate) fn run_commands( config_files::read_loginshell_file(engine_state, &mut stack); } - perf( - "read login.nu", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read login.nu", start_time, use_color); } // Before running commands, set up the startup time @@ -123,14 +95,7 @@ pub(crate) fn run_commands( report_error_new(engine_state, &err); std::process::exit(1); } - perf( - "evaluate_commands", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("evaluate_commands", start_time, use_color); } pub(crate) fn run_file( @@ -153,14 +118,7 @@ pub(crate) fn run_file( let start_time = std::time::Instant::now(); #[cfg(feature = "plugin")] read_plugin_file(engine_state, parsed_nu_cli_args.plugin_file, NUSHELL_FOLDER); - perf( - "read plugins", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read plugins", start_time, use_color); let start_time = std::time::Instant::now(); // only want to load config and env if relative argument is provided. @@ -174,14 +132,7 @@ pub(crate) fn run_file( } else { config_files::read_default_env_file(engine_state, &mut stack) } - perf( - "read env.nu", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read env.nu", start_time, use_color); let start_time = std::time::Instant::now(); if parsed_nu_cli_args.config_file.is_some() { @@ -192,14 +143,7 @@ pub(crate) fn run_file( false, ); } - perf( - "read config.nu", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("read config.nu", start_time, use_color); } // Regenerate the $nu constant to contain the startup time and any other potential updates @@ -216,14 +160,7 @@ pub(crate) fn run_file( report_error_new(engine_state, &err); std::process::exit(1); } - perf( - "evaluate_file", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("evaluate_file", start_time, use_color); let start_time = std::time::Instant::now(); let last_exit_code = stack.get_env_var(&*engine_state, "LAST_EXIT_CODE"); @@ -235,14 +172,7 @@ pub(crate) fn run_file( } } } - perf( - "get exit code", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("get exit code", start_time, use_color); } pub(crate) fn run_repl( @@ -268,14 +198,7 @@ pub(crate) fn run_repl( // Reload use_color from config in case it's different from the default value let use_color = engine_state.get_config().use_ansi_coloring; - perf( - "setup_config", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("setup_config", start_time, use_color); let start_time = std::time::Instant::now(); let ret_val = evaluate_repl( @@ -286,14 +209,7 @@ pub(crate) fn run_repl( parsed_nu_cli_args.no_std_lib, entire_start_time, ); - perf( - "evaluate_repl", - start_time, - file!(), - line!(), - column!(), - use_color, - ); + perf!("evaluate_repl", start_time, use_color); ret_val }