remove profiling from nushell's hot loop (#10325)

# Description

This removes pipeline element profiling. This could be a useful feature,
but pipeline elements are going to be the most sensitive to in terms of
performance, as `eval_block` and how pipelines are built is one of the
hot loops inside of the eval engine.

# User-Facing Changes

Removes pipeline element profiling.

# Tests + Formatting
<!--
Don't forget to add tests that cover your changes.

Make sure you've run and fixed any issues with these commands:

- `cargo fmt --all -- --check` to check standard code formatting (`cargo
fmt --all` applies these changes)
- `cargo clippy --workspace -- -D warnings -D clippy::unwrap_used` to
check that you're using the standard code style
- `cargo test --workspace` to check that all tests pass (on Windows make
sure to [enable developer
mode](https://learn.microsoft.com/en-us/windows/apps/get-started/developer-mode-features-and-debugging))
- `cargo run -- -c "use std testing; testing run-tests --path
crates/nu-std"` to run the tests for the standard library

> **Note**
> from `nushell` you can also use the `toolkit` as follows
> ```bash
> use toolkit.nu # or use an `env_change` hook to activate it
automatically
> toolkit check pr
> ```
-->

# After Submitting
<!-- If your PR had any user-facing changes, update [the
documentation](https://github.com/nushell/nushell.github.io) after the
PR is merged, if necessary. This will help us keep the docs up to date.
-->
This commit is contained in:
JT 2023-09-12 06:50:03 +12:00 committed by GitHub
parent d618b60d9e
commit 84c10de864
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 6 additions and 193 deletions

View File

@ -1,6 +1,6 @@
use nu_engine::{eval_block, CallExt}; use nu_engine::{eval_block, CallExt};
use nu_protocol::ast::Call; use nu_protocol::ast::Call;
use nu_protocol::engine::{Closure, Command, EngineState, ProfilingConfig, Stack}; use nu_protocol::engine::{Closure, Command, EngineState, Stack};
use nu_protocol::{ use nu_protocol::{
Category, DataSource, Example, IntoPipelineData, PipelineData, PipelineMetadata, Signature, Category, DataSource, Example, IntoPipelineData, PipelineData, PipelineMetadata, Signature,
Spanned, SyntaxShape, Type, Value, Spanned, SyntaxShape, Type, Value,
@ -70,24 +70,13 @@ Current known limitations are:
} }
} }
stack.profiling_config = ProfilingConfig::new(
call.get_flag::<i64>(engine_state, &mut stack, "max-depth")?
.unwrap_or(1),
call.has_flag("source"),
call.has_flag("values"),
);
let profiling_metadata = Box::new(PipelineMetadata {
data_source: DataSource::Profiling(vec![]),
});
let result = if let Some(PipelineMetadata { let result = if let Some(PipelineMetadata {
data_source: DataSource::Profiling(values), data_source: DataSource::Profiling(values),
}) = eval_block( }) = eval_block(
engine_state, engine_state,
&mut stack, &mut stack,
block, block,
input_val.into_pipeline_data_with_metadata(profiling_metadata), input_val.into_pipeline_data(),
redirect_stdout, redirect_stdout,
redirect_stderr, redirect_stderr,
)? )?

View File

@ -5,13 +5,11 @@ use nu_protocol::{
eval_operator, Argument, Assignment, Bits, Block, Boolean, Call, Comparison, Expr, eval_operator, Argument, Assignment, Bits, Block, Boolean, Call, Comparison, Expr,
Expression, Math, Operator, PathMember, PipelineElement, Redirection, Expression, Math, Operator, PathMember, PipelineElement, Redirection,
}, },
engine::{EngineState, ProfilingConfig, Stack}, engine::{EngineState, Stack},
record, DataSource, IntoInterruptiblePipelineData, IntoPipelineData, PipelineData, IntoInterruptiblePipelineData, IntoPipelineData, PipelineData, Range, Record, ShellError, Span,
PipelineMetadata, Range, Record, ShellError, Span, Spanned, Unit, Value, VarId, Spanned, Unit, Value, VarId, ENV_VARIABLE_ID,
ENV_VARIABLE_ID,
}; };
use std::collections::HashMap; use std::collections::HashMap;
use std::time::Instant;
pub fn eval_call( pub fn eval_call(
engine_state: &EngineState, engine_state: &EngineState,
@ -1016,13 +1014,6 @@ pub fn eval_block(
let num_pipelines = block.len(); let num_pipelines = block.len();
let mut input_metadata = if stack.profiling_config.should_debug() {
stack.profiling_config.enter_block();
input.metadata()
} else {
None
};
for (pipeline_idx, pipeline) in block.pipelines.iter().enumerate() { for (pipeline_idx, pipeline) in block.pipelines.iter().enumerate() {
let mut i = 0; let mut i = 0;
@ -1036,12 +1027,6 @@ pub fn eval_block(
| PipelineElement::SeparateRedirection { .. } | PipelineElement::SeparateRedirection { .. }
))); )));
let start_time = if stack.profiling_config.should_debug() {
Some(Instant::now())
} else {
None
};
// if eval internal command failed, it can just make early return with `Err(ShellError)`. // if eval internal command failed, it can just make early return with `Err(ShellError)`.
let eval_result = eval_element_with_input( let eval_result = eval_element_with_input(
engine_state, engine_state,
@ -1060,34 +1045,6 @@ pub fn eval_block(
redirect_stderr, redirect_stderr,
); );
let end_time = if stack.profiling_config.should_debug() {
Some(Instant::now())
} else {
None
};
if let (Some(start_time), Some(end_time), Some(input_metadata)) =
(start_time, end_time, input_metadata.as_deref_mut())
{
let element_span = pipeline.elements[i].span();
let element_str = String::from_utf8_lossy(
engine_state.get_span_contents(pipeline.elements[i].span()),
)
.to_string();
collect_profiling_metadata(
pipeline_idx,
i,
element_str,
element_span,
start_time,
end_time,
&stack.profiling_config,
&eval_result,
input_metadata,
);
}
match (eval_result, redirect_stderr) { match (eval_result, redirect_stderr) {
(Ok((pipeline_data, _)), true) => { (Ok((pipeline_data, _)), true) => {
input = pipeline_data; input = pipeline_data;
@ -1112,9 +1069,6 @@ pub fn eval_block(
// make early return so remaining commands will not be executed. // make early return so remaining commands will not be executed.
// don't return `Err(ShellError)`, so nushell wouldn't show extra error message. // don't return `Err(ShellError)`, so nushell wouldn't show extra error message.
if output.1 { if output.1 {
if stack.profiling_config.should_debug() {
stack.profiling_config.leave_block();
}
return Ok(input); return Ok(input);
} }
} }
@ -1148,12 +1102,7 @@ pub fn eval_block(
} }
} }
if stack.profiling_config.should_debug() { Ok(input)
stack.profiling_config.leave_block();
Ok(input.set_metadata(input_metadata))
} else {
Ok(input)
}
} }
pub fn eval_subexpression( pub fn eval_subexpression(
@ -1208,86 +1157,3 @@ pub fn eval_variable(
fn compute(size: i64, unit: Unit, span: Span) -> Result<Value, ShellError> { fn compute(size: i64, unit: Unit, span: Span) -> Result<Value, ShellError> {
unit.to_value(size, span) unit.to_value(size, span)
} }
#[allow(clippy::too_many_arguments)]
fn collect_profiling_metadata(
pipeline_idx: usize,
element_idx: usize,
element_str: String,
element_span: Span,
start_time: Instant,
end_time: Instant,
profiling_config: &ProfilingConfig,
eval_result: &Result<(PipelineData, bool), ShellError>,
input_metadata: &mut PipelineMetadata,
) {
let element_str = Value::string(element_str, element_span);
let time_ns = (end_time - start_time).as_nanos() as i64;
let span_record = record! {
"start" => Value::int(element_span.start as i64, element_span),
"end" => Value::int(element_span.end as i64, element_span),
};
let mut record = record! {
"pipeline_idx" => Value::int(pipeline_idx as i64, element_span),
"element_idx" => Value::int(element_idx as i64, element_span),
"depth" => Value::int(profiling_config.depth, element_span),
"span" => Value::record(span_record, element_span),
};
if profiling_config.collect_source {
record.push("source", element_str);
}
if profiling_config.collect_values {
let value = match &eval_result {
Ok((PipelineData::Value(val, ..), ..)) => val.clone(),
Ok((PipelineData::ListStream(..), ..)) => Value::string("list-stream", element_span),
Ok((PipelineData::ExternalStream { .. }, ..)) => {
Value::string("raw stream", element_span)
}
Ok((PipelineData::Empty, ..)) => Value::nothing(element_span),
Err(err) => Value::error(err.clone(), element_span),
};
record.push("value", value);
}
record.push("time", Value::duration(time_ns, element_span));
let record = Value::record(record, element_span);
let element_metadata = if let Ok((pipeline_data, ..)) = &eval_result {
pipeline_data.metadata()
} else {
None
};
if let PipelineMetadata {
data_source: DataSource::Profiling(tgt_vals),
} = input_metadata
{
tgt_vals.push(record);
} else {
*input_metadata = PipelineMetadata {
data_source: DataSource::Profiling(vec![record]),
};
}
if let Some(PipelineMetadata {
data_source: DataSource::Profiling(element_vals),
}) = element_metadata.map(|m| *m)
{
if let PipelineMetadata {
data_source: DataSource::Profiling(tgt_vals),
} = input_metadata
{
tgt_vals.extend(element_vals);
} else {
*input_metadata = PipelineMetadata {
data_source: DataSource::Profiling(element_vals),
};
}
}
}

View File

@ -7,44 +7,6 @@ use crate::{ShellError, Span, Value, VarId};
/// Environment variables per overlay /// Environment variables per overlay
pub type EnvVars = HashMap<String, HashMap<String, Value>>; pub type EnvVars = HashMap<String, HashMap<String, Value>>;
#[derive(Debug, Clone)]
pub struct ProfilingConfig {
pub max_depth: i64,
pub depth: i64,
pub collect_source: bool,
pub collect_values: bool,
}
impl ProfilingConfig {
pub fn new(max_depth: i64, collect_source: bool, collect_values: bool) -> Self {
ProfilingConfig {
max_depth,
depth: 0,
collect_source,
collect_values,
}
}
pub fn enter_block(&mut self) {
self.depth += 1;
}
pub fn leave_block(&mut self) {
self.depth -= 1;
}
pub fn should_debug(&self) -> bool {
self.depth <= self.max_depth
}
pub fn reset(&mut self) {
self.max_depth = 0;
self.depth = 0;
self.collect_source = false;
self.collect_values = false;
}
}
/// A runtime value stack used during evaluation /// A runtime value stack used during evaluation
/// ///
/// A note on implementation: /// A note on implementation:
@ -73,7 +35,6 @@ pub struct Stack {
/// List of active overlays /// List of active overlays
pub active_overlays: Vec<String>, pub active_overlays: Vec<String>,
pub recursion_count: Box<u64>, pub recursion_count: Box<u64>,
pub profiling_config: ProfilingConfig,
} }
impl Stack { impl Stack {
@ -84,7 +45,6 @@ impl Stack {
env_hidden: HashMap::new(), env_hidden: HashMap::new(),
active_overlays: vec![DEFAULT_OVERLAY_NAME.to_string()], active_overlays: vec![DEFAULT_OVERLAY_NAME.to_string()],
recursion_count: Box::new(0), recursion_count: Box::new(0),
profiling_config: ProfilingConfig::new(0, false, false),
} }
} }
@ -195,7 +155,6 @@ impl Stack {
env_hidden: self.env_hidden.clone(), env_hidden: self.env_hidden.clone(),
active_overlays: self.active_overlays.clone(), active_overlays: self.active_overlays.clone(),
recursion_count: self.recursion_count.to_owned(), recursion_count: self.recursion_count.to_owned(),
profiling_config: self.profiling_config.clone(),
} }
} }
@ -223,7 +182,6 @@ impl Stack {
env_hidden: self.env_hidden.clone(), env_hidden: self.env_hidden.clone(),
active_overlays: self.active_overlays.clone(), active_overlays: self.active_overlays.clone(),
recursion_count: self.recursion_count.to_owned(), recursion_count: self.recursion_count.to_owned(),
profiling_config: self.profiling_config.clone(),
} }
} }