made perf a macro

This commit is contained in:
Jack Wright 2024-06-25 16:50:19 -07:00
parent 5ec6395783
commit 45a7281422
8 changed files with 148 additions and 361 deletions

View File

@ -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
}

View File

@ -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,13 +89,10 @@ pub fn evaluate_repl(
if let Err(e) = convert_env_values(engine_state, &unique_stack) {
report_error_new(engine_state, &e);
}
perf(
perf!(
"translate env vars",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
// seed env vars
@ -225,13 +222,10 @@ 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(
perf!(
"setup reedline",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
if let Some(history) = engine_state.history_config() {
@ -239,13 +233,10 @@ fn get_line_editor(
line_editor = setup_history(nushell_path, engine_state, line_editor, history)?;
perf(
perf!(
"setup history",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
Ok(line_editor)
@ -289,13 +280,10 @@ 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(
perf!(
"merge env",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -303,13 +291,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
if let Some(ctrlc) = &mut engine_state.ctrlc {
ctrlc.store(false, Ordering::SeqCst);
}
perf(
perf!(
"reset ctrlc",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -320,13 +305,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
report_error_new(engine_state, &err);
}
}
perf(
perf!(
"pre-prompt hook",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -336,13 +318,10 @@ 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(
perf!(
"env-change hook",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let engine_reference = Arc::new(engine_state.clone());
@ -355,13 +334,10 @@ 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(
perf!(
"get config/cursor config",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -394,13 +370,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
.with_ansi_colors(config.use_ansi_coloring)
.with_cursor_config(cursor_config);
perf(
perf!(
"reedline builder",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let style_computer = StyleComputer::from_config(engine_state, &stack_arc);
@ -416,13 +389,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
line_editor.disable_hints()
};
perf(
perf!(
"reedline coloring/style_computer",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -433,13 +403,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
Reedline::create()
});
perf(
perf!(
"reedline adding menus",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -457,13 +424,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
line_editor
};
perf(
perf!(
"reedline buffer_editor",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
if let Some(history) = engine_state.history_config() {
@ -474,13 +438,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
}
}
perf(
perf!(
"sync_history",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -488,13 +449,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
// Changing the line editor based on the found keybindings
line_editor = setup_keybindings(engine_state, line_editor);
perf(
perf!(
"keybindings",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -512,13 +470,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
nu_prompt,
);
perf(
perf!(
"update_prompt",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
*entry_num += 1;
@ -546,13 +501,10 @@ 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(
perf!(
"line_editor setup",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let line_editor_input_time = std::time::Instant::now();
@ -590,13 +542,10 @@ fn loop_iteration(ctx: LoopContext) -> (bool, Stack, Reedline) {
}
}
perf(
perf!(
"pre_execution_hook",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let mut repl = engine_state.repl_state.lock().expect("repl state mutex");
@ -612,26 +561,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 +582,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 +709,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,13 +995,10 @@ fn run_shell_integration_osc2(
// ESC]2;stringBEL -- Set window title to string
run_ansi_sequence(&format!("\x1b]2;{title}\x07"));
perf(
perf!(
"set title with command osc2",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
}
@ -1093,13 +1024,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 +1044,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 +1067,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 +1293,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 +1308,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 +1324,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
);
}
}

View File

@ -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

View File

@ -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<String>) -> 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(),
);
}
};
}

View File

@ -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;
@ -395,13 +395,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);
@ -437,13 +434,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)
@ -521,14 +515,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 {
@ -566,14 +553,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)

View File

@ -15,8 +15,6 @@ use crate::{
series::series_commands, values::PolarsPluginCustomValue,
};
use nu_utils::utils::perf as nu_utils_perf;
pub trait EngineWrapper {
fn get_env_var(&self, key: &str) -> Option<String>;
fn use_color(&self) -> bool;
@ -47,24 +45,6 @@ impl EngineWrapper for &EngineInterface {
}
}
pub fn perf(
env: impl EngineWrapper,
msg: &str,
start_time: std::time::Instant,
file: &str,
line: u32,
column: u32,
) {
nu_utils_perf(
msg,
start_time,
file,
line,
column,
env.use_color(),
);
}
#[derive(Default)]
pub struct PolarsPlugin {
pub(crate) cache: Cache,

View File

@ -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,13 +219,10 @@ fn main() -> Result<()> {
logger(|builder| configure(&level, &target, filters, builder))?;
// info!("start logging {}:{}:{}", file!(), line!(), column!());
perf(
perf!(
"start logging",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -245,26 +242,20 @@ fn main() -> Result<()> {
"env-path",
parsed_nu_cli_args.env_file.as_ref(),
);
perf(
perf!(
"set_config_path",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
#[cfg(unix)]
{
start_time = std::time::Instant::now();
terminal::acquire(engine_state.is_interactive);
perf(
perf!(
"acquire_terminal",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -279,25 +270,19 @@ fn main() -> Result<()> {
engine_state.add_env_var("NU_LIB_DIRS".into(), Value::list(vals, span));
}
perf(
perf!(
"NU_LIB_DIRS setup",
start_time,
file!(),
line!(),
column!(),
use_color,
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(
perf!(
"gather env vars",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
engine_state.add_env_var(
@ -359,13 +344,10 @@ fn main() -> Result<()> {
}
std::process::exit(0)
}
perf(
perf!(
"run test_bins",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
start_time = std::time::Instant::now();
@ -376,25 +358,19 @@ fn main() -> Result<()> {
trace!("not redirecting stdin");
PipelineData::empty()
};
perf(
perf!(
"redirect stdin",
start_time,
file!(),
line!(),
column!(),
use_color,
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(
perf!(
"create_nu_constant",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
#[cfg(feature = "plugin")]
@ -433,25 +409,19 @@ fn main() -> Result<()> {
}
engine_state.merge_delta(working_set.render())?;
perf(
perf!(
"load plugins specified in --plugins",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
)
}
start_time = std::time::Instant::now();
if parsed_nu_cli_args.lsp {
perf(
perf!(
"lsp starting",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
if parsed_nu_cli_args.no_config_file.is_none() {

View File

@ -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,13 +35,10 @@ pub(crate) fn run_commands(
#[cfg(feature = "plugin")]
read_plugin_file(engine_state, parsed_nu_cli_args.plugin_file, NUSHELL_FOLDER);
perf(
perf!(
"read plugins",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -57,13 +54,10 @@ pub(crate) fn run_commands(
config_files::read_default_env_file(engine_state, &mut stack)
}
perf(
perf!(
"read env.nu",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -77,13 +71,10 @@ pub(crate) fn run_commands(
);
}
perf(
perf!(
"read config.nu",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
// If we have a login shell parameter, read the login file
@ -92,13 +83,10 @@ pub(crate) fn run_commands(
config_files::read_loginshell_file(engine_state, &mut stack);
}
perf(
perf!(
"read login.nu",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -123,13 +111,10 @@ pub(crate) fn run_commands(
report_error_new(engine_state, &err);
std::process::exit(1);
}
perf(
perf!(
"evaluate_commands",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -153,13 +138,10 @@ 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(
perf!(
"read plugins",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -174,13 +156,10 @@ pub(crate) fn run_file(
} else {
config_files::read_default_env_file(engine_state, &mut stack)
}
perf(
perf!(
"read env.nu",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -192,13 +171,10 @@ pub(crate) fn run_file(
false,
);
}
perf(
perf!(
"read config.nu",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -216,13 +192,10 @@ pub(crate) fn run_file(
report_error_new(engine_state, &err);
std::process::exit(1);
}
perf(
perf!(
"evaluate_file",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -235,13 +208,10 @@ pub(crate) fn run_file(
}
}
}
perf(
perf!(
"get exit code",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
}
@ -268,13 +238,10 @@ 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(
perf!(
"setup_config",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
let start_time = std::time::Instant::now();
@ -286,13 +253,10 @@ pub(crate) fn run_repl(
parsed_nu_cli_args.no_std_lib,
entire_start_time,
);
perf(
perf!(
"evaluate_repl",
start_time,
file!(),
line!(),
column!(),
use_color,
use_color
);
ret_val