std::log

Saying what happened, on the stream meant for it.

Log is the capability for structured diagnostics: one JSON object per line on standard error, with the level and the destination chosen by the caller. eprint is the unstructured primitive underneath it.

Standard error rather than standard output, because a program’s diagnostics and its answer are different things: a command-line tool whose output is redirected would otherwise lose its own error messages into the file.

Why logging is an effect

Because everything else that reaches outside is. A function that logs is a function that writes to a stream somebody else owns, and Khora’s whole argument is that such a function says so in its signature:

fn charge(account: Account, amount: Decimal) -> Receipt
  with { log: Log, db: Db }
  raises DbError

That buys the same three things capabilities always buy. A test installs a logger that collects into a list and asserts on what was said, with no global to reset between cases. A library cannot log without its caller knowing, because the row would say so. And the caller decides the format and the destination, which is the decision a library has no business making.

print is not an effect and says so in its own doc comment; it is the one that predates the argument rather than the one that refutes it.

Levels

Five, in the order everybody already knows: Severity::Trace, Severity::Debug, Severity::Info, Severity::Warn, Severity::Error. Not four and not seven, because these are the ones every operator has a filter for, and a level nobody filters on is a level nobody sets.

The handler decides what to drop, not the caller. Log::json, Log::json_using and Log::plain each take a minimum and discard anything below it. A caller that checked the level itself would be a caller that has to know the configuration, which is the thing the capability exists to keep away from it.

The format is JSON

One object per line, on standard error:

{"timestamp":1757021376817,"level":"warn","message":"retrying","attempt":2}

Because a log is read by a program before it is read by a person. It goes to a collector, gets indexed, and is queried months later by somebody who was not there; a format that needs a regular expression to take apart is a format that loses a field the first time a message contains a space. Log::plain is there for a terminal, and it is the exception rather than the default.

timestamp is milliseconds since 1970, as a JSON number. Milliseconds rather than nanoseconds because a nanosecond epoch is about 2^60 and JSON numbers are doubles in most readers, which would round it — the same trap std::trace’s OTLP encoding avoids by sending strings. Milliseconds are about 2^41 and exact in a double for the next twenty thousand years.

level is lower case — "warn", not "Warn" — which is what Elastic Common Schema, slog, zap and structlog all emit, and therefore what a collector’s default level filter already matches.

Attributes become fields of the same object. A field named level, message or timestamp would collide with the three above; it is written anyway, last, because silently renaming somebody’s field is worse than a duplicate key that a collector will show them.

Correlating with traces

trace_id and span_id are added by the handler, not by the caller. A line logged inside an around carries the ids of the span it was logged in, because std::trace::current is ambient and per fiber; a line logged outside every span carries neither, rather than carrying zeros. Nothing has to be threaded through a signature to make a log line findable from a trace, which was the whole point of the exercise.

{"timestamp":1757021376817,"level":"info","message":"charging",
 "trace_id":"4bf92f3577b34da6a3ce929d0e0e4736","span_id":"00f067aa0ba902b7"}

A record carries Attributes, the same ones std::trace puts on a span, so whatever else is worth correlating on goes on the line beside them:

log.record(Severity::Warn, "retrying", [text("account", account.id)])

Attributes named trace_id or span_id are still written, after these and by the same rule as level and message: silently dropping somebody’s field is worse than a duplicate key a collector will show them. Writing one by hand — text("trace_id", Context::trace_id(span.context)), and it is a method on Context rather than a free function — is how a line ends up carrying the key twice.

API at a glance

Types: Severity

Effects: Log

Methods: Severity · Log

Functions: trace · debug · info · warn · error · eprint

Types

Severity

derive(Eq, Ord, Show)
pub type Severity =
  | Trace
  | Debug
  | Info
  | Warn
  | Error;

How much something matters, in the order everybody already filters on.

Ord so a handler can compare against a minimum: Trace is the least and Error the most, which is the direction “at least Info” reads in.

Named Severity; the JSON field it writes is still level. Level is a name a program is likely to have already, and two modules declaring one type name does not resolve cleanly today.

Trace

| Trace

The finest detail, off outside a debugging session.

Debug

| Debug

What a developer wants while working on this code.

Info

| Info

What an operator wants while the program is behaving.

Warn

| Warn

Something is wrong and the program is carrying on.

Error

| Error

Something is wrong and something did not happen.

Effects

Log

pub effect Log {
  record: (Severity, String, List<Attribute>) -> (),
}

Writing a line somebody will read later.

One operation, because a level is an argument rather than a method: five operations would be five things for every handler to implement and five places for one of them to behave differently.

record

record: (Severity, String, List) ->()

Records one line at level, with whatever structure is attached.

Methods

Severity

impl Severity

label

pub fn label(self) -> String

The five-character name, padded, so lines align in a terminal.

Padded rather than not, because an operator reads a log by scanning the left edge, and a ragged one makes them read every line instead.

name

pub fn name(self) -> String

The lower-case name, which is what goes on the wire.

Lower case because that is what Elastic Common Schema, slog, zap and structlog emit, so a collector’s default level filter already matches it without anybody configuring one.

severity

pub fn severity(self) -> Int

Where this sits, for comparing against a minimum.

of_name

pub fn of_name(name: String) -> Option<Severity>

The level name spells, or None.

Both cases spelled out rather than lower-cased first. String::lower exists and is ASCII-only, which is right for these six words; what it would also do is accept wArN and Info, and a level name arrives from a manifest or an environment variable where everything that writes one writes it in one of two ways. A level name is a closed set of six words, and listing the spellings is honest about what is actually accepted rather than folding a case nobody sends.

WARNING is taken as well as WARN because half the world writes it.

Log

impl Log

none

pub fn none() -> Log

A logger that records nothing, as cheaply as possible.

The default, and it has to be nearly free. If logging costs when it is off it gets turned off, and then it does not exist. This reads no argument and builds no string; with Perceus the list the caller passed is released at the call.

json

pub fn json(minimum: Severity) -> Log

A logger that writes one JSON object per line to standard error, at minimum and above.

Stamped from the real clock. Log::json_using takes one instead, which is what a test wants: a fixed clock makes the output byte-for-byte predictable, and a log line with a real timestamp in it cannot be compared against anything.

json_using

pub fn json_using(minimum: Severity, clock: Clock) -> Log

json, reading the time from a clock the caller supplies.

The clock is a value here, not a requirement. An effect operation cannot ask for a capability — it runs wherever the effect is performed, not where the handler was built — so this holds the one it was given, the same way std::trace’s exporters hold theirs.

plain

pub fn plain(minimum: Severity) -> Log

A logger that writes a plain line to standard error, for a terminal.

The level, the message, then key=value for each attribute. For a small program whose log is read by the person who ran it; anything that ships its logs anywhere wants json.

Functions

trace

pub fn trace(message: String) ->() with { log: Log }

The finest detail: what somebody reading a transcript afterwards would want, and nobody wants while the program is behaving.

import std::log::{Log, trace};

fn charge(amount: Int, card: String) -> Int with { log: Log } {
  trace("authorizing ${amount} against ${card}");
  amount
}

debug

pub fn debug(message: String) ->() with { log: Log }

What a developer wants while working on this code.

import std::log::{Log, debug};

fn charge(amount: Int) -> Int with { log: Log } {
  debug("charging ${amount}");
  amount
}

info

pub fn info(message: String) ->() with { log: Log }

What an operator wants while the program is behaving.

import std::log::{Log, info};

fn charge(amount: Int) -> Int with { log: Log } {
  info("charged ${amount}");
  amount
}

warn

pub fn warn(message: String) ->() with { log: Log }

Something is wrong and the program is carrying on.

import std::log::{Log, warn};

fn charge(amount: Int) -> Int with { log: Log } {
  warn("the rate table is stale; charging ${amount} at yesterday's rate");
  amount
}

error

pub fn error(message: String) ->() with { log: Log }

Something is wrong and something did not happen.

import std::log::{Log, error};

fn charge(amount: Int) -> Int with { log: Log } {
  error("the acquirer refused ${amount}; nothing was charged");
  0
}

eprint

pub fn eprint(text: String) ->()

Writes a line to standard error.

The stream is the whole point. print writes a program’s answer, and an answer is what > out.txt is for. A diagnostic written there goes into the file with it, which is how a command-line tool ends up silently discarding the reason it failed.

Not an effect, for the same reason print is not one: it is the primitive the effect above is built out of, and a usage message printed before any capability is installed has nowhere to get one from.

eprint("usage: report <events.json>")