1use nu_engine::{ClosureEvalOnce, command_prelude::*};
2use nu_protocol::{
3 debugger::{DurationMode, Profiler, ProfilerOptions},
4 engine::Closure,
5 shell_error::generic::GenericError,
6};
7
8#[derive(Clone)]
9pub struct DebugProfile;
10
11impl Command for DebugProfile {
12 fn name(&self) -> &str {
13 "debug profile"
14 }
15
16 fn signature(&self) -> nu_protocol::Signature {
17 Signature::build("debug profile")
18 .required(
19 "closure",
20 SyntaxShape::Closure(None),
21 "The closure to profile.",
22 )
23 .switch("spans", "Collect spans of profiled elements.", Some('s'))
24 .switch(
25 "expand-source",
26 "Collect full source fragments of profiled elements.",
27 Some('e'),
28 )
29 .switch(
30 "values",
31 "Collect pipeline element output values.",
32 Some('v'),
33 )
34 .switch("lines", "Collect line numbers.", Some('l'))
35 .switch(
36 "duration-values",
37 "Report instruction duration as duration values rather than milliseconds.",
38 Some('d'),
39 )
40 .named(
41 "max-depth",
42 SyntaxShape::Int,
43 "How many blocks/closures deep to step into (default 2).",
44 Some('m'),
45 )
46 .input_output_types(vec![(Type::Any, Type::table())])
47 .category(Category::Debug)
48 }
49
50 fn description(&self) -> &str {
51 "Profile pipeline elements in a closure."
52 }
53
54 fn extra_description(&self) -> &str {
55 r#"The profiler profiles every evaluated instruction inside a closure, stepping into all
56commands calls and other blocks/closures.
57
58The output can be heavily customized. By default, the following columns are included:
59- depth : Depth of the instruction. Each entered block adds one level of depth. How many
60 blocks deep to step into is controlled with the --max-depth option.
61- id : ID of the instruction
62- parent_id : ID of the instruction that created the parent scope
63- source : Source code that generated the instruction. If the source code has multiple lines,
64 only the first line is used and `...` is appended to the end. Full source code can
65 be shown with the --expand-source flag.
66- pc : The index of the instruction within the block.
67- instruction : The pretty printed instruction being evaluated.
68- duration : How long it took to run the instruction.
69- (optional) span : Span associated with the instruction. Can be viewed via the `view span`
70 command. Enabled with the --spans flag.
71- (optional) output : The output value of the instruction. Enabled with the --values flag.
72
73To illustrate the depth and IDs, consider `debug profile { do { if true { echo 'spam' } } }`. A unique ID is generated each time an instruction is executed, and there are two levels of depth:
74
75```
76depth id parent_id source pc instruction
77 0 0 0 debug profile { do { if true { 'spam' } } } 0 <start>
78 1 1 0 { if true { 'spam' } } 0 load-literal %1, closure(2164)
79 1 2 0 { if true { 'spam' } } 1 push-positional %1
80 1 3 0 { do { if true { 'spam' } } } 2 redirect-out caller
81 1 4 0 { do { if true { 'spam' } } } 3 redirect-err caller
82 1 5 0 do 4 call decl 7 "do", %0
83 2 6 5 true 0 load-literal %1, bool(true)
84 2 7 5 if 1 not %1
85 2 8 5 if 2 branch-if %1, 5
86 2 9 5 'spam' 3 load-literal %0, string("spam")
87 2 10 5 if 4 jump 6
88 2 11 5 { if true { 'spam' } } 6 return %0
89 1 12 0 { do { if true { 'spam' } } } 5 return %0
90```
91
92Each block entered increments depth by 1 and each block left decrements it by one. This way you can
93control the profiling granularity. Passing --max-depth=1 to the above would stop inside the `do`
94at `if true { 'spam' }`. The id is used to identify each element. The parent_id tells you that the
95instructions inside the block are being executed because of `do` (5), which in turn was spawned from
96the root `debug profile { ... }`.
97
98For a better understanding of how instructions map to source code, see the `view ir` command.
99
100Note: In some cases, the ordering of pipeline elements might not be intuitive. For example,
101`[ a bb cc ] | each { $in | str length }` involves some implicit collects and lazy evaluation
102confusing the id/parent_id hierarchy. The --expr flag is helpful for investigating these issues."#
103 }
104
105 fn run(
106 &self,
107 engine_state: &EngineState,
108 stack: &mut Stack,
109 call: &Call,
110 input: PipelineData,
111 ) -> Result<PipelineData, ShellError> {
112 let closure: Closure = call.req(engine_state, stack, 0)?;
113 let collect_spans = call.has_flag(engine_state, stack, "spans")?;
114 let collect_expanded_source = call.has_flag(engine_state, stack, "expanded-source")?;
115 let collect_values = call.has_flag(engine_state, stack, "values")?;
116 let collect_lines = call.has_flag(engine_state, stack, "lines")?;
117 let duration_values = call.has_flag(engine_state, stack, "duration-values")?;
118 let max_depth = call
119 .get_flag(engine_state, stack, "max-depth")?
120 .unwrap_or(2);
121
122 let duration_mode = match duration_values {
123 true => DurationMode::Value,
124 false => DurationMode::Milliseconds,
125 };
126 let profiler = Profiler::new(
127 ProfilerOptions {
128 max_depth,
129 collect_spans,
130 collect_source: true,
131 collect_expanded_source,
132 collect_values,
133 collect_exprs: false,
134 collect_instructions: true,
135 collect_lines,
136 duration_mode,
137 },
138 call.span(),
139 );
140
141 let lock_err = |_| {
142 ShellError::Generic(GenericError::new(
143 "Profiler Error",
144 "could not lock debugger, poisoned mutex",
145 call.head,
146 ))
147 };
148
149 engine_state
150 .activate_debugger(Box::new(profiler))
151 .map_err(lock_err)?;
152
153 let result = ClosureEvalOnce::new(engine_state, stack, closure).run_with_input(input);
154
155 let pipeline_data = result?;
157
158 let _ = pipeline_data.into_value(call.span());
160
161 Ok(engine_state
162 .deactivate_debugger()
163 .map_err(lock_err)?
164 .report(engine_state, call.span())?
165 .into_pipeline_data())
166 }
167
168 fn examples(&self) -> Vec<Example<'_>> {
169 vec![
170 Example {
171 description: "Profile config evaluation.",
172 example: "debug profile { source $nu.config-path }",
173 result: None,
174 },
175 Example {
176 description: "Profile config evaluation with more granularity.",
177 example: "debug profile { source $nu.config-path } --max-depth 4",
178 result: None,
179 },
180 ]
181 }
182}