Wide-event structured logging for V. One rich JSON event per logical operation — built up over the operation's lifetime from any call depth, emitted as a single NDJSON line at the end.
Inspired by loggingsucks.com: instead of many thin log lines that must be correlated after the fact, each request or job emits exactly one event containing everything that happened.
Traditional logging emits one line per thing that happens:
[INFO] request started method=POST path=/api/orders
[INFO] db query table=orders duration_ms=12
[INFO] request finished status=200 duration_ms=15
Three lines to reconstruct one request. With wide events, the same information becomes a single line:
{"timestamp_ms":1778725478232,"level":"info","message":"http_request","service":"witch","version":"0.0.1","duration_ms":15,"outcome":"success","method":"POST","path":"/api/orders","user_id":1234,"status":200,"steps":[{"name":"db_query","table":"orders","duration_ms":12}]}Everything is queryable in one shot with jq, Loki, or any JSON-aware tool.
The module maintains a global map from thread ID → current scope. Field writers (str, int_, f64_, etc.) always write into the current thread's active scope — no logger or span object needs to be passed through the call stack. Nested scopes push/pop automatically so concurrent requests on different threads never interfere.
The module uses __global variables. Compile with:
v -enable-globals run .
v -enable-globals build .
v -enable-globals test trace/import trace
fn main() {
mut logger := trace.new_stdout_logger('my-service', '1.0.0')
trace.scope_begin(&logger, .info, 'http_request')
trace.str('method', 'POST')
trace.str('path', '/api/orders')
trace.int_('user_id', i64(1234))
trace.set_outcome('success')
trace.scope_end()
}Output:
{"timestamp_ms":1778725478232,"level":"info","message":"http_request","service":"my-service","version":"1.0.0","duration_ms":0,"outcome":"success","method":"POST","path":"/api/orders","user_id":1234}// stdout only
mut logger := trace.new_stdout_logger(service string, version string) Logger
// stdout + append to file
mut logger := trace.new_logger(service string, version string, file_path string) !Logger
// attach a sampler (see Samplers section)
logger.with_sampler(fn (e &trace.Event) bool { ... })
// flush and close the log file
logger.close()Logger is @[heap] — always pass it by pointer (&logger).
Every event needs an open scope. Fields written outside a scope are silently dropped.
trace.scope_begin(&logger, .info, 'operation_name')
// ... do work, call helpers, write fields ...
trace.scope_end() // emits the eventtrace.with_event(&logger, .info, 'operation_name', fn () {
trace.str('key', 'value')
})scope_end (or returning from with_event) automatically calculates duration_ms from the moment scope_begin was called.
Calling scope_begin inside an already-open scope pushes a new event onto the stack. scope_end pops it and emits it, then restores the outer scope. The outer scope continues accumulating its own fields.
trace.scope_begin(&logger, .info, 'outer')
trace.str('outer_key', 'a')
trace.scope_begin(&logger, .debug, 'inner') // push
trace.str('inner_key', 'b')
trace.scope_end() // emits inner event, pops
trace.str('outer_key2', 'c')
trace.scope_end() // emits outer eventCall these from anywhere on the current thread — including helper functions that have no reference to the logger or scope.
trace.str(key string, val string)
trace.int_(key string, val i64)
trace.u64_(key string, val u64)
trace.f64_(key string, val f64)
trace.bool_(key string, val bool)int_, u64_, bool_, and f64_ have trailing underscores to avoid clashing with V's built-in type names.
Structured fields that carry semantic meaning for log pipelines and dashboards:
trace.set_level(level trace.Level) // override level after scope_begin
trace.set_outcome(outcome string) // e.g. "success", "failure", "timeout"
trace.set_error(error_type string, error_code string)
trace.set_trace_id(id string) // distributed tracing correlation
trace.set_request_id(id string)
trace.set_event_id(id string)All metadata fields are omitted from the JSON output when empty.
Steps record named sub-operations within an event as a JSON array. Each step can carry its own typed fields.
trace.step('validate_input')
trace.step_str('schema', 'orders_v2')
trace.step_bool('passed', true)
trace.step('nested step')
trace.step_str('nested schema', 'nested orders_v2')
trace.step_end()
trace.step('db_query')
trace.step_str('table', 'orders')
trace.step_int('rows', i64(1))
trace.step_end() // optional will auto end when no other stepsOutput fragment:
"steps":[
{"name":"validate_input","schema":"orders_v2","passed":true},
{"name":"db_query","table":"orders","rows":1}
]Step field writers — same types as top-level:
trace.step_str(key string, val string)
trace.step_int(key string, val i64)
trace.step_f64(key string, val f64)
trace.step_bool(key string, val bool)step_str / step_int / step_f64 / step_bool write into the most recently opened step. Calling them when no step is open is a no-op.
Timer measures wall-clock duration and writes key.duration_ms when .end() is called. If a step is currently open, the field goes onto the step; otherwise it goes onto the event.
fn handle_order(order_id int) {
trace.int_('order.id', i64(order_id))
t := trace.timer('db')
// ... database call ...
t.end() // writes "db.duration_ms": <elapsed>
}pub enum Level {
debug
info
warn
err // named "err" to avoid clash with V's built-in "error"
}Serialised in JSON as "debug", "info", "warn", "error".
A sampler is a function fn (&Event) bool attached to a Logger. It runs at emit time; returning false suppresses the event entirely.
// built-in helpers
trace.keep_all // always emit
trace.drop_all // never emit
// custom — drop debug events in production
logger.with_sampler(fn (e &trace.Event) bool {
return e.level != .debug
})
// custom — sample high-volume events
logger.with_sampler(fn (e &trace.Event) bool {
if e.message == 'health_check' {
return rand.intn(100) or { 0 } == 0 // 1 %
}
return true
})No sampler attached → all events are emitted.
Every emitted event is one NDJSON line (no trailing comma, no wrapping array). Fields are written in this order:
| Field | Type | Always present |
|---|---|---|
timestamp_ms |
integer | yes |
level |
string | yes |
message |
string | yes |
service |
string | if non-empty |
version |
string | if non-empty |
event_id |
string | if non-empty |
trace_id |
string | if non-empty |
request_id |
string | if non-empty |
duration_ms |
integer | yes (auto-calculated) |
outcome |
string | if non-empty |
error_type |
string | if non-empty |
error_code |
string | if non-empty |
steps |
array | if any steps |
| (custom fields) | any | in insertion order |
String values have ", \, \n, \r, \t escaped. Numbers and booleans are unquoted.
import trace
fn charge_card(amount f64) {
t := trace.timer('stripe')
trace.step('stripe_charge')
trace.step_f64('amount_usd', amount)
// ... call stripe ...
trace.step_bool('captured', true)
t.end()
}
fn handle_checkout(user_id int, cart_total f64) {
trace.int_('user_id', i64(user_id))
trace.f64_('cart_total', cart_total)
charge_card(cart_total)
trace.set_outcome('success')
trace.int_('status', i64(200))
}
fn main() {
mut logger := trace.new_stdout_logger('shop', '2.1.0')
trace.scope_begin(&logger, .info, 'http_request')
trace.str('method', 'POST')
trace.str('path', '/checkout')
handle_checkout(42, 99.99)
trace.scope_end()
}Output (pretty-printed for readability):
{
"timestamp_ms": 1778725478232,
"level": "info",
"message": "http_request",
"service": "shop",
"version": "2.1.0",
"duration_ms": 14,
"outcome": "success",
"steps": [
{
"name": "stripe_charge",
"amount_usd": 99.99,
"captured": true,
"stripe.duration_ms": 12
}
],
"method": "POST",
"path": "/checkout",
"user_id": 42,
"cart_total": 99.99,
"status": 200
}mut logger := trace.new_logger('shop', '2.1.0', '/var/log/shop.ndjson') or {
eprintln('failed to open log file: ${err}')
exit(1)
}
defer { logger.close() }Events are written to stdout and the file. The file is opened in append mode so restarts do not truncate existing logs.