Logging

use std.log

type OrderPlaced: LogEvent {
    order_id: Int
    amount: Decimal
    secret card: String
}

fn main() {
    log.info(OrderPlaced(order_id: 7, amount: 499.00, card: "4242 4242 4242 4242"))
}

INFO OrderPlaced(order_id: 7, amount: 499.00, card: <secret>)

• type OrderPlaced: LogEvent makes the record an event. Only events can be logged: log.info("order placed") is a compile error (below).
• Each event is one line: the level, then the event as it prints. Every entry of a kind has the same fields, so logs can be searched and counted.
• A secret field is written as <secret>.

Logging plain text out of habit is refused, and the message shows the record to declare:

use std.log

fn main() {
    log.info("order placed")
}

error: `String` does not implement `LogEvent`: log events are records, so a log line can be searched by its fields. Declare one, as `type OrderPlaced: LogEvent { order_id: Int }`, and log that: `log.info(OrderPlaced(order_id: 7))` (spec 14.12)

Levels

Events below the lowest level written are left out. kavach.toml sets it; here only warnings and errors are written:

[package]
name = "shop"
version = "0.1.0"

[log]
level = "warn"

use std.log

type Started: LogEvent {
    port: Int
}

type Retrying: LogEvent {
    attempt: Int
}

type DiskFull: LogEvent {
    free_mb: Int
}

fn main() {
    log.debug(Started(port: 8080))
    log.info(Started(port: 8080))
    log.warn(Retrying(attempt: 2))
    log.error(DiskFull(free_mb: 12))
}

WARN Retrying(attempt: 2)ERROR DiskFull(free_mb: 12)

The same settings send lines to a file, which starts a new one at a size you choose, or to an OpenTelemetry collector. See Settings.

No capability needed

use std.log

type Refunded: LogEvent {
    order_id: Int
}

pub fn refund(order_id: Int) -> Int {
    log.info(Refunded(order_id: order_id))
    order_id
}

fn main() {
    print(refund(42))
}

INFO Refunded(order_id: 42)42

refund is pub and logs, yet has no uses: where events go is the owner's choice, not the code's, and the code can't read them back.

Traces

A trace follows one piece of work, such as a request, through the program and the services it calls. It is made of spans: log.span(name) { … } runs its block as one span, timed from its start to its end. The block is a plain block: see Blocks Given to a Call.

use std.log

fn main() ! Error {
    print(log.trace_id() ?? "no trace outside a span")
    log.span("request") {
        const id = log.trace_id() ?? ""
        print("trace id: {id.len()} hex digits")
        const header = log.traceparent() ?? ""
        print("traceparent: {header.len()} characters, starts {header.slice(0, 3)}")
        const task = spawn log.trace_id()
        print("a task keeps it: {(try task.wait()) == id}")
    }
    print(log.trace_id() ?? "no trace after it")

    const continued = log.span("next", from: "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") {
        log.trace_id() ?? ""
    }
    print(continued)
}

no trace outside a spantrace id: 32 hex digitstraceparent: 55 characters, starts 00-a task keeps it: trueno trace after it4bf92f3577b34da6a3ce929d0e0e4736

• log.trace_id() is the trace's id, 32 hexadecimal digits, or none outside a span: for an error page or a header in a reply.
• log.traceparent() is the span's W3C traceparent header, and from: continues the trace one names. Together they carry a trace over any connection: a queue, gRPC metadata, a file.
• A span inside another is its child. A task keeps the trace of the code that spawned it.
• Each event written inside a span carries the span's trace and span ids. A span whose block fails is marked as an error.
• HTTP joins traces with no code: http.serve runs each handler in a span that continues the caller's trace, and http.request sends it. The span is named by the method (GET), never the path, which can hold ids and tokens. See Serving.
• log.name_span(name) renames the current span, once the code knows what it is doing; outside a span it does nothing. Give it one of a few names, such as a route's pattern ("GET /orders/\{id}"), not text with ids in it.
• With [log.otlp] set, each span goes to the collector when it ends. Without it, spans are sent nowhere.

Metrics

Numbers a program counts or measures go to the collector every 10 seconds as OpenTelemetry metrics, when [log.otlp] is set. Without it, they are kept nowhere and cost almost nothing:

log.count("orders_placed", 1)
log.histogram("checkout_ms", Float(elapsed))

Each also takes attributes, a [String: String] map that is empty unless given. Each name and set of attributes is a series of its own, whatever order the attributes are written in:

use std.log

fn main() {
    const ms = 12.5
    log.histogram("checkout.duration_ms", ms, attributes: [
        "http.route": "/orders/\{id}",
        "http.response.status_code": "200",
    ])
    log.count("orders_paid", 1, attributes: ["method": "card"])  // one series
    log.count("orders_paid", 1)                                  // and another
    print("recorded: sent only when [log.otlp] is set")
}

recorded: sent only when [log.otlp] is set

Give attributes with few values, such as a route's pattern, a method or a status, never ids: each new value makes a new series to keep and send. Like events, spans and metrics need no capability.

Limits and sizes

Every limit in Kavach, on one page: Limits and Sizes.