penna 0.1.0

Structured JSON logging for tracing, in one line per event, without a regex engine underneath
Documentation
//! Structured JSON logging for [`tracing`](https://docs.rs/tracing), one line
//! per event.
//!
//! A service that logs JSON lines to stdout and filters them by level needs a
//! timestamp, an escaper and a comparison against a target prefix. The usual
//! way to get that pulls in a regex engine, an ANSI colour library, a sharded
//! slab and a thread-local crate, none of which a JSON line ever touches.
//! `penna` has one dependency — `tracing-core`, which defines the traits — and
//! writes the same lines.
//!
//! ```
//! # fn main() {
//! penna::json().install();
//!
//! tracing::info!(events = 5000, backup_key = "…", "telemetry events persisted");
//! # }
//! ```
//!
//! ```text
//! {"timestamp":"2026-09-21T00:56:59.991167Z","level":"INFO","fields":{"message":"telemetry events persisted","events":5000,"backup_key":"…"},"target":"my_service"}
//! ```
//!
//! That shape is deliberate: it is what `tracing-subscriber`'s JSON formatter
//! emits with its defaults, so a dashboard or log pipeline already parsing
//! those lines keeps working.
//!
//! # Filtering
//!
//! [`Builder::filter`] takes the same directives as `RUST_LOG`, read by
//! [`Builder::install`] when no filter is set:
//!
//! ```text
//! info                            everything at info and above
//! warn,my_service=debug           debug for one module, warn elsewhere
//! my_service::spool=trace         one module, everything else off
//! ```
//!
//! A directive is a target prefix and a level. Matching is by path prefix on
//! module boundaries — `my_service` matches `my_service::spool` but not
//! `my_service_other` — and the longest matching prefix wins, so a specific
//! directive overrides a general one whatever order they appear in. There is
//! no regex, no field matching and no span filtering; if you need those,
//! `tracing-subscriber`'s `EnvFilter` is the right tool.
//!
//! # Spans
//!
//! Open spans ride along on every event inside them: the innermost as `span`
//! and the whole stack as `spans`, each with the fields it was created with.
//! Nothing is printed when a span opens or closes — a span is context for the
//! events inside it, not an event.

#![forbid(unsafe_code)]
#![warn(missing_docs)]

mod filter;
mod json;
mod time;
mod writer;

use std::io;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::Mutex;

use tracing_core::span::{Attributes, Id, Record};
use tracing_core::{Event, Metadata, Subscriber};

pub use filter::Filter;
pub use writer::{MakeWriter, Stderr, Stdout};

/// Starts building a subscriber that writes JSON lines to stdout.
pub fn json() -> Builder<Stdout> {
    Builder {
        writer: Stdout,
        filter: None,
    }
}

/// A subscriber being configured.
#[derive(Debug)]
pub struct Builder<W> {
    writer: W,
    filter: Option<Filter>,
}

impl<W: MakeWriter> Builder<W> {
    /// Sets the filter directly, instead of reading `RUST_LOG`.
    pub fn filter(mut self, directives: &str) -> Self {
        self.filter = Some(Filter::parse(directives));
        self
    }

    /// Writes somewhere other than stdout — [`Stderr`], or anything you
    /// implement [`MakeWriter`] for.
    pub fn with_writer<T: MakeWriter>(self, writer: T) -> Builder<T> {
        Builder {
            writer,
            filter: self.filter,
        }
    }

    /// Builds the subscriber without installing it, for
    /// `tracing::subscriber::with_default` or for wrapping.
    pub fn finish(self) -> Penna<W> {
        Penna {
            writer: self.writer,
            filter: self.filter.unwrap_or_else(Filter::from_env),
            spans: Mutex::new(Vec::new()),
            next_id: AtomicU64::new(1),
        }
    }

    /// Installs the subscriber as the global default for the process.
    ///
    /// Returns an error if one is already installed, which is the only way
    /// this can fail; a program that logs from tests should use
    /// [`Builder::finish`] with `with_default` instead.
    pub fn try_install(self) -> Result<(), tracing_core::dispatcher::SetGlobalDefaultError> {
        tracing_core::dispatcher::set_global_default(tracing_core::Dispatch::new(self.finish()))
    }

    /// Installs the subscriber as the global default, ignoring the error if
    /// one is already installed. This is what a binary wants in `main`.
    pub fn install(self) {
        let _ = self.try_install();
    }
}

/// The subscriber. Build it with [`json`].
#[derive(Debug)]
pub struct Penna<W> {
    writer: W,
    filter: Filter,
    /// Open spans, indexed by id minus one. A span is replaced by `None` when
    /// it closes, and its slot is reused; a service holds few spans open at
    /// once, so a vector with a mutex beats anything cleverer and is easier to
    /// be sure of.
    spans: Mutex<Vec<Option<SpanData>>>,
    next_id: AtomicU64,
}

#[derive(Debug)]
struct SpanData {
    name: &'static str,
    /// The span's fields, already rendered as `"key":value` pairs.
    fields: String,
    /// How many handles exist. The span closes when this reaches zero, which
    /// is what keeps a cloned `Id` from dropping it early.
    refs: usize,
}

thread_local! {
    /// The ids entered on this thread, innermost last. Spans are per-thread
    /// context, so this is where they belong.
    static STACK: std::cell::RefCell<Vec<u64>> = const { std::cell::RefCell::new(Vec::new()) };
}

impl<W: MakeWriter> Subscriber for Penna<W> {
    fn enabled(&self, metadata: &Metadata<'_>) -> bool {
        self.filter.enabled(metadata.target(), *metadata.level())
    }

    fn max_level_hint(&self) -> Option<tracing_core::LevelFilter> {
        Some(self.filter.max_level())
    }

    fn new_span(&self, attributes: &Attributes<'_>) -> Id {
        let mut fields = String::new();
        attributes.record(&mut json::FieldWriter::new(&mut fields));
        let data = SpanData {
            name: attributes.metadata().name(),
            fields,
            refs: 1,
        };

        let mut spans = self
            .spans
            .lock()
            .unwrap_or_else(|poison| poison.into_inner());
        let index = spans.iter().position(Option::is_none);
        match index {
            Some(index) => {
                spans[index] = Some(data);
                Id::from_u64(index as u64 + 1)
            }
            None => {
                spans.push(Some(data));
                // Kept in step with the vector so a reused slot never hands
                // out an id the caller already holds.
                self.next_id
                    .store(spans.len() as u64 + 1, Ordering::Relaxed);
                Id::from_u64(spans.len() as u64)
            }
        }
    }

    fn record(&self, id: &Id, values: &Record<'_>) {
        let mut spans = self
            .spans
            .lock()
            .unwrap_or_else(|poison| poison.into_inner());
        if let Some(Some(span)) = spans.get_mut(index_of(id)) {
            values.record(&mut json::FieldWriter::appending(&mut span.fields));
        }
    }

    fn record_follows_from(&self, _span: &Id, _follows: &Id) {}

    fn event(&self, event: &Event<'_>) {
        let metadata = event.metadata();
        let mut line = String::with_capacity(256);
        line.push_str("{\"timestamp\":\"");
        time::write_rfc3339_micros(&mut line, std::time::SystemTime::now());
        line.push_str("\",\"level\":\"");
        line.push_str(metadata.level().as_str());
        line.push_str("\",\"fields\":{");
        event.record(&mut json::FieldWriter::new(&mut line));
        line.push_str("},\"target\":");
        json::write_string(&mut line, metadata.target());
        self.write_spans(&mut line);
        line.push_str("}\n");

        // A failed write goes nowhere useful: reporting it would need the very
        // logger that just failed.
        let _ = self.writer.make_writer().write_all(line.as_bytes());
    }

    fn enter(&self, id: &Id) {
        STACK.with(|stack| stack.borrow_mut().push(id.into_u64()));
    }

    fn exit(&self, id: &Id) {
        STACK.with(|stack| {
            let mut stack = stack.borrow_mut();
            // Spans are not guaranteed to exit in order, so remove the
            // innermost match rather than assuming it is on top.
            if let Some(position) = stack.iter().rposition(|open| *open == id.into_u64()) {
                stack.remove(position);
            }
        });
    }

    fn clone_span(&self, id: &Id) -> Id {
        let mut spans = self
            .spans
            .lock()
            .unwrap_or_else(|poison| poison.into_inner());
        if let Some(Some(span)) = spans.get_mut(index_of(id)) {
            span.refs += 1;
        }
        id.clone()
    }

    fn try_close(&self, id: Id) -> bool {
        let mut spans = self
            .spans
            .lock()
            .unwrap_or_else(|poison| poison.into_inner());
        let Some(slot) = spans.get_mut(index_of(&id)) else {
            return false;
        };
        let Some(span) = slot else { return false };
        span.refs -= 1;
        if span.refs == 0 {
            *slot = None;
            return true;
        }
        false
    }
}

impl<W: MakeWriter> Penna<W> {
    /// Appends the enclosing spans: the innermost as `span`, the whole stack
    /// as `spans`. Both are omitted when nothing is open, which is the common
    /// case for a service that logs events and holds no spans.
    fn write_spans(&self, line: &mut String) {
        let open = STACK.with(|stack| stack.borrow().clone());
        if open.is_empty() {
            return;
        }
        let spans = self
            .spans
            .lock()
            .unwrap_or_else(|poison| poison.into_inner());
        let rendered: Vec<String> = open
            .iter()
            .filter_map(|id| spans.get(*id as usize - 1).and_then(Option::as_ref))
            .map(|span| {
                let mut out = String::with_capacity(span.fields.len() + 32);
                out.push('{');
                out.push_str(&span.fields);
                if !span.fields.is_empty() {
                    out.push(',');
                }
                out.push_str("\"name\":");
                json::write_string(&mut out, span.name);
                out.push('}');
                out
            })
            .collect();
        if rendered.is_empty() {
            return;
        }
        line.push_str(",\"span\":");
        line.push_str(rendered.last().expect("checked non-empty"));
        line.push_str(",\"spans\":[");
        line.push_str(&rendered.join(","));
        line.push(']');
    }
}

fn index_of(id: &Id) -> usize {
    id.into_u64() as usize - 1
}

/// Writes to whatever the writer makes, so a `MakeWriter` returning a locked
/// handle keeps one line whole.
trait WriteAll {
    fn write_all(self, bytes: &[u8]) -> io::Result<()>;
}

impl<T: io::Write> WriteAll for T {
    fn write_all(mut self, bytes: &[u8]) -> io::Result<()> {
        io::Write::write_all(&mut self, bytes)
    }
}