diff --git a/cli/args/flags.rs b/cli/args/flags.rs index 9b0f840e9d..5261411ce0 100644 --- a/cli/args/flags.rs +++ b/cli/args/flags.rs @@ -417,6 +417,7 @@ pub struct Flags { pub no_prompt: bool, pub reload: bool, pub seed: Option, + pub strace_ops: Option>, pub unstable: bool, pub unstable_bare_node_builtins: bool, pub unstable_byonm: bool, @@ -2688,6 +2689,7 @@ fn runtime_args( .arg(v8_flags_arg()) .arg(seed_arg()) .arg(enable_testing_features_arg()) + .arg(strace_ops_arg()) } fn inspect_args(app: Command) -> Command { @@ -2837,6 +2839,17 @@ fn enable_testing_features_arg() -> Arg { .hide(true) } +fn strace_ops_arg() -> Arg { + Arg::new("strace-ops") + .long("strace-ops") + .num_args(0..) + .use_value_delimiter(true) + .require_equals(true) + .value_name("OPS") + .help("Trace low-level op calls") + .hide(true) +} + fn v8_flags_arg() -> Arg { Arg::new("v8-flags") .long("v8-flags") @@ -3802,6 +3815,7 @@ fn permission_args_parse(flags: &mut Flags, matches: &mut ArgMatches) { flags.no_prompt = true; } } + fn unsafely_ignore_certificate_errors_parse( flags: &mut Flags, matches: &mut ArgMatches, @@ -3833,6 +3847,7 @@ fn runtime_args_parse( seed_arg_parse(flags, matches); enable_testing_features_arg_parse(flags, matches); env_file_arg_parse(flags, matches); + strace_ops_parse(flags, matches); } fn inspect_arg_parse(flags: &mut Flags, matches: &mut ArgMatches) { @@ -3900,6 +3915,12 @@ fn enable_testing_features_arg_parse( } } +fn strace_ops_parse(flags: &mut Flags, matches: &mut ArgMatches) { + if let Some(patterns) = matches.remove_many::("strace-ops") { + flags.strace_ops = Some(patterns.collect()); + } +} + fn cached_only_arg_parse(flags: &mut Flags, matches: &mut ArgMatches) { if matches.get_flag("cached-only") { flags.cached_only = true; @@ -5400,6 +5421,19 @@ mod tests { ); } + #[test] + fn repl_strace_ops() { + // Lightly test this undocumented flag + let r = flags_from_vec(svec!["deno", "repl", "--strace-ops"]); + assert_eq!(r.unwrap().strace_ops, Some(vec![])); + let r = + flags_from_vec(svec!["deno", "repl", "--strace-ops=http,websocket"]); + assert_eq!( + r.unwrap().strace_ops, + Some(vec!["http".to_string(), "websocket".to_string()]) + ); + } + #[test] fn repl_with_flags() { #[rustfmt::skip] diff --git a/cli/args/mod.rs b/cli/args/mod.rs index 9c113acd2b..24d1237aa5 100644 --- a/cli/args/mod.rs +++ b/cli/args/mod.rs @@ -1245,6 +1245,10 @@ impl CliOptions { &self.flags.subcommand } + pub fn strace_ops(&self) -> &Option> { + &self.flags.strace_ops + } + pub fn type_check_mode(&self) -> TypeCheckMode { self.flags.type_check_mode } diff --git a/cli/factory.rs b/cli/factory.rs index e696313052..bd457e2ab8 100644 --- a/cli/factory.rs +++ b/cli/factory.rs @@ -676,6 +676,7 @@ impl CliFactory { hmr: self.options.has_hmr(), inspect_brk: self.options.inspect_brk().is_some(), inspect_wait: self.options.inspect_wait().is_some(), + strace_ops: self.options.strace_ops().clone(), is_inspecting: self.options.is_inspecting(), is_npm_main: self.options.is_npm_main(), location: self.options.location_flag().clone(), diff --git a/cli/standalone/mod.rs b/cli/standalone/mod.rs index 4c54308341..56281b34b1 100644 --- a/cli/standalone/mod.rs +++ b/cli/standalone/mod.rs @@ -459,6 +459,7 @@ pub async fn run( hmr: false, inspect_brk: false, inspect_wait: false, + strace_ops: None, is_inspecting: false, is_npm_main: main_module.scheme() == "npm", location: metadata.location, diff --git a/cli/worker.rs b/cli/worker.rs index 173d944c00..19fa400341 100644 --- a/cli/worker.rs +++ b/cli/worker.rs @@ -92,6 +92,7 @@ pub struct CliMainWorkerOptions { pub hmr: bool, pub inspect_brk: bool, pub inspect_wait: bool, + pub strace_ops: Option>, pub is_inspecting: bool, pub is_npm_main: bool, pub location: Option, @@ -580,6 +581,7 @@ impl CliMainWorkerFactory { maybe_inspector_server, should_break_on_first_statement: shared.options.inspect_brk, should_wait_for_inspector_session: shared.options.inspect_wait, + strace_ops: shared.options.strace_ops.clone(), module_loader, fs: shared.fs.clone(), npm_resolver: Some(shared.npm_resolver.clone().into_npm_resolver()), diff --git a/runtime/worker.rs b/runtime/worker.rs index 4775b474c7..b0dc6259f3 100644 --- a/runtime/worker.rs +++ b/runtime/worker.rs @@ -7,6 +7,7 @@ use std::sync::atomic::Ordering::Relaxed; use std::sync::Arc; use std::task::Context; use std::task::Poll; +use std::time::Instant; use deno_broadcast_channel::InMemoryBroadcastChannel; use deno_cache::CreateCache; @@ -15,6 +16,7 @@ use deno_core::ascii_str; use deno_core::error::AnyError; use deno_core::error::JsError; use deno_core::futures::Future; +use deno_core::merge_op_metrics; use deno_core::v8; use deno_core::CompiledWasmModuleStore; use deno_core::Extension; @@ -27,6 +29,7 @@ use deno_core::ModuleCode; use deno_core::ModuleId; use deno_core::ModuleLoader; use deno_core::ModuleSpecifier; +use deno_core::OpMetricsFactoryFn; use deno_core::OpMetricsSummaryTracker; use deno_core::RuntimeOptions; use deno_core::SharedArrayBufferStore; @@ -120,6 +123,8 @@ pub struct WorkerOptions { // If true, the worker will wait for inspector session before executing // user code. pub should_wait_for_inspector_session: bool, + /// If Some, print a low-level trace output for ops matching the given patterns. + pub strace_ops: Option>, /// Allows to map error type to a string "class" used to represent /// error in JavaScript. @@ -159,6 +164,7 @@ impl Default for WorkerOptions { unsafely_ignore_certificate_errors: Default::default(), should_break_on_first_statement: Default::default(), should_wait_for_inspector_session: Default::default(), + strace_ops: Default::default(), compiled_wasm_module_store: Default::default(), shared_array_buffer_store: Default::default(), maybe_inspector_server: Default::default(), @@ -181,6 +187,71 @@ impl Default for WorkerOptions { } } +fn create_op_metrics( + enable_op_summary_metrics: bool, + strace_ops: Option>, +) -> ( + Option>, + Option, +) { + let mut op_summary_metrics = None; + let mut op_metrics_factory_fn: Option = None; + let now = Instant::now(); + let max_len: Rc> = Default::default(); + if let Some(patterns) = strace_ops { + /// Match an op name against a list of patterns + fn matches_pattern(patterns: &[String], name: &str) -> bool { + let mut found_match = false; + let mut found_nomatch = false; + for pattern in patterns.iter() { + if let Some(pattern) = pattern.strip_prefix('-') { + if name.contains(pattern) { + return false; + } + } else if name.contains(pattern.as_str()) { + found_match = true; + } else { + found_nomatch = true; + } + } + + found_match || !found_nomatch + } + + op_metrics_factory_fn = Some(Box::new(move |_, _, decl| { + // If we don't match a requested pattern, or we match a negative pattern, bail + if !matches_pattern(&patterns, decl.name) { + return None; + } + + max_len.set(max_len.get().max(decl.name.len())); + let max_len = max_len.clone(); + Some(Rc::new( + move |op: &deno_core::_ops::OpCtx, event, source| { + eprintln!( + "[{: >10.3}] {name:max_len$}: {event:?} {source:?}", + now.elapsed().as_secs_f64(), + name = op.decl().name, + max_len = max_len.get() + ); + }, + )) + })); + } + + if enable_op_summary_metrics { + let summary = Rc::new(OpMetricsSummaryTracker::default()); + let summary_metrics = summary.clone().op_metrics_factory_fn(|_| true); + op_metrics_factory_fn = Some(match op_metrics_factory_fn { + Some(f) => merge_op_metrics(f, summary_metrics), + None => summary_metrics, + }); + op_summary_metrics = Some(summary); + } + + (op_summary_metrics, op_metrics_factory_fn) +} + impl MainWorker { pub fn bootstrap_from_options( main_module: ModuleSpecifier, @@ -209,6 +280,12 @@ impl MainWorker { }, ); + // Get our op metrics + let (op_summary_metrics, op_metrics_factory_fn) = create_op_metrics( + options.bootstrap.enable_op_summary_metrics, + options.strace_ops, + ); + // Permissions: many ops depend on this let enable_testing_features = options.bootstrap.enable_testing_features; let exit_code = ExitCode(Arc::new(AtomicI32::new(0))); @@ -325,18 +402,6 @@ impl MainWorker { } } - // Hook up the summary metrics if the user or subcommand requested them - let (op_summary_metrics, op_metrics_factory_fn) = - if options.bootstrap.enable_op_summary_metrics { - let op_summary_metrics = Rc::new(OpMetricsSummaryTracker::default()); - ( - Some(op_summary_metrics.clone()), - Some(op_summary_metrics.op_metrics_factory_fn(|_| true)), - ) - } else { - (None, None) - }; - extensions.extend(std::mem::take(&mut options.extensions)); #[cfg(all(feature = "include_js_files_for_snapshotting", feature = "dont_create_runtime_snapshot", not(feature = "__runtime_js_sources")))]