From 3687140b2db2922a6a26155f9056e1f334f64165 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 10:46:28 -0400 Subject: [PATCH 1/7] feat: initialize binding logging from environment Signed-off-by: Will Killian --- crates/core/src/logging/mod.rs | 16 ++++++ crates/ffi/nemo_relay.h | 9 ++++ crates/ffi/src/api/mod.rs | 16 ++++++ crates/node/src/api/mod.rs | 2 + crates/node/tests/logging_tests.mjs | 42 ++++++++++++++++ crates/python/src/lib.rs | 5 ++ docs/reference/operational-logging.mdx | 13 +++-- go/nemo_relay/logging_test.go | 67 ++++++++++++++++++++++++++ go/nemo_relay/nemo_relay.go | 7 +++ python/tests/test_logging.py | 43 +++++++++++++++++ 10 files changed, 215 insertions(+), 5 deletions(-) create mode 100644 crates/node/tests/logging_tests.mjs create mode 100644 go/nemo_relay/logging_test.go create mode 100644 python/tests/test_logging.py diff --git a/crates/core/src/logging/mod.rs b/crates/core/src/logging/mod.rs index 9b3c7528c..6afb6c39d 100644 --- a/crates/core/src/logging/mod.rs +++ b/crates/core/src/logging/mod.rs @@ -33,6 +33,7 @@ use sink::log_level_filter; pub(crate) use format::format_event_for_test; static LOGGER_LIFECYCLE_LOCK: Mutex<()> = Mutex::new(()); +static DEFAULT_LOGGING_RUNTIME: Mutex> = Mutex::new(None); fn lock_logger_lifecycle() -> MutexGuard<'static, ()> { LOGGER_LIFECYCLE_LOCK @@ -170,6 +171,21 @@ pub fn init_logging(config: &LoggingConfig) -> Result { LoggingRuntime::configure(config.clone()) } +/// Installs and retains the default process-wide logging runtime for a language binding. +/// +/// Configuration is resolved from the supported logging environment variables, with built-in +/// defaults when none are present. Repeated initialization in the same linked runtime is a no-op. +#[doc(hidden)] +pub fn initialize_default_logging() -> Result<()> { + let mut runtime = DEFAULT_LOGGING_RUNTIME.lock().map_err(|error| { + FlowError::Internal(format!("default logging runtime lock poisoned: {error}")) + })?; + if runtime.is_none() { + *runtime = Some(LoggingRuntime::configure_from_environment()?); + } + Ok(()) +} + #[cfg(test)] #[path = "../../tests/coverage/logging_tests.rs"] mod tests; diff --git a/crates/ffi/nemo_relay.h b/crates/ffi/nemo_relay.h index 9a17fe485..6aa9968ce 100644 --- a/crates/ffi/nemo_relay.h +++ b/crates/ffi/nemo_relay.h @@ -445,6 +445,15 @@ typedef char *(*NemoRelayToolExecInterceptCb)(void *user_data, */ typedef char *(*NemoRelayToolExecCb)(void *user_data, const char *args_json); +/** + * Initializes the Go binding runtime and installs default operational logging. + * + * Logging configuration is resolved from `NEMO_RELAY_LOG`, + * `NEMO_RELAY_LOG_STDERR_FORMAT`, or `NEMO_RELAY_LOG_CONFIG_PATH`, with built-in defaults when + * none are set. Repeated initialization is a no-op. + */ +NemoRelayStatus nemo_relay_initialize_default_logging(void); + /** * Run the registered tool request intercept chain on the given arguments. * diff --git a/crates/ffi/src/api/mod.rs b/crates/ffi/src/api/mod.rs index cd08d8d03..87c86eb31 100644 --- a/crates/ffi/src/api/mod.rs +++ b/crates/ffi/src/api/mod.rs @@ -99,6 +99,22 @@ fn tokio_runtime() -> &'static Runtime { }) } +/// Initializes the Go binding runtime and installs default operational logging. +/// +/// Logging configuration is resolved from `NEMO_RELAY_LOG`, +/// `NEMO_RELAY_LOG_STDERR_FORMAT`, or `NEMO_RELAY_LOG_CONFIG_PATH`, with built-in defaults when +/// none are set. Repeated initialization is a no-op. +#[unsafe(no_mangle)] +pub extern "C" fn nemo_relay_initialize_default_logging() -> NemoRelayStatus { + clear_last_error(); + let result = nemo_relay::shared_runtime::initialize_shared_runtime_binding("go") + .and_then(|()| nemo_relay::logging::initialize_default_logging()); + match result { + Ok(()) => NemoRelayStatus::Ok, + Err(error) => status_from_error(&error), + } +} + fn block_on_sync_ffi(future: F) -> FlowResult where T: Send, diff --git a/crates/node/src/api/mod.rs b/crates/node/src/api/mod.rs index 9daec5dad..89fada94e 100644 --- a/crates/node/src/api/mod.rs +++ b/crates/node/src/api/mod.rs @@ -119,6 +119,8 @@ fn effective_scope_top( fn init() { initialize_shared_runtime_binding("node") .expect("node runtime ownership initialization should succeed"); + nemo_relay::logging::initialize_default_logging() + .expect("node operational logging initialization should succeed"); register_adaptive_component() .expect("node adaptive plugin component registration should succeed"); register_pii_redaction_component() diff --git a/crates/node/tests/logging_tests.mjs b/crates/node/tests/logging_tests.mjs new file mode 100644 index 000000000..98973d4a9 --- /dev/null +++ b/crates/node/tests/logging_tests.mjs @@ -0,0 +1,42 @@ +// SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 + +import { describe, it } from 'node:test'; +import assert from 'node:assert/strict'; +import { spawnSync } from 'node:child_process'; +import { fileURLToPath } from 'node:url'; + +const packageDirectory = fileURLToPath(new URL('..', import.meta.url)); +const loggingEnvironmentNames = ['NEMO_RELAY_LOG', 'NEMO_RELAY_LOG_STDERR_FORMAT', 'NEMO_RELAY_LOG_CONFIG_PATH']; + +function requireBinding(loggingEnvironment) { + const environment = { ...process.env }; + for (const name of loggingEnvironmentNames) { + delete environment[name]; + } + Object.assign(environment, loggingEnvironment); + return spawnSync(process.execPath, ['-e', "require('./index.js')"], { + cwd: packageDirectory, + encoding: 'utf8', + env: environment, + }); +} + +describe('operational logging', () => { + it('initializes from the logging environment', () => { + const result = requireBinding({ + NEMO_RELAY_LOG: 'info', + NEMO_RELAY_LOG_STDERR_FORMAT: 'jsonl', + }); + + assert.equal(result.status, 0, result.stderr); + assert.match(result.stderr, /"event":"logging_initialized"/); + }); + + it('rejects an invalid logging environment', () => { + const result = requireBinding({ NEMO_RELAY_LOG: '' }); + + assert.notEqual(result.status, 0); + assert.match(result.stderr, /NEMO_RELAY_LOG must not be empty/); + }); +}); diff --git a/crates/python/src/lib.rs b/crates/python/src/lib.rs index 84ebb2295..a5f7ed04b 100644 --- a/crates/python/src/lib.rs +++ b/crates/python/src/lib.rs @@ -50,6 +50,11 @@ fn _native(m: &Bound<'_, PyModule>) -> PyResult<()> { "failed to initialize NeMo Relay runtime ownership: {e}" )) })?; + nemo_relay::logging::initialize_default_logging().map_err(|e| { + pyo3::exceptions::PyRuntimeError::new_err(format!( + "failed to initialize NeMo Relay operational logging: {e}" + )) + })?; register_adaptive_component().map_err(|e| { pyo3::exceptions::PyRuntimeError::new_err(format!( "failed to register adaptive plugin component: {e}" diff --git a/docs/reference/operational-logging.mdx b/docs/reference/operational-logging.mdx index 942a75149..0aa129409 100644 --- a/docs/reference/operational-logging.mdx +++ b/docs/reference/operational-logging.mdx @@ -29,7 +29,7 @@ Use the source that matches how Relay is launched: | Use Case | Configuration Source | | --- | --- | | Run the Relay CLI with temporary settings | `--log-*` options | -| Configure a process without a Relay config file | `NEMO_RELAY_LOG*` environment variables | +| Configure a language binding or CLI process | `NEMO_RELAY_LOG*` environment variables | | Reuse logging settings across runs | `[logging]` in TOML | | Embed Relay in a Rust application | `LoggingConfig` and `LoggingRuntime` | @@ -40,8 +40,10 @@ For CLI processes, Relay selects one source in this order: 3. `[logging]` in the resolved Relay `config.toml` 4. Built-in defaults -Sources are selected rather than merged. Rust applications explicitly choose -which `LoggingRuntime` initialization method to use and do not apply the CLI +Sources are selected rather than merged. Python, Node.js, and Go install a +process-lifetime `LoggingRuntime` when the binding loads, using environment +configuration or built-in defaults. Rust applications explicitly choose which +`LoggingRuntime` initialization method to use and do not apply the CLI precedence rules. ## CLI Options @@ -63,8 +65,9 @@ Do not combine `--log-config-path` with `--log-level` or ## Environment Variables -Set these variables for the CLI or a Rust application that initializes logging -with `LoggingRuntime::configure_from_environment()`: +Set these variables for a Python, Node.js, or Go process, the CLI, or a Rust +application that initializes logging with +`LoggingRuntime::configure_from_environment()`: ```bash export NEMO_RELAY_LOG=debug diff --git a/go/nemo_relay/logging_test.go b/go/nemo_relay/logging_test.go new file mode 100644 index 000000000..7b408dbcf --- /dev/null +++ b/go/nemo_relay/logging_test.go @@ -0,0 +1,67 @@ +// SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 + +package nemo_relay + +import ( + "os" + "os/exec" + "strings" + "testing" +) + +const loggingHelperEnvironment = "NEMO_RELAY_TEST_LOGGING_HELPER" + +var loggingEnvironmentNames = map[string]struct{}{ + "NEMO_RELAY_LOG": {}, + "NEMO_RELAY_LOG_STDERR_FORMAT": {}, + "NEMO_RELAY_LOG_CONFIG_PATH": {}, +} + +func loggingTestEnvironment(values ...string) []string { + environment := make([]string, 0, len(os.Environ())+len(values)) + for _, value := range os.Environ() { + name, _, _ := strings.Cut(value, "=") + if _, isLoggingEnvironment := loggingEnvironmentNames[name]; !isLoggingEnvironment { + environment = append(environment, value) + } + } + return append(environment, values...) +} + +func TestBindingLoggingEnvironment(t *testing.T) { + if os.Getenv(loggingHelperEnvironment) == "1" { + return + } + + t.Run("initializes from environment", func(t *testing.T) { + command := exec.Command(os.Args[0], "-test.run=TestBindingLoggingEnvironment") + command.Env = loggingTestEnvironment( + loggingHelperEnvironment+"=1", + "NEMO_RELAY_LOG=info", + "NEMO_RELAY_LOG_STDERR_FORMAT=jsonl", + ) + output, err := command.CombinedOutput() + if err != nil { + t.Fatalf("binding import failed: %v\n%s", err, output) + } + if !strings.Contains(string(output), `"event":"logging_initialized"`) { + t.Fatalf("logging initialization event missing from output:\n%s", output) + } + }) + + t.Run("rejects invalid environment", func(t *testing.T) { + command := exec.Command(os.Args[0], "-test.run=TestBindingLoggingEnvironment") + command.Env = loggingTestEnvironment( + loggingHelperEnvironment+"=1", + "NEMO_RELAY_LOG=", + ) + output, err := command.CombinedOutput() + if err == nil { + t.Fatalf("binding initialization unexpectedly succeeded:\n%s", output) + } + if !strings.Contains(string(output), "NEMO_RELAY_LOG must not be empty") { + t.Fatalf("logging initialization error missing from output:\n%s", output) + } + }) +} diff --git a/go/nemo_relay/nemo_relay.go b/go/nemo_relay/nemo_relay.go index 3046120f5..50313f84e 100644 --- a/go/nemo_relay/nemo_relay.go +++ b/go/nemo_relay/nemo_relay.go @@ -46,6 +46,7 @@ typedef struct NemoRelayLlmSanitizeResponseContext { uint32_t codec_kind; const typedef void (*NemoRelayFreeFn)(void* user_data); // Core API +extern int32_t nemo_relay_initialize_default_logging(void); extern int32_t nemo_relay_get_handle(FfiScopeHandle** out); extern int32_t nemo_relay_push_scope(const char* name, int32_t scope_type, const FfiScopeHandle* parent, uint32_t attributes, const char* data_json, const char* metadata_json, const char* input_json, const int64_t* timestamp_unix_micros, FfiScopeHandle** out); extern int32_t nemo_relay_pop_scope(const FfiScopeHandle* handle, const char* output_json, const char* metadata_json, const int64_t* timestamp_unix_micros); @@ -298,6 +299,12 @@ import ( const defaultServiceName = "nemo-relay" +func init() { + if err := checkStatus(C.nemo_relay_initialize_default_logging()); err != nil { + panic(fmt.Sprintf("failed to initialize NeMo Relay operational logging: %v", err)) + } +} + func checkedValue[T any](status int32, value T) (T, error) { if err := checkStatus(C.int32_t(status)); err != nil { var zero T diff --git a/python/tests/test_logging.py b/python/tests/test_logging.py new file mode 100644 index 000000000..7035983e8 --- /dev/null +++ b/python/tests/test_logging.py @@ -0,0 +1,43 @@ +# SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. +# SPDX-License-Identifier: Apache-2.0 + +import os +import subprocess +import sys + +_LOG_ENVIRONMENT = ( + "NEMO_RELAY_LOG", + "NEMO_RELAY_LOG_STDERR_FORMAT", + "NEMO_RELAY_LOG_CONFIG_PATH", +) + + +def _import_nemo_relay(**logging_environment: str) -> subprocess.CompletedProcess[str]: + environment = os.environ.copy() + for name in _LOG_ENVIRONMENT: + environment.pop(name, None) + environment.update(logging_environment) + return subprocess.run( + [sys.executable, "-c", "import nemo_relay"], + check=False, + capture_output=True, + text=True, + env=environment, + ) + + +def test_binding_initializes_logging_from_environment(): + completed = _import_nemo_relay( + NEMO_RELAY_LOG="info", + NEMO_RELAY_LOG_STDERR_FORMAT="jsonl", + ) + + assert completed.returncode == 0, completed.stderr + assert '"event":"logging_initialized"' in completed.stderr + + +def test_binding_rejects_invalid_logging_environment(): + completed = _import_nemo_relay(NEMO_RELAY_LOG="") + + assert completed.returncode != 0 + assert "NEMO_RELAY_LOG must not be empty" in completed.stderr From a6c4c078267586d052eea507e635f6172ac8a8f7 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 12:40:06 -0400 Subject: [PATCH 2/7] fix: drain binding logging during shutdown Signed-off-by: Will Killian --- crates/core/src/logging/mod.rs | 18 +++++ crates/core/tests/coverage/logging_tests.rs | 60 ++++++++++++++- crates/ffi/nemo_relay.h | 8 ++ crates/ffi/src/api/mod.rs | 13 ++++ crates/ffi/tests/unit/api_tests.rs | 13 ++++ crates/node/src/api/mod.rs | 17 ++++- crates/node/tests/logging_tests.mjs | 83 ++++++++++++++++++++- crates/python/src/py_api/mod.rs | 8 ++ docs/reference/operational-logging.mdx | 5 ++ go/nemo_relay/README.md | 6 ++ go/nemo_relay/logging_test.go | 48 +++++++++++- go/nemo_relay/nemo_relay.go | 7 ++ python/nemo_relay/__init__.py | 4 + python/nemo_relay/_native.pyi | 2 + python/tests/test_logging.py | 24 ++++++ 15 files changed, 309 insertions(+), 7 deletions(-) diff --git a/crates/core/src/logging/mod.rs b/crates/core/src/logging/mod.rs index 6afb6c39d..53d9dbfd2 100644 --- a/crates/core/src/logging/mod.rs +++ b/crates/core/src/logging/mod.rs @@ -186,6 +186,24 @@ pub fn initialize_default_logging() -> Result<()> { Ok(()) } +/// Shuts down and releases the default process-wide logging runtime for a language binding. +/// +/// Repeated shutdown in the same linked runtime is a no-op. The runtime is removed from shared +/// state before its sinks are drained so shutdown does not hold the default-runtime lock. +#[doc(hidden)] +pub fn shutdown_default_logging() -> Result<()> { + let runtime = DEFAULT_LOGGING_RUNTIME + .lock() + .map_err(|error| { + FlowError::Internal(format!("default logging runtime lock poisoned: {error}")) + })? + .take(); + if let Some(runtime) = runtime { + runtime.shutdown(); + } + Ok(()) +} + #[cfg(test)] #[path = "../../tests/coverage/logging_tests.rs"] mod tests; diff --git a/crates/core/tests/coverage/logging_tests.rs b/crates/core/tests/coverage/logging_tests.rs index 430c4f3b6..dbaf27f39 100644 --- a/crates/core/tests/coverage/logging_tests.rs +++ b/crates/core/tests/coverage/logging_tests.rs @@ -4,7 +4,7 @@ use crate::logging::{ FileLogRotationConfig, FileLogSinkConfig, LogFormat, LogLevel, LogSinkConfig, LoggingConfig, LoggingRuntime, MAX_FILE_SINK_QUEUE_ENTRIES, MAX_FILE_SINK_RETAINED_FILES, build_logger, - format_event_for_test, init_logging, + format_event_for_test, init_logging, initialize_default_logging, shutdown_default_logging, }; use opentelemetry::trace::{Span as _, Tracer as _, TracerProvider as _}; use opentelemetry_sdk::error::OTelSdkResult; @@ -192,6 +192,64 @@ queue_capacity = 16 assert_eq!(record["fields"]["source"], "toml"); } +#[test] +fn default_logging_runtime_initializes_once_and_shuts_down_idempotently() { + let temp = tempfile::tempdir().unwrap(); + let config_path = temp.path().join("logging.toml"); + let log_path = temp.path().join("relay.log.jsonl"); + std::fs::write( + &config_path, + format!( + r#" +[logging] +level = "info" +stderr_format = "human" +flush_interval_millis = 0 + +[[logging.sinks]] +path = {} +level = "info" +format = "jsonl" +queue_capacity = 16 +"#, + toml_basic_string(log_path.to_string_lossy().as_ref()) + ), + ) + .unwrap(); + let _environment = LoggingEnvScope::set(&[ + ("NEMO_RELAY_LOG", None), + ("NEMO_RELAY_LOG_STDERR_FORMAT", None), + ("NEMO_RELAY_LOG_CONFIG_PATH", Some(config_path.as_os_str())), + ]); + + shutdown_default_logging().unwrap(); + initialize_default_logging().unwrap(); + initialize_default_logging().unwrap(); + shutdown_default_logging().unwrap(); + shutdown_default_logging().unwrap(); + + let records = std::fs::read_to_string(log_path).unwrap(); + assert!(records.contains("logging_initialized")); + assert!(records.contains("logging_shutdown_started")); +} + +#[test] +fn default_logging_runtime_rejects_invalid_environment() { + let _environment = LoggingEnvScope::set(&[ + ("NEMO_RELAY_LOG", Some(OsStr::new(""))), + ("NEMO_RELAY_LOG_STDERR_FORMAT", None), + ("NEMO_RELAY_LOG_CONFIG_PATH", None), + ]); + + shutdown_default_logging().unwrap(); + let error = initialize_default_logging().unwrap_err().to_string(); + + assert!( + error.contains("NEMO_RELAY_LOG must not be empty"), + "{error}" + ); +} + #[test] fn logging_config_from_environment_resolves_direct_settings() { let _environment = LoggingEnvScope::set(&[ diff --git a/crates/ffi/nemo_relay.h b/crates/ffi/nemo_relay.h index 6aa9968ce..112286a8b 100644 --- a/crates/ffi/nemo_relay.h +++ b/crates/ffi/nemo_relay.h @@ -454,6 +454,14 @@ typedef char *(*NemoRelayToolExecCb)(void *user_data, const char *args_json); */ NemoRelayStatus nemo_relay_initialize_default_logging(void); +/** + * Shuts down and releases the default operational logging runtime. + * + * Pending file-sink records are drained before this function returns. Repeated shutdown is a + * no-op. + */ +NemoRelayStatus nemo_relay_shutdown_default_logging(void); + /** * Run the registered tool request intercept chain on the given arguments. * diff --git a/crates/ffi/src/api/mod.rs b/crates/ffi/src/api/mod.rs index 87c86eb31..848ad7243 100644 --- a/crates/ffi/src/api/mod.rs +++ b/crates/ffi/src/api/mod.rs @@ -115,6 +115,19 @@ pub extern "C" fn nemo_relay_initialize_default_logging() -> NemoRelayStatus { } } +/// Shuts down and releases the default operational logging runtime. +/// +/// Pending file-sink records are drained before this function returns. Repeated shutdown is a +/// no-op. +#[unsafe(no_mangle)] +pub extern "C" fn nemo_relay_shutdown_default_logging() -> NemoRelayStatus { + clear_last_error(); + match nemo_relay::logging::shutdown_default_logging() { + Ok(()) => NemoRelayStatus::Ok, + Err(error) => status_from_error(&error), + } +} + fn block_on_sync_ffi(future: F) -> FlowResult where T: Send, diff --git a/crates/ffi/tests/unit/api_tests.rs b/crates/ffi/tests/unit/api_tests.rs index 6f9eac085..e99c1b5ca 100644 --- a/crates/ffi/tests/unit/api_tests.rs +++ b/crates/ffi/tests/unit/api_tests.rs @@ -243,6 +243,19 @@ unsafe fn fresh_scope_stack() -> *mut FfiScopeStack { stack } +#[test] +fn default_logging_shutdown_is_idempotent() { + let _guard = lock_unpoisoned(&TEST_MUTEX); + assert_status!( + api::nemo_relay_shutdown_default_logging(), + NemoRelayStatus::Ok + ); + assert_status!( + api::nemo_relay_shutdown_default_logging(), + NemoRelayStatus::Ok + ); +} + #[test] fn propagation_context_json_round_trips_through_the_ffi() { let _guard = lock_unpoisoned(&TEST_MUTEX); diff --git a/crates/node/src/api/mod.rs b/crates/node/src/api/mod.rs index 89fada94e..dddfe684b 100644 --- a/crates/node/src/api/mod.rs +++ b/crates/node/src/api/mod.rs @@ -16,7 +16,7 @@ use std::pin::Pin; use std::ptr; use std::sync::Arc; use std::sync::Mutex as StdMutex; -use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; +use std::sync::atomic::{AtomicBool, AtomicU64, AtomicUsize, Ordering}; use std::task::{Context, Poll}; use chrono::{DateTime, Utc}; @@ -88,6 +88,8 @@ use crate::promise_call::with_publication_callback_context; use crate::stream::LlmStream; use crate::types::{LlmHandle, ScopeHandle, ScopeStack, ScopeType, ToolHandle}; +static NODE_ENVIRONMENT_COUNT: AtomicUsize = AtomicUsize::new(0); + fn effective_scope_context( env: &Env, ) -> napi::Result<( @@ -129,7 +131,18 @@ fn init() { #[cfg(not(test))] #[napi_derive::module_exports] -fn install_well_known_symbol_methods(exports: JsObject, env: Env) -> napi::Result<()> { +fn install_well_known_symbol_methods(exports: JsObject, mut env: Env) -> napi::Result<()> { + NODE_ENVIRONMENT_COUNT.fetch_add(1, Ordering::AcqRel); + if let Err(error) = env.add_env_cleanup_hook((), |_| { + if NODE_ENVIRONMENT_COUNT.fetch_sub(1, Ordering::AcqRel) == 1 + && let Err(error) = nemo_relay::logging::shutdown_default_logging() + { + eprintln!("nemo-relay: operational logging shutdown failed: {error}"); + } + }) { + NODE_ENVIRONMENT_COUNT.fetch_sub(1, Ordering::AcqRel); + return Err(error); + } let activation: JsFunction = exports.get_named_property("DynamicPluginActivation")?; let activation = activation.coerce_to_object()?; let mut prototype: JsObject = activation.get_named_property("prototype")?; diff --git a/crates/node/tests/logging_tests.mjs b/crates/node/tests/logging_tests.mjs index 98973d4a9..2e4c8170b 100644 --- a/crates/node/tests/logging_tests.mjs +++ b/crates/node/tests/logging_tests.mjs @@ -4,18 +4,21 @@ import { describe, it } from 'node:test'; import assert from 'node:assert/strict'; import { spawnSync } from 'node:child_process'; +import { mkdtempSync, readFileSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; import { fileURLToPath } from 'node:url'; const packageDirectory = fileURLToPath(new URL('..', import.meta.url)); const loggingEnvironmentNames = ['NEMO_RELAY_LOG', 'NEMO_RELAY_LOG_STDERR_FORMAT', 'NEMO_RELAY_LOG_CONFIG_PATH']; -function requireBinding(loggingEnvironment) { +function requireBinding(loggingEnvironment, source = "require('./index.js')") { const environment = { ...process.env }; for (const name of loggingEnvironmentNames) { delete environment[name]; } Object.assign(environment, loggingEnvironment); - return spawnSync(process.execPath, ['-e', "require('./index.js')"], { + return spawnSync(process.execPath, ['-e', source], { cwd: packageDirectory, encoding: 'utf8', env: environment, @@ -39,4 +42,80 @@ describe('operational logging', () => { assert.notEqual(result.status, 0); assert.match(result.stderr, /NEMO_RELAY_LOG must not be empty/); }); + + it('flushes file sinks during environment cleanup', () => { + const directory = mkdtempSync(join(tmpdir(), 'nemo-relay-node-logging-')); + try { + const configPath = join(directory, 'logging.toml'); + const logPath = join(directory, 'operational.jsonl'); + writeFileSync( + configPath, + `[logging] +level = "info" +stderr_format = "human" +flush_interval_millis = 0 + +[[logging.sinks]] +path = ${JSON.stringify(logPath)} +level = "info" +format = "jsonl" +queue_capacity = 16 +`, + ); + + const result = requireBinding({ NEMO_RELAY_LOG_CONFIG_PATH: configPath }); + + assert.equal(result.status, 0, result.stderr); + assert.match(readFileSync(logPath, 'utf8'), /"event":"logging_shutdown_started"/); + } finally { + rmSync(directory, { recursive: true, force: true }); + } + }); + + it('keeps logging active while another Node environment remains', () => { + const directory = mkdtempSync(join(tmpdir(), 'nemo-relay-node-worker-logging-')); + try { + const configPath = join(directory, 'logging.toml'); + const logPath = join(directory, 'operational.jsonl'); + writeFileSync( + configPath, + `[logging] +level = "info" +stderr_format = "human" +flush_interval_millis = 0 + +[[logging.sinks]] +path = ${JSON.stringify(logPath)} +level = "info" +format = "jsonl" +queue_capacity = 16 +`, + ); + const workerSource = `require(${JSON.stringify(join(packageDirectory, 'index.js'))})`; + const source = ` +const { Worker } = require('node:worker_threads'); +const relay = require('./index.js'); +const worker = new Worker(${JSON.stringify(workerSource)}, { + eval: true, +}); +worker.once('error', (error) => { + console.error(error); + process.exitCode = 1; +}); +worker.once('exit', (code) => { + if (code !== 0) process.exitCode = code; + relay.deregisterPlugin('adaptive'); +}); +`; + + const result = requireBinding({ NEMO_RELAY_LOG_CONFIG_PATH: configPath }, source); + + assert.equal(result.status, 0, result.stderr); + const output = readFileSync(logPath, 'utf8'); + assert.match(output, /"event":"plugin_deregistered"/); + assert.match(output, /"event":"logging_shutdown_started"/); + } finally { + rmSync(directory, { recursive: true, force: true }); + } + }); }); diff --git a/crates/python/src/py_api/mod.rs b/crates/python/src/py_api/mod.rs index d09933a0f..54f801702 100644 --- a/crates/python/src/py_api/mod.rs +++ b/crates/python/src/py_api/mod.rs @@ -62,6 +62,12 @@ fn to_py_err(e: FlowError) -> PyErr { PyErr::new::(e.to_string()) } +#[pyfunction(name = "_shutdown_default_logging")] +fn py_shutdown_default_logging(py: Python<'_>) -> PyResult<()> { + py.detach(nemo_relay::logging::shutdown_default_logging) + .map_err(to_py_err) +} + fn python_event_loop_running(py: Python<'_>) -> PyResult { match py.import("asyncio")?.call_method0("get_running_loop") { Ok(_) => Ok(true), @@ -2083,6 +2089,8 @@ fn scope_deregister_subscriber(scope_uuid: &str, name: &str) -> PyResult { /// Register all API functions into the given `PyModule`. pub fn register(m: &Bound<'_, PyModule>) -> PyResult<()> { + m.add_function(wrap_pyfunction!(py_shutdown_default_logging, m)?)?; + // Scope stack creation / binding / query m.add_function(wrap_pyfunction!(create_scope_stack, m)?)?; m.add_function(wrap_pyfunction!(capture_propagation_context, m)?)?; diff --git a/docs/reference/operational-logging.mdx b/docs/reference/operational-logging.mdx index 0aa129409..626337e85 100644 --- a/docs/reference/operational-logging.mdx +++ b/docs/reference/operational-logging.mdx @@ -88,6 +88,11 @@ export NEMO_RELAY_LOG_CONFIG_PATH=/absolute/path/to/logging.toml `NEMO_RELAY_LOG_CONFIG_PATH` cannot be combined with the other logging environment variables. +Python and Node.js drain pending file-sink records during normal runtime +teardown. Go applications that configure file sinks must call +`nemo_relay.ShutdownLogging` before `main` returns; defer it near the start of +`main` so it runs after other Relay cleanup. + ## TOML Configuration Logging settings use a `[logging]` table: diff --git a/go/nemo_relay/README.md b/go/nemo_relay/README.md index 57bbca94c..5162c1bf9 100644 --- a/go/nemo_relay/README.md +++ b/go/nemo_relay/README.md @@ -110,6 +110,12 @@ import ( ) func main() { + defer func() { + if err := nemo.ShutdownLogging(); err != nil { + log.Printf("shut down NeMo Relay logging: %v", err) + } + }() + if err := nemo.RegisterSubscriber("printer", func(event nemo.Event) { fmt.Printf("%s %s\n", event.Kind(), event.Name()) fmt.Println(string(event.JSON())) diff --git a/go/nemo_relay/logging_test.go b/go/nemo_relay/logging_test.go index 7b408dbcf..09af8e799 100644 --- a/go/nemo_relay/logging_test.go +++ b/go/nemo_relay/logging_test.go @@ -6,6 +6,8 @@ package nemo_relay import ( "os" "os/exec" + "path/filepath" + "strconv" "strings" "testing" ) @@ -30,14 +32,19 @@ func loggingTestEnvironment(values ...string) []string { } func TestBindingLoggingEnvironment(t *testing.T) { - if os.Getenv(loggingHelperEnvironment) == "1" { + if helper := os.Getenv(loggingHelperEnvironment); helper != "" { + if helper == "shutdown" { + if err := ShutdownLogging(); err != nil { + t.Fatalf("logging shutdown failed: %v", err) + } + } return } t.Run("initializes from environment", func(t *testing.T) { command := exec.Command(os.Args[0], "-test.run=TestBindingLoggingEnvironment") command.Env = loggingTestEnvironment( - loggingHelperEnvironment+"=1", + loggingHelperEnvironment+"=shutdown", "NEMO_RELAY_LOG=info", "NEMO_RELAY_LOG_STDERR_FORMAT=jsonl", ) @@ -64,4 +71,41 @@ func TestBindingLoggingEnvironment(t *testing.T) { t.Fatalf("logging initialization error missing from output:\n%s", output) } }) + + t.Run("flushes file sink during shutdown", func(t *testing.T) { + directory := t.TempDir() + configPath := filepath.Join(directory, "logging.toml") + logPath := filepath.Join(directory, "operational.jsonl") + config := `[logging] +level = "info" +stderr_format = "human" +flush_interval_millis = 0 + +[[logging.sinks]] +path = ` + strconv.Quote(logPath) + ` +level = "info" +format = "jsonl" +queue_capacity = 16 +` + if err := os.WriteFile(configPath, []byte(config), 0o600); err != nil { + t.Fatalf("write logging config: %v", err) + } + + command := exec.Command(os.Args[0], "-test.run=TestBindingLoggingEnvironment") + command.Env = loggingTestEnvironment( + loggingHelperEnvironment+"=shutdown", + "NEMO_RELAY_LOG_CONFIG_PATH="+configPath, + ) + output, err := command.CombinedOutput() + if err != nil { + t.Fatalf("binding logging shutdown failed: %v\n%s", err, output) + } + contents, err := os.ReadFile(logPath) + if err != nil { + t.Fatalf("read operational log: %v", err) + } + if !strings.Contains(string(contents), `"event":"logging_shutdown_started"`) { + t.Fatalf("logging shutdown event missing from file:\n%s", contents) + } + }) } diff --git a/go/nemo_relay/nemo_relay.go b/go/nemo_relay/nemo_relay.go index 50313f84e..8646c122a 100644 --- a/go/nemo_relay/nemo_relay.go +++ b/go/nemo_relay/nemo_relay.go @@ -47,6 +47,7 @@ typedef void (*NemoRelayFreeFn)(void* user_data); // Core API extern int32_t nemo_relay_initialize_default_logging(void); +extern int32_t nemo_relay_shutdown_default_logging(void); extern int32_t nemo_relay_get_handle(FfiScopeHandle** out); extern int32_t nemo_relay_push_scope(const char* name, int32_t scope_type, const FfiScopeHandle* parent, uint32_t attributes, const char* data_json, const char* metadata_json, const char* input_json, const int64_t* timestamp_unix_micros, FfiScopeHandle** out); extern int32_t nemo_relay_pop_scope(const FfiScopeHandle* handle, const char* output_json, const char* metadata_json, const int64_t* timestamp_unix_micros); @@ -305,6 +306,12 @@ func init() { } } +// ShutdownLogging drains pending operational log records and releases the default logging runtime. +// Callers that configure file sinks should defer ShutdownLogging from main. +func ShutdownLogging() error { + return checkStatus(C.nemo_relay_shutdown_default_logging()) +} + func checkedValue[T any](status int32, value T) (T, error) { if err := checkStatus(C.int32_t(status)); err != nil { var zero T diff --git a/python/nemo_relay/__init__.py b/python/nemo_relay/__init__.py index 585fbe683..1fa187220 100644 --- a/python/nemo_relay/__init__.py +++ b/python/nemo_relay/__init__.py @@ -77,6 +77,7 @@ async def main(): from __future__ import annotations +import atexit import contextvars import typing from collections.abc import Callable as AbcCallable @@ -119,6 +120,7 @@ async def main(): ToolAttributes, ToolExecutionInterceptOutcome, ToolHandle, + _shutdown_default_logging, ) from nemo_relay._native import ( capture_propagation_context as _capture_propagation_context, @@ -136,6 +138,8 @@ async def main(): from nemo_relay._native import set_thread_scope_stack as _set_thread_scope_stack from nemo_relay._native import sync_thread_scope_stack as _sync_thread_scope_stack +atexit.register(_shutdown_default_logging) + #: Scalar JSON leaf values accepted in NeMo Relay payloads. This alias has no #: runtime behavior; it exists to document and type JSON-compatible public API #: arguments and return values. diff --git a/python/nemo_relay/_native.pyi b/python/nemo_relay/_native.pyi index 43f2fa5f1..cc025751c 100644 --- a/python/nemo_relay/_native.pyi +++ b/python/nemo_relay/_native.pyi @@ -32,6 +32,8 @@ _JsonObject: TypeAlias = dict[str, _JsonValue] _Json: TypeAlias = _JsonValue _MessageContent: TypeAlias = str | Sequence[Mapping[str, _JsonValue]] +def _shutdown_default_logging() -> None: ... + class _EventSanitizeFields(TypedDict): data: _Json | None category_profile: _JsonObject | None diff --git a/python/tests/test_logging.py b/python/tests/test_logging.py index 7035983e8..9312a7ac9 100644 --- a/python/tests/test_logging.py +++ b/python/tests/test_logging.py @@ -1,6 +1,7 @@ # SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. # SPDX-License-Identifier: Apache-2.0 +import json import os import subprocess import sys @@ -41,3 +42,26 @@ def test_binding_rejects_invalid_logging_environment(): assert completed.returncode != 0 assert "NEMO_RELAY_LOG must not be empty" in completed.stderr + + +def test_binding_flushes_file_sink_during_shutdown(tmp_path): + config_path = tmp_path / "logging.toml" + log_path = tmp_path / "operational.jsonl" + config_path.write_text( + f"""[logging] +level = "info" +stderr_format = "human" +flush_interval_millis = 0 + +[[logging.sinks]] +path = {json.dumps(str(log_path))} +level = "info" +format = "jsonl" +queue_capacity = 16 +""" + ) + + completed = _import_nemo_relay(NEMO_RELAY_LOG_CONFIG_PATH=str(config_path)) + + assert completed.returncode == 0, completed.stderr + assert '"event":"logging_shutdown_started"' in log_path.read_text() From 5bde739ed3ca76d415d6a62bb89e73bacfe51ab6 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 13:12:54 -0400 Subject: [PATCH 3/7] fix: synchronize Node logging lifecycle Signed-off-by: Will Killian --- crates/core/tests/coverage/logging_tests.rs | 12 +++++-- crates/node/src/api/mod.rs | 35 ++++++++++++++------- 2 files changed, 34 insertions(+), 13 deletions(-) diff --git a/crates/core/tests/coverage/logging_tests.rs b/crates/core/tests/coverage/logging_tests.rs index dbaf27f39..d5f74a7e3 100644 --- a/crates/core/tests/coverage/logging_tests.rs +++ b/crates/core/tests/coverage/logging_tests.rs @@ -229,8 +229,16 @@ queue_capacity = 16 shutdown_default_logging().unwrap(); let records = std::fs::read_to_string(log_path).unwrap(); - assert!(records.contains("logging_initialized")); - assert!(records.contains("logging_shutdown_started")); + assert_eq!( + records.matches(r#""event":"logging_initialized""#).count(), + 1 + ); + assert_eq!( + records + .matches(r#""event":"logging_shutdown_started""#) + .count(), + 1 + ); } #[test] diff --git a/crates/node/src/api/mod.rs b/crates/node/src/api/mod.rs index dddfe684b..c81958ef8 100644 --- a/crates/node/src/api/mod.rs +++ b/crates/node/src/api/mod.rs @@ -89,6 +89,27 @@ use crate::stream::LlmStream; use crate::types::{LlmHandle, ScopeHandle, ScopeStack, ScopeType, ToolHandle}; static NODE_ENVIRONMENT_COUNT: AtomicUsize = AtomicUsize::new(0); +static NODE_ENVIRONMENT_LIFECYCLE_LOCK: StdMutex<()> = StdMutex::new(()); + +fn register_node_environment() -> FlowResult<()> { + let _guard = NODE_ENVIRONMENT_LIFECYCLE_LOCK + .lock() + .unwrap_or_else(|poisoned| poisoned.into_inner()); + nemo_relay::logging::initialize_default_logging()?; + NODE_ENVIRONMENT_COUNT.fetch_add(1, Ordering::AcqRel); + Ok(()) +} + +fn cleanup_node_environment() { + let _guard = NODE_ENVIRONMENT_LIFECYCLE_LOCK + .lock() + .unwrap_or_else(|poisoned| poisoned.into_inner()); + if NODE_ENVIRONMENT_COUNT.fetch_sub(1, Ordering::AcqRel) == 1 + && let Err(error) = nemo_relay::logging::shutdown_default_logging() + { + eprintln!("nemo-relay: operational logging shutdown failed: {error}"); + } +} fn effective_scope_context( env: &Env, @@ -121,8 +142,6 @@ fn effective_scope_top( fn init() { initialize_shared_runtime_binding("node") .expect("node runtime ownership initialization should succeed"); - nemo_relay::logging::initialize_default_logging() - .expect("node operational logging initialization should succeed"); register_adaptive_component() .expect("node adaptive plugin component registration should succeed"); register_pii_redaction_component() @@ -132,15 +151,9 @@ fn init() { #[cfg(not(test))] #[napi_derive::module_exports] fn install_well_known_symbol_methods(exports: JsObject, mut env: Env) -> napi::Result<()> { - NODE_ENVIRONMENT_COUNT.fetch_add(1, Ordering::AcqRel); - if let Err(error) = env.add_env_cleanup_hook((), |_| { - if NODE_ENVIRONMENT_COUNT.fetch_sub(1, Ordering::AcqRel) == 1 - && let Err(error) = nemo_relay::logging::shutdown_default_logging() - { - eprintln!("nemo-relay: operational logging shutdown failed: {error}"); - } - }) { - NODE_ENVIRONMENT_COUNT.fetch_sub(1, Ordering::AcqRel); + register_node_environment().map_err(to_napi_err)?; + if let Err(error) = env.add_env_cleanup_hook((), |_| cleanup_node_environment()) { + cleanup_node_environment(); return Err(error); } let activation: JsFunction = exports.get_named_property("DynamicPluginActivation")?; From 281018f716c5a6ac5756c12e844d366324921163 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 14:39:57 -0400 Subject: [PATCH 4/7] fix: defer unconfigured logging to host facade Signed-off-by: Will Killian --- crates/core/src/logging/mod.rs | 10 +++++++++- crates/core/tests/coverage/logging_tests.rs | 14 ++++++++++++++ docs/reference/operational-logging.mdx | 4 ++++ 3 files changed, 27 insertions(+), 1 deletion(-) diff --git a/crates/core/src/logging/mod.rs b/crates/core/src/logging/mod.rs index 53d9dbfd2..c35c37d11 100644 --- a/crates/core/src/logging/mod.rs +++ b/crates/core/src/logging/mod.rs @@ -181,7 +181,15 @@ pub fn initialize_default_logging() -> Result<()> { FlowError::Internal(format!("default logging runtime lock poisoned: {error}")) })?; if runtime.is_none() { - *runtime = Some(LoggingRuntime::configure_from_environment()?); + let config = LoggingConfig::from_environment()?; + let uses_default_config = config.is_none(); + match LoggingRuntime::configure(config.unwrap_or_default()) { + Ok(configured) => *runtime = Some(configured), + // Language bindings initialize logging automatically. When Relay was not explicitly + // configured, defer to an application logger that already owns the process facade. + Err(FlowError::AlreadyExists(_)) if uses_default_config => {} + Err(error) => return Err(error), + } } Ok(()) } diff --git a/crates/core/tests/coverage/logging_tests.rs b/crates/core/tests/coverage/logging_tests.rs index d5f74a7e3..98755c490 100644 --- a/crates/core/tests/coverage/logging_tests.rs +++ b/crates/core/tests/coverage/logging_tests.rs @@ -1647,6 +1647,17 @@ fn configure_rejects_preinstalled_foreign_logger() { .contains("process-global log facade is already initialized by another logger"), "{error}" ); + initialize_default_logging() + .expect("unconfigured default logging should defer to the foreign logger"); + unsafe { std::env::set_var("NEMO_RELAY_LOG", "info") }; + let error = initialize_default_logging() + .expect_err("explicit default logging should reject the foreign logger"); + assert!( + error + .to_string() + .contains("process-global log facade is already initialized by another logger"), + "{error}" + ); return; } @@ -1655,6 +1666,9 @@ fn configure_rejects_preinstalled_foreign_logger() { let output = std::process::Command::new(std::env::current_exe().unwrap()) .args(["--exact", test_name, "--nocapture"]) .env(FOREIGN_LOGGER_CHILD_ENV, "1") + .env_remove("NEMO_RELAY_LOG") + .env_remove("NEMO_RELAY_LOG_STDERR_FORMAT") + .env_remove("NEMO_RELAY_LOG_CONFIG_PATH") .output() .expect("foreign logger child test should start"); diff --git a/docs/reference/operational-logging.mdx b/docs/reference/operational-logging.mdx index 626337e85..64fd97946 100644 --- a/docs/reference/operational-logging.mdx +++ b/docs/reference/operational-logging.mdx @@ -88,6 +88,10 @@ export NEMO_RELAY_LOG_CONFIG_PATH=/absolute/path/to/logging.toml `NEMO_RELAY_LOG_CONFIG_PATH` cannot be combined with the other logging environment variables. +When none of these variables are set, Python, Node.js, and Go defer to an +existing application logger if it already owns Rust's process-global `log` +facade. Set one of these variables when Relay must configure its own logging. + Python and Node.js drain pending file-sink records during normal runtime teardown. Go applications that configure file sinks must call `nemo_relay.ShutdownLogging` before `main` returns; defer it near the start of From 203c17b84361171dde70cfac9d5dd6cb27b27b67 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 15:16:06 -0400 Subject: [PATCH 5/7] fix: preserve host logging during binding startup Signed-off-by: Will Killian --- crates/core/src/logging/mod.rs | 11 ++++++ crates/core/tests/coverage/logging_tests.rs | 38 +++++++++++++++++++-- docs/reference/operational-logging.mdx | 13 +++++-- 3 files changed, 56 insertions(+), 6 deletions(-) diff --git a/crates/core/src/logging/mod.rs b/crates/core/src/logging/mod.rs index c35c37d11..0fa97ddfc 100644 --- a/crates/core/src/logging/mod.rs +++ b/crates/core/src/logging/mod.rs @@ -45,6 +45,14 @@ fn log_crate_proxy_is_installed() -> bool { std::ptr::addr_eq(log::logger(), spdlog::log_crate_proxy() as &dyn log::Log) } +fn log_crate_proxy_has_receiver() -> bool { + let _lifecycle = lock_logger_lifecycle(); + let receiver = spdlog::log_crate_proxy().swap_logger(None); + let has_receiver = receiver.is_some(); + spdlog::log_crate_proxy().set_logger(receiver); + has_receiver +} + fn install_log_crate_proxy() -> Result<()> { match spdlog::init_log_crate_proxy() { Ok(()) => Ok(()), @@ -183,6 +191,9 @@ pub fn initialize_default_logging() -> Result<()> { if runtime.is_none() { let config = LoggingConfig::from_environment()?; let uses_default_config = config.is_none(); + if uses_default_config && log_crate_proxy_is_installed() && log_crate_proxy_has_receiver() { + return Ok(()); + } match LoggingRuntime::configure(config.unwrap_or_default()) { Ok(configured) => *runtime = Some(configured), // Language bindings initialize logging automatically. When Relay was not explicitly diff --git a/crates/core/tests/coverage/logging_tests.rs b/crates/core/tests/coverage/logging_tests.rs index 98755c490..41f6011ce 100644 --- a/crates/core/tests/coverage/logging_tests.rs +++ b/crates/core/tests/coverage/logging_tests.rs @@ -228,19 +228,51 @@ queue_capacity = 16 shutdown_default_logging().unwrap(); shutdown_default_logging().unwrap(); - let records = std::fs::read_to_string(log_path).unwrap(); + let records = std::fs::read_to_string(log_path) + .unwrap() + .lines() + .map(|line| serde_json::from_str::(line).expect("valid JSONL lifecycle record")) + .collect::>(); assert_eq!( - records.matches(r#""event":"logging_initialized""#).count(), + records + .iter() + .filter(|record| record["event"] == "logging_initialized") + .count(), 1 ); assert_eq!( records - .matches(r#""event":"logging_shutdown_started""#) + .iter() + .filter(|record| record["event"] == "logging_shutdown_started") .count(), 1 ); } +#[test] +fn implicit_default_logging_preserves_an_existing_relay_logger() { + let _environment = LoggingEnvScope::set(&[ + ("NEMO_RELAY_LOG", None), + ("NEMO_RELAY_LOG_STDERR_FORMAT", None), + ("NEMO_RELAY_LOG_CONFIG_PATH", None), + ]); + shutdown_default_logging().unwrap(); + let host_runtime = init_logging(&default_config()).unwrap(); + + initialize_default_logging().unwrap(); + shutdown_default_logging().unwrap(); + + let receiver = spdlog::log_crate_proxy().swap_logger(None); + assert!( + receiver + .as_ref() + .is_some_and(|receiver| Arc::ptr_eq(receiver, &host_runtime.logger)), + "implicit binding startup must preserve the host Relay logger" + ); + spdlog::log_crate_proxy().set_logger(receiver); + drop(host_runtime); +} + #[test] fn default_logging_runtime_rejects_invalid_environment() { let _environment = LoggingEnvScope::set(&[ diff --git a/docs/reference/operational-logging.mdx b/docs/reference/operational-logging.mdx index 64fd97946..c3912f29f 100644 --- a/docs/reference/operational-logging.mdx +++ b/docs/reference/operational-logging.mdx @@ -88,9 +88,16 @@ export NEMO_RELAY_LOG_CONFIG_PATH=/absolute/path/to/logging.toml `NEMO_RELAY_LOG_CONFIG_PATH` cannot be combined with the other logging environment variables. -When none of these variables are set, Python, Node.js, and Go defer to an -existing application logger if it already owns Rust's process-global `log` -facade. Set one of these variables when Relay must configure its own logging. +When none of these variables are set, Python, Node.js, and Go install Relay's +built-in default logger unless the host already owns Rust's process-global +`log` facade. They also preserve an existing Relay logger rather than replacing +it. Records emitted before any logger is installed are discarded, and a host +cannot install its own logger after Relay has claimed the facade. Set one of +these variables when Relay must configure its own logging. + +This binding behavior differs from +`LoggingRuntime::configure_from_environment()`, which always attempts to +install Relay's built-in defaults when no variables are set. Python and Node.js drain pending file-sink records during normal runtime teardown. Go applications that configure file sinks must call From d045bb3608995641e93881b1a65ce55824adffa2 Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 15:28:44 -0400 Subject: [PATCH 6/7] test: restore logging proxy after assertion Signed-off-by: Will Killian --- crates/core/tests/coverage/logging_tests.rs | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/crates/core/tests/coverage/logging_tests.rs b/crates/core/tests/coverage/logging_tests.rs index 41f6011ce..6ecf30e6a 100644 --- a/crates/core/tests/coverage/logging_tests.rs +++ b/crates/core/tests/coverage/logging_tests.rs @@ -263,13 +263,14 @@ fn implicit_default_logging_preserves_an_existing_relay_logger() { shutdown_default_logging().unwrap(); let receiver = spdlog::log_crate_proxy().swap_logger(None); + let preserves_host_logger = receiver + .as_ref() + .is_some_and(|receiver| Arc::ptr_eq(receiver, &host_runtime.logger)); + spdlog::log_crate_proxy().set_logger(receiver); assert!( - receiver - .as_ref() - .is_some_and(|receiver| Arc::ptr_eq(receiver, &host_runtime.logger)), + preserves_host_logger, "implicit binding startup must preserve the host Relay logger" ); - spdlog::log_crate_proxy().set_logger(receiver); drop(host_runtime); } From 6eb20b4614180462f534996f391b46e4f0d6f41f Mon Sep 17 00:00:00 2001 From: Will Killian Date: Tue, 4 Aug 2026 16:07:16 -0400 Subject: [PATCH 7/7] fix: preserve Relay logging receiver Signed-off-by: Will Killian --- crates/core/src/logging/mod.rs | 54 ++++++++++++++++++++++++++-------- 1 file changed, 41 insertions(+), 13 deletions(-) diff --git a/crates/core/src/logging/mod.rs b/crates/core/src/logging/mod.rs index 0fa97ddfc..4d06f5806 100644 --- a/crates/core/src/logging/mod.rs +++ b/crates/core/src/logging/mod.rs @@ -13,7 +13,7 @@ mod sink; use std::io::{self, Write}; use std::path::Path; -use std::sync::{Arc, Mutex, MutexGuard}; +use std::sync::{Arc, Mutex, MutexGuard, Weak}; use spdlog::sink::Sink; use spdlog::{Logger, ThreadPool}; @@ -34,6 +34,7 @@ pub(crate) use format::format_event_for_test; static LOGGER_LIFECYCLE_LOCK: Mutex<()> = Mutex::new(()); static DEFAULT_LOGGING_RUNTIME: Mutex> = Mutex::new(None); +static ACTIVE_RELAY_LOGGER: Mutex>> = Mutex::new(None); fn lock_logger_lifecycle() -> MutexGuard<'static, ()> { LOGGER_LIFECYCLE_LOCK @@ -45,12 +46,30 @@ fn log_crate_proxy_is_installed() -> bool { std::ptr::addr_eq(log::logger(), spdlog::log_crate_proxy() as &dyn log::Log) } -fn log_crate_proxy_has_receiver() -> bool { - let _lifecycle = lock_logger_lifecycle(); - let receiver = spdlog::log_crate_proxy().swap_logger(None); - let has_receiver = receiver.is_some(); - spdlog::log_crate_proxy().set_logger(receiver); - has_receiver +fn active_relay_logger_exists() -> bool { + ACTIVE_RELAY_LOGGER + .lock() + .unwrap_or_else(|error| error.into_inner()) + .as_ref() + .is_some_and(|logger| logger.upgrade().is_some()) +} + +fn set_active_relay_logger(logger: &Arc) { + *ACTIVE_RELAY_LOGGER + .lock() + .unwrap_or_else(|error| error.into_inner()) = Some(Arc::downgrade(logger)); +} + +fn clear_active_relay_logger(logger: &Arc) { + let mut active = ACTIVE_RELAY_LOGGER + .lock() + .unwrap_or_else(|error| error.into_inner()); + if active + .as_ref() + .is_some_and(|current| Weak::ptr_eq(current, &Arc::downgrade(logger))) + { + *active = None; + } } fn install_log_crate_proxy() -> Result<()> { @@ -84,17 +103,22 @@ impl LoggingRuntime { /// opened. Dropping the returned runtime flushes sinks and detaches its logger from the /// process-global `log` proxy when it is still installed. pub fn configure(config: LoggingConfig) -> Result { - let root_relay_id = Uuid::now_v7().to_string(); - let (logger, thread_pools) = build_logger(&config, root_relay_id.clone())?; - // Install once per process. Subsequent calls (tests / re-entry) reuse the proxy and swap // the receiver logger. A different global logger would prevent Relay sinks from receiving // `log` facade records, so fail instead of returning a nonfunctional runtime. let _lifecycle = lock_logger_lifecycle(); + Self::configure_with_lifecycle_lock(config) + } + + fn configure_with_lifecycle_lock(config: LoggingConfig) -> Result { + let root_relay_id = Uuid::now_v7().to_string(); + let (logger, thread_pools) = build_logger(&config, root_relay_id.clone())?; + install_log_crate_proxy()?; spdlog::log_crate_proxy().set_logger(Some(Arc::clone(&logger))); spdlog::log_crate_proxy().set_filter(None); log::set_max_level(log_level_filter(config.level)); + set_active_relay_logger(&logger); log::info!( target: "nemo_relay.logging", @@ -163,7 +187,10 @@ impl Drop for LoggingRuntime { if let Some(logger) = detached && !Arc::ptr_eq(&logger, &self.logger) { - spdlog::log_crate_proxy().set_logger(Some(logger)); + spdlog::log_crate_proxy().set_logger(Some(Arc::clone(&logger))); + set_active_relay_logger(&logger); + } else { + clear_active_relay_logger(&self.logger); } } } @@ -191,10 +218,11 @@ pub fn initialize_default_logging() -> Result<()> { if runtime.is_none() { let config = LoggingConfig::from_environment()?; let uses_default_config = config.is_none(); - if uses_default_config && log_crate_proxy_is_installed() && log_crate_proxy_has_receiver() { + let _lifecycle = lock_logger_lifecycle(); + if uses_default_config && active_relay_logger_exists() { return Ok(()); } - match LoggingRuntime::configure(config.unwrap_or_default()) { + match LoggingRuntime::configure_with_lifecycle_lock(config.unwrap_or_default()) { Ok(configured) => *runtime = Some(configured), // Language bindings initialize logging automatically. When Relay was not explicitly // configured, defer to an application logger that already owns the process facade.