Native API - Option to dump Rust tracing to file

api/native/Cargo.toml

@@ -14,6 +14,7 @@ azihsm_api.workspace = true
 open-enum.workspace = true
 parking_lot.workspace = true
 tracing.workspace = true
+tracing-subscriber = { features = ["env-filter", "fmt"], workspace = true }
 zerocopy = { features = ["derive"], workspace = true }
 
 [features]

api/native/doc/chapter_11_diagnostics.md

@@ -0,0 +1,78 @@
+# Diagnostics
+
+## File-Based Tracing
+
+The native API library uses Rust's `tracing` framework internally for structured logging across the entire SDK stack, from the API layer down through the DDI.
+By default no trace output is emitted, but it can be directed to a file by setting environment variables before loading the library.
+
+This is useful for diagnosing failures in any host process that loads `azihsm_api_native` (e.g., the OpenSSL provider, C/C++ test binaries, or custom applications).
+
+### Environment Variables
+
+| Variable | Required | Description |
+|----------|----------|-------------|
+| `AZIHSM_NATIVEAPI_TRACE_FILE` | Yes | File path for trace output. When set, a tracing subscriber is installed on the first API call. |
+| `AZIHSM_NATIVEAPI_TRACE_FILE_APPEND` | No | Set to `1` to append to an existing file. If unset or any other value, the file is truncated on each run. |
+| `RUST_LOG` | No | Controls the trace filter level. Defaults to `info`. Accepts standard `tracing` filter syntax (see below). |
+
+### Trace Filter Syntax
+
+The `RUST_LOG` variable accepts directives in the format used by [`tracing-subscriber`'s `EnvFilter`](https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html).
+A few examples:
+
+| Value | Effect |
+|-------|--------|
+| `debug` | All crates at DEBUG level and above |
+| `trace` | All crates at TRACE level (most verbose) |
+| `info` | All crates at INFO level (the default) |
+| `azihsm_api=debug,azihsm_ddi_mock=info` | DEBUG for the API, INFO for the mock DDI, WARN for others |
+
+### Usage Example
+
+```bash
+# Linux
+export AZIHSM_NATIVEAPI_TRACE_FILE=/tmp/azihsm_trace.log
+export RUST_LOG=debug
+./my_application
+
+# Inspect the trace
+head -50 /tmp/azihsm_trace.log
+```
+
+```powershell
+# Windows (PowerShell)
+$env:AZIHSM_NATIVEAPI_TRACE_FILE = "$env:TEMP\azihsm_trace.log"
+$env:RUST_LOG = "debug"
+.\my_application.exe
+
+# Inspect the trace
+Get-Content $env:AZIHSM_NATIVEAPI_TRACE_FILE | Select-Object -First 50
+```
+
+### Output Format
+
+Each line in the trace file contains a structured event with the following fields:
+
+* **Timestamp** — UTC wall-clock time (e.g., `2026-06-12T17:13:42.223204Z`)
+* **Level** — `TRACE`, `DEBUG`, `INFO`, `WARN`, or `ERROR`
+* **Thread ID** — Identifies the originating thread (e.g., `ThreadId(01)`)
+* **Span context** — Nested call chain showing the path through the SDK
+* **Target** — The Rust module that emitted the event (e.g., `azihsm_api::partition`)
+* **Message** — The log message and any structured fields
+
+Example output:
+
+```text
+2026-06-12T17:13:42.223204Z  INFO ThreadId(01) partition_info_list: azihsm_api::partition: enter
+2026-06-12T17:13:42.224544Z DEBUG ThreadId(01) partition_info_list:dev_paths:dev_info_list{self=DdiMock}: azihsm_ddi_mock::ddi: Got DdiMock device info list size=1
+```
+
+### Behavior Notes
+
+* Tracing initialization occurs exactly once, on the first API call.
+  Subsequent calls incur no overhead.
+* If `AZIHSM_NATIVEAPI_TRACE_FILE` is not set, no subscriber is installed and there is no performance impact.
+* If the trace file cannot be opened (e.g., invalid path or permission denied), the library silently continues without tracing.
+* The trace subscriber is global to the process.
+  If another subscriber has already been installed (e.g., by the host application), the library's subscriber will not replace it.
+

api/native/src/lib.rs

@@ -35,6 +35,7 @@ mod session_props;
 #[path = "../../lib/src/shared_types.rs"]
 mod shared_types;
 mod str;
+mod trace_file;
 mod utils;
 
 use std::ffi::c_void;
@@ -200,6 +201,7 @@ static HANDLE_TABLE: LazyLock<HandleTable> = LazyLock::new(HandleTable::default)
 pub(crate) fn abi_boundary<F: FnOnce() -> Result<(), AzihsmStatus> + UnwindSafe>(
     f: F,
 ) -> AzihsmStatus {
+    let _ = std::panic::catch_unwind(trace_file::init_trace_file);
     match catch_unwind(f) {
         Ok(hr) => match hr {
             Ok(_) => AzihsmStatus::Success,

api/native/src/trace_file.rs

@@ -0,0 +1,206 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+//! File-based tracing initialization for the native API.
+//!
+//! When the environment variable `AZIHSM_NATIVEAPI_TRACE_FILE` is set to a file
+//! path, this module installs a `tracing_subscriber` that writes all trace
+//! output to that file. Initialization is idempotent and thread-safe thanks
+//! to [`std::sync::Once`].
+//!
+//! By default, the file is truncated on each run.
+//! Set `AZIHSM_NATIVEAPI_TRACE_FILE_APPEND=1` to append instead.
+//!
+//! If the environment variable is not set, or if any step of the
+//! initialization fails (file open, filter parse, subscriber install), the
+//! function silently returns without installing a subscriber.
+
+use std::io::Write;
+use std::sync::Once;
+
+use tracing_subscriber::EnvFilter;
+use tracing_subscriber::fmt;
+use tracing_subscriber::fmt::MakeWriter;
+use tracing_subscriber::prelude::*;
+
+/// Name of the environment variable that controls file-based tracing.
+const TRACE_FILE_ENV_VAR: &str = "AZIHSM_NATIVEAPI_TRACE_FILE";
+
+/// Name of the environment variable that controls append mode.
+/// When set to `"1"`, the trace file is opened in append mode so that
+/// output from successive runs accumulates.  Any other value (or unset)
+/// causes the file to be truncated on each run.
+const TRACE_FILE_APPEND_ENV_VAR: &str = "AZIHSM_NATIVEAPI_TRACE_FILE_APPEND";
+
+/// Thread-safe, non-poisoning file writer for the tracing subscriber.
+///
+/// Uses [`parking_lot::Mutex`] instead of [`std::sync::Mutex`] so that a
+/// panic while holding the lock does not poison the mutex and silently
+/// break all subsequent trace writes.
+struct TraceFileWriter(parking_lot::Mutex<std::fs::File>);
+
+/// RAII guard returned by [`TraceFileWriter`] that implements [`Write`].
+struct TraceFileWriterGuard<'a>(parking_lot::MutexGuard<'a, std::fs::File>);
+
+impl Write for TraceFileWriterGuard<'_> {
+    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
+        self.0.write(buf)
+    }
+
+    fn flush(&mut self) -> std::io::Result<()> {
+        self.0.flush()
+    }
+}
+
+impl<'a> MakeWriter<'a> for TraceFileWriter {
+    type Writer = TraceFileWriterGuard<'a>;
+
+    fn make_writer(&'a self) -> Self::Writer {
+        TraceFileWriterGuard(self.0.lock())
+    }
+}
+
+/// Ensures file-based tracing is initialized exactly once.
+///
+/// This function is safe to call from any thread and any number of times.
+/// On the first call it checks `AZIHSM_NATIVEAPI_TRACE_FILE`:
+///
+/// * If the variable is **not set**, no subscriber is installed.
+/// * If it **is set**, the file is opened and a `tracing_subscriber::fmt`
+///   subscriber is installed that writes timestamped, structured trace events
+///   to the file.  Timestamps are always in UTC.
+///
+/// All errors are silently ignored so that tracing failures never affect
+/// normal library operation.
+pub(crate) fn init_trace_file() {
+    static ONCE: Once = Once::new();
+
+    ONCE.call_once(|| {
+        // If the env var is not set, do nothing.
+        let trace_path = match std::env::var(TRACE_FILE_ENV_VAR) {
+            Ok(p) if !p.is_empty() => p,
+            _ => return,
+        };
+
+        // Check whether append mode is requested.
+        let append = matches!(std::env::var(TRACE_FILE_APPEND_ENV_VAR).as_deref(), Ok("1"));
+
+        // Attempt to open/create the trace file.
+        let mut opts = std::fs::OpenOptions::new();
+        opts.create(true).write(true);
+        if append {
+            opts.append(true);
+        } else {
+            opts.truncate(true);
+        }
+        let file = match opts.open(&trace_path) {
+            Ok(f) => f,
+            Err(_) => return,
+        };
+        let writer = TraceFileWriter(parking_lot::Mutex::new(file));
+
+        // Build an EnvFilter from RUST_LOG, defaulting to `info`.
+        let filter = match EnvFilter::try_from_default_env() {
+            Ok(f) => f,
+            Err(_) => match EnvFilter::try_new("info") {
+                Ok(f) => f,
+                Err(_) => return,
+            },
+        };
+
+        // Build and install the subscriber.  If `set_global_default` fails
+        // (e.g. another subscriber was already installed), silently ignore.
+        let subscriber = tracing_subscriber::registry().with(filter).with(
+            fmt::layer()
+                .with_writer(writer)
+                .with_ansi(false)
+                .with_timer(fmt::time::SystemTime)
+                .with_thread_ids(true)
+                .with_target(true)
+                .with_span_events(fmt::format::FmtSpan::FULL),
+        );
+
+        let _ = tracing::subscriber::set_global_default(subscriber);
+    });
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    /// Calling `init_trace_file` multiple times must never panic, regardless
+    /// of whether the env var is set.
+    #[test]
+    fn init_trace_file_is_idempotent() {
+        // Without the env var set, these are all no-ops.
+        init_trace_file();
+        init_trace_file();
+        init_trace_file();
+    }
+
+    /// Verifies that trace output is written to the file when the
+    /// environment variable is set.  Runs as a subprocess so that the
+    /// `Once` guard and global subscriber don't interfere with other tests.
+    #[test]
+    fn trace_output_written_to_file() {
+        // Use a unique filename to avoid collisions when tests run in
+        // parallel or multiple jobs share the same temp directory.
+        let filename = format!(
+            "azihsm_nativeapi_trace_test_{}_{}.log",
+            std::process::id(),
+            std::time::SystemTime::now()
+                .duration_since(std::time::UNIX_EPOCH)
+                .map_or(0, |d| d.as_nanos()),
+        );
+        let trace_path = std::env::temp_dir().join(filename);
+        let _ = std::fs::remove_file(&trace_path);
+
+        // Re-invoke *this* test binary running only the helper test, with
+        // the trace env vars set.  The helper emits a known marker event.
+        // The helper is #[ignore]d so it doesn't run as a no-op during
+        // normal test execution; --include-ignored allows us to invoke it.
+        let exe = std::env::current_exe().expect("current_exe should be available");
+        let status = std::process::Command::new(&exe)
+            .arg("--exact")
+            .arg("trace_file::tests::trace_output_helper")
+            .arg("--nocapture")
+            .arg("--include-ignored")
+            .env(TRACE_FILE_ENV_VAR, &trace_path)
+            .env("RUST_LOG", "trace")
+            .status()
+            .expect("failed to spawn subprocess");
+
+        assert!(status.success(), "helper subprocess failed: {status}");
+
+        let contents = std::fs::read_to_string(&trace_path)
+            .expect("trace file should exist after the helper ran");
+
+        assert!(
+            contents.contains("trace_init_marker_event"),
+            "trace file should contain the marker event, but got:\n{contents}"
+        );
+
+        // Verify the first line starts with an RFC 3339 UTC timestamp
+        // (e.g. "2026-06-12T17:13:42.223204Z").
+        let first_line = contents.lines().next().unwrap_or("");
+        assert!(
+            first_line.len() > 30
+                && first_line.as_bytes()[4] == b'-'
+                && first_line.as_bytes()[10] == b'T'
+                && first_line.contains("Z "),
+            "first line should start with an RFC 3339 UTC timestamp, but was:\n{first_line}"
+        );
+
+        let _ = std::fs::remove_file(&trace_path);
+    }
+
+    /// Helper test invoked as a subprocess by `trace_output_written_to_file`.
+    /// Not meant to be run directly — it requires the trace env vars to be
+    /// set by the parent process.
+    #[ignore]
+    #[test]
+    fn trace_output_helper() {
+        init_trace_file();
+        tracing::info!("trace_init_marker_event");
+    }
+}