diff options
Diffstat (limited to 'runtime')
-rw-r--r-- | runtime/clippy.toml | 1 | ||||
-rw-r--r-- | runtime/js/telemetry.js | 20 | ||||
-rw-r--r-- | runtime/lib.rs | 6 | ||||
-rw-r--r-- | runtime/ops/os/mod.rs | 4 | ||||
-rw-r--r-- | runtime/ops/otel.rs | 136 | ||||
-rw-r--r-- | runtime/snapshot.rs | 2 | ||||
-rw-r--r-- | runtime/web_worker.rs | 10 | ||||
-rw-r--r-- | runtime/worker.rs | 4 | ||||
-rw-r--r-- | runtime/worker_bootstrap.rs | 2 |
9 files changed, 128 insertions, 57 deletions
diff --git a/runtime/clippy.toml b/runtime/clippy.toml index 53676a90e..79e6bbd08 100644 --- a/runtime/clippy.toml +++ b/runtime/clippy.toml @@ -42,4 +42,5 @@ disallowed-methods = [ { path = "std::fs::write", reason = "File system operations should be done using FileSystem trait" }, { path = "std::path::Path::canonicalize", reason = "File system operations should be done using FileSystem trait" }, { path = "std::path::Path::exists", reason = "File system operations should be done using FileSystem trait" }, + { path = "std::process::exit", reason = "use deno_runtime::exit instead" }, ] diff --git a/runtime/js/telemetry.js b/runtime/js/telemetry.js index e9eb51f7c..195839fb1 100644 --- a/runtime/js/telemetry.js +++ b/runtime/js/telemetry.js @@ -22,11 +22,14 @@ const { ReflectApply, SymbolFor, Error, + NumberPrototypeToString, + StringPrototypePadStart, } = primordials; const { AsyncVariable, setAsyncContext } = core; const CURRENT = new AsyncVariable(); let TRACING_ENABLED = false; +let DETERMINISTIC = false; const SPAN_ID_BYTES = 8; const TRACE_ID_BYTES = 16; @@ -45,7 +48,19 @@ const hexSliceLookupTable = (function () { return table; })(); +let counter = 1; + +const INVALID_SPAN_ID = "0000000000000000"; +const INVALID_TRACE_ID = "00000000000000000000000000000000"; + function generateId(bytes) { + if (DETERMINISTIC) { + return StringPrototypePadStart( + NumberPrototypeToString(counter++, 16), + bytes * 2, + "0", + ); + } let out = ""; for (let i = 0; i < bytes / 4; i += 1) { const r32 = (MathRandom() * 2 ** 32) >>> 0; @@ -112,8 +127,6 @@ function submit(span) { const now = () => (performance.timeOrigin + performance.now()) / 1000; -const INVALID_SPAN_ID = "0000000000000000"; -const INVALID_TRACE_ID = "00000000000000000000000000000000"; const NO_ASYNC_CONTEXT = {}; class Span { @@ -362,9 +375,10 @@ const otelConsoleConfig = { export function bootstrap(config) { if (config.length === 0) return; - const { 0: consoleConfig } = config; + const { 0: consoleConfig, 1: deterministic } = config; TRACING_ENABLED = true; + DETERMINISTIC = deterministic === 1; switch (consoleConfig) { case otelConsoleConfig.capture: diff --git a/runtime/lib.rs b/runtime/lib.rs index 21b61e1c0..6fb8c5f3d 100644 --- a/runtime/lib.rs +++ b/runtime/lib.rs @@ -140,6 +140,12 @@ pub static UNSTABLE_GRANULAR_FLAGS: &[UnstableGranularFlag] = &[ }, ]; +pub fn exit(code: i32) -> ! { + crate::ops::otel::flush(); + #[allow(clippy::disallowed_methods)] + std::process::exit(code); +} + #[cfg(test)] mod test { use super::*; diff --git a/runtime/ops/os/mod.rs b/runtime/ops/os/mod.rs index 790962f38..b10a2939e 100644 --- a/runtime/ops/os/mod.rs +++ b/runtime/ops/os/mod.rs @@ -186,10 +186,8 @@ fn op_get_exit_code(state: &mut OpState) -> i32 { #[op2(fast)] fn op_exit(state: &mut OpState) { - crate::ops::otel::otel_drop_state(state); - let code = state.borrow::<ExitCode>().get(); - std::process::exit(code) + crate::exit(code) } #[op2] diff --git a/runtime/ops/otel.rs b/runtime/ops/otel.rs index 6a4750acc..b32764d7f 100644 --- a/runtime/ops/otel.rs +++ b/runtime/ops/otel.rs @@ -13,6 +13,9 @@ use deno_core::op2; use deno_core::v8; use deno_core::OpState; use once_cell::sync::Lazy; +use once_cell::sync::OnceCell; +use opentelemetry::logs::AnyValue; +use opentelemetry::logs::LogRecord as LogRecordTrait; use opentelemetry::logs::Severity; use opentelemetry::trace::SpanContext; use opentelemetry::trace::SpanId; @@ -58,15 +61,15 @@ type LogProcessor = BatchLogProcessor<OtelSharedRuntime>; deno_core::extension!( deno_otel, - ops = [op_otel_log, op_otel_span_start, op_otel_span_continue, op_otel_span_attribute, op_otel_span_attribute2, op_otel_span_attribute3, op_otel_span_flush], - options = { - otel_config: Option<OtelConfig>, // `None` means OpenTelemetry is disabled. - }, - state = |state, options| { - if let Some(otel_config) = options.otel_config { - otel_create_globals(otel_config, state).unwrap(); - } - } + ops = [ + op_otel_log, + op_otel_span_start, + op_otel_span_continue, + op_otel_span_attribute, + op_otel_span_attribute2, + op_otel_span_attribute3, + op_otel_span_flush, + ], ); #[derive(Debug, Clone, Serialize, Deserialize)] @@ -74,6 +77,7 @@ pub struct OtelConfig { pub runtime_name: Cow<'static, str>, pub runtime_version: Cow<'static, str>, pub console: OtelConsoleConfig, + pub deterministic: bool, } #[derive(Debug, Clone, Copy, Serialize, Deserialize)] @@ -90,6 +94,7 @@ impl Default for OtelConfig { runtime_name: Cow::Borrowed(env!("CARGO_PKG_NAME")), runtime_version: Cow::Borrowed(env!("CARGO_PKG_VERSION")), console: OtelConsoleConfig::Capture, + deterministic: false, } } } @@ -295,10 +300,10 @@ mod hyper_client { } } -fn otel_create_globals( - config: OtelConfig, - op_state: &mut OpState, -) -> anyhow::Result<()> { +static OTEL_PROCESSORS: OnceCell<(SpanProcessor, LogProcessor)> = + OnceCell::new(); + +pub fn init(config: OtelConfig) -> anyhow::Result<()> { // Parse the `OTEL_EXPORTER_OTLP_PROTOCOL` variable. The opentelemetry_* // crates don't do this automatically. // TODO(piscisaureus): enable GRPC support. @@ -318,7 +323,7 @@ fn otel_create_globals( return Err(anyhow!( "Failed to read env var OTEL_EXPORTER_OTLP_PROTOCOL: {}", err - )) + )); } }; @@ -372,7 +377,6 @@ fn otel_create_globals( let mut span_processor = BatchSpanProcessor::builder(span_exporter, OtelSharedRuntime).build(); span_processor.set_resource(&resource); - op_state.put::<SpanProcessor>(span_processor); let log_exporter = HttpExporterBuilder::default() .with_http_client(client) @@ -381,36 +385,92 @@ fn otel_create_globals( let log_processor = BatchLogProcessor::builder(log_exporter, OtelSharedRuntime).build(); log_processor.set_resource(&resource); - op_state.put::<LogProcessor>(log_processor); + + OTEL_PROCESSORS + .set((span_processor, log_processor)) + .map_err(|_| anyhow!("failed to init otel"))?; Ok(()) } /// This function is called by the runtime whenever it is about to call -/// `os::process::exit()`, to ensure that all OpenTelemetry logs are properly +/// `process::exit()`, to ensure that all OpenTelemetry logs are properly /// flushed before the process terminates. -pub fn otel_drop_state(state: &mut OpState) { - if let Some(processor) = state.try_take::<SpanProcessor>() { - let _ = processor.force_flush(); - drop(processor); +pub fn flush() { + if let Some((span_processor, log_processor)) = OTEL_PROCESSORS.get() { + let _ = span_processor.force_flush(); + let _ = log_processor.force_flush(); } - if let Some(processor) = state.try_take::<LogProcessor>() { - let _ = processor.force_flush(); - drop(processor); +} + +pub fn handle_log(record: &log::Record) { + use log::Level; + + let Some((_, log_processor)) = OTEL_PROCESSORS.get() else { + return; + }; + + let mut log_record = LogRecord::default(); + + log_record.set_observed_timestamp(SystemTime::now()); + log_record.set_severity_number(match record.level() { + Level::Error => Severity::Error, + Level::Warn => Severity::Warn, + Level::Info => Severity::Info, + Level::Debug => Severity::Debug, + Level::Trace => Severity::Trace, + }); + log_record.set_severity_text(record.level().as_str()); + log_record.set_body(record.args().to_string().into()); + log_record.set_target(record.metadata().target().to_string()); + + struct Visitor<'s>(&'s mut LogRecord); + + impl<'s, 'kvs> log::kv::VisitSource<'kvs> for Visitor<'s> { + fn visit_pair( + &mut self, + key: log::kv::Key<'kvs>, + value: log::kv::Value<'kvs>, + ) -> Result<(), log::kv::Error> { + #[allow(clippy::manual_map)] + let value = if let Some(v) = value.to_bool() { + Some(AnyValue::Boolean(v)) + } else if let Some(v) = value.to_borrowed_str() { + Some(AnyValue::String(v.to_owned().into())) + } else if let Some(v) = value.to_f64() { + Some(AnyValue::Double(v)) + } else if let Some(v) = value.to_i64() { + Some(AnyValue::Int(v)) + } else { + None + }; + + if let Some(value) = value { + let key = Key::from(key.as_str().to_owned()); + self.0.add_attribute(key, value); + } + + Ok(()) + } } + + let _ = record.key_values().visit(&mut Visitor(&mut log_record)); + + log_processor.emit( + &mut log_record, + &InstrumentationScope::builder("deno").build(), + ); } #[op2(fast)] fn op_otel_log( - state: &mut OpState, #[string] message: String, #[smi] level: i32, #[string] trace_id: &str, #[string] span_id: &str, #[smi] trace_flags: u8, ) { - let Some(logger) = state.try_borrow::<LogProcessor>() else { - log::error!("op_otel_log: OpenTelemetry Logger not available"); + let Some((_, log_processor)) = OTEL_PROCESSORS.get() else { return; }; @@ -425,23 +485,21 @@ fn op_otel_log( let mut log_record = LogRecord::default(); - log_record.observed_timestamp = Some(SystemTime::now()); - log_record.body = Some(message.into()); - log_record.severity_number = Some(severity); - log_record.severity_text = Some(severity.name()); + log_record.set_observed_timestamp(SystemTime::now()); + log_record.set_body(message.into()); + log_record.set_severity_number(severity); + log_record.set_severity_text(severity.name()); if let (Ok(trace_id), Ok(span_id)) = (TraceId::from_hex(trace_id), SpanId::from_hex(span_id)) { - let span_context = SpanContext::new( + log_record.set_trace_context( trace_id, span_id, - TraceFlags::new(trace_flags), - false, - Default::default(), + Some(TraceFlags::new(trace_flags)), ); - log_record.trace_context = Some((&span_context).into()); } - logger.emit( + + log_processor.emit( &mut log_record, &InstrumentationScope::builder("deno").build(), ); @@ -463,7 +521,7 @@ fn op_otel_span_start<'s>( end_time: f64, ) -> Result<(), anyhow::Error> { if let Some(temporary_span) = state.try_take::<TemporarySpan>() { - let Some(span_processor) = state.try_borrow::<SpanProcessor>() else { + let Some((span_processor, _)) = OTEL_PROCESSORS.get() else { return Ok(()); }; span_processor.on_end(temporary_span.0); @@ -678,7 +736,7 @@ fn op_otel_span_flush(state: &mut OpState) { return; }; - let Some(span_processor) = state.try_borrow::<SpanProcessor>() else { + let Some((span_processor, _)) = OTEL_PROCESSORS.get() else { return; }; diff --git a/runtime/snapshot.rs b/runtime/snapshot.rs index bb9bf9166..7f6e6b8ab 100644 --- a/runtime/snapshot.rs +++ b/runtime/snapshot.rs @@ -312,7 +312,7 @@ pub fn create_runtime_snapshot( ), ops::fs_events::deno_fs_events::init_ops(), ops::os::deno_os::init_ops(Default::default()), - ops::otel::deno_otel::init_ops(None), + ops::otel::deno_otel::init_ops(), ops::permissions::deno_permissions::init_ops(), ops::process::deno_process::init_ops(None), ops::signal::deno_signal::init_ops(), diff --git a/runtime/web_worker.rs b/runtime/web_worker.rs index e27229153..b056e01fc 100644 --- a/runtime/web_worker.rs +++ b/runtime/web_worker.rs @@ -512,9 +512,7 @@ impl WebWorker { ), ops::fs_events::deno_fs_events::init_ops_and_esm(), ops::os::deno_os_worker::init_ops_and_esm(), - ops::otel::deno_otel::init_ops_and_esm( - options.bootstrap.otel_config.clone(), - ), + ops::otel::deno_otel::init_ops_and_esm(), ops::permissions::deno_permissions::init_ops_and_esm(), ops::process::deno_process::init_ops_and_esm( services.npm_process_state_provider, @@ -831,13 +829,12 @@ impl WebWorker { // TODO(mmastrac): we don't want to test this w/classic workers because // WPT triggers a failure here. This is only exposed via --enable-testing-features-do-not-use. - #[allow(clippy::print_stderr)] if self.worker_type == WebWorkerType::Module { panic!( "coding error: either js is polling or the worker is terminated" ); } else { - eprintln!("classic worker terminated unexpectedly"); + log::error!("classic worker terminated unexpectedly"); Poll::Ready(Ok(())) } } @@ -905,7 +902,6 @@ impl WebWorker { } } -#[allow(clippy::print_stderr)] fn print_worker_error( error: &AnyError, name: &str, @@ -918,7 +914,7 @@ fn print_worker_error( }, None => error.to_string(), }; - eprintln!( + log::error!( "{}: Uncaught (in worker \"{}\") {}", colors::red_bold("error"), name, diff --git a/runtime/worker.rs b/runtime/worker.rs index 82df755fa..c7bfb1c5f 100644 --- a/runtime/worker.rs +++ b/runtime/worker.rs @@ -422,9 +422,7 @@ impl MainWorker { ), ops::fs_events::deno_fs_events::init_ops_and_esm(), ops::os::deno_os::init_ops_and_esm(exit_code.clone()), - ops::otel::deno_otel::init_ops_and_esm( - options.bootstrap.otel_config.clone(), - ), + ops::otel::deno_otel::init_ops_and_esm(), ops::permissions::deno_permissions::init_ops_and_esm(), ops::process::deno_process::init_ops_and_esm( services.npm_process_state_provider, diff --git a/runtime/worker_bootstrap.rs b/runtime/worker_bootstrap.rs index dc989a1c0..3f5c245a0 100644 --- a/runtime/worker_bootstrap.rs +++ b/runtime/worker_bootstrap.rs @@ -226,7 +226,7 @@ impl BootstrapOptions { serve_is_main, serve_worker_count, if let Some(otel_config) = self.otel_config.as_ref() { - Box::new([otel_config.console as u8]) + Box::new([otel_config.console as u8, otel_config.deterministic as u8]) } else { Box::new([]) }, |