ktm v0.28.3

Logging

Write what a program does to stderr, to stdout or to a file, with the standard library's log module. This guide starts with one line and adds a step at a time: levels, a level from the environment, a log file, where each line came from, rotation, a second log of your own, threads, and the access log of an HTTP server. Every step is a whole program you can build and run.

What you need

Any ktm. log is part of the standard library, so there is nothing to fetch. Every program in this guide is one file, app.ktm, built and run like this:

ktm app.ktm -o app
./app

The times in the outputs below are the ones from the runs that made this guide. Yours are the time you run it.

The first lines

import log;

i32 main() {
    log.info("starting, version %s", "1.4.0");
    log.debug("this line is not written: debug is below the default level");
    log.warn("disk %d%% full", 91);
    log.error("can't reach %s: %s", "db.internal:5432", "connection refused");
    return 0;
}
ktm app.ktm -o app
./app
2026-10-16T02:23:59.539Z INFO  starting, version 1.4.0
2026-10-16T02:23:59.539Z WARN  disk 91% full
2026-10-16T02:23:59.539Z ERROR can't reach db.internal:5432: connection refused

The lines go to stderr, so they stay out of what the program prints on stdout. The shell sends them wherever you want:

./app 2> app.err
cat app.err
2026-10-16T02:23:59.541Z INFO  starting, version 1.4.0
2026-10-16T02:23:59.541Z WARN  disk 91% full
2026-10-16T02:23:59.541Z ERROR can't reach db.internal:5432: connection refused

Levels

Use debug for detail you need only while hunting a bug, info for what the program is doing, warn for something wrong that it got past, and error for something it couldn't do. log.setLevel changes which of them are written. A common way to choose is an environment variable, so the same build can be quiet in production and chatty while you look into a problem:

import log, proc, str;

/* The level LOG_LEVEL names (debug, info, warn or error); info when it is
 * unset or something else */
log.Level levelFromEnv() {
    scoped String v = proc.getenv("LOG_LEVEL");
    if (str.equals(v[0:], "debug")) { return log.Level.debug; }
    if (str.equals(v[0:], "warn")) { return log.Level.warn; }
    if (str.equals(v[0:], "error")) { return log.Level.error; }
    return log.Level.info;
}

i32 main() {
    log.setLevel(levelFromEnv());
    log.debug("config loaded from %s", "/etc/app.conf");
    log.info("starting");
    log.warn("cache is cold");
    log.error("payment provider timed out");
    return 0;
}
ktm app.ktm -o app
./app
2026-10-16T02:24:08.546Z INFO  starting
2026-10-16T02:24:08.546Z WARN  cache is cold
2026-10-16T02:24:08.546Z ERROR payment provider timed out
LOG_LEVEL=debug ./app
2026-10-16T02:24:08.547Z DEBUG config loaded from /etc/app.conf
2026-10-16T02:24:08.547Z INFO  starting
2026-10-16T02:24:08.547Z WARN  cache is cold
2026-10-16T02:24:08.547Z ERROR payment provider timed out
LOG_LEVEL=error ./app
2026-10-16T02:24:08.548Z ERROR payment provider timed out

Logging to a file

log.setup sets the default logger up from a log.Options: the one log.info and the others write to. Start from log.options(), which holds the defaults, and change what you need. Here the lines go to a file, with the file, line and function of each call:

import log;

void loadConfig() {
    log.info("config loaded");
}

void connect(u8 *host) {
    log.warn("%s is slow to answer", host);
}

i32 main() {
    log.Options o = log.options();
    o.path = "app.log";
    o.showFile = true;
    o.showFunc = true;
    log.setup(&o);
    defer log.shutdown();

    log.info("starting");
    loadConfig();
    connect("db.internal");
    log.error("query failed:\nSELECT * FROM users\nno such table: users");
    return 0;
}
ktm app.ktm -o app
./app
cat app.log
2026-10-16T02:24:13.683Z INFO  app.ktm:19 main:    starting
2026-10-16T02:24:13.684Z INFO  app.ktm:4 loadConfig: config loaded
2026-10-16T02:24:13.684Z WARN  app.ktm:8 connect:    db.internal is slow to answer
2026-10-16T02:24:13.684Z ERROR app.ktm:22 main:      query failed:\nSELECT * FROM users\nno such table: users

Stdout, for containers

Docker, Kubernetes and systemd collect what a program writes to stdout and stderr. A program run by one of them usually logs to stdout and has no file. o.toStdout without a path does that:

import log;

i32 main() {
    log.Options o = log.options();
    o.toStdout = true;
    log.setup(&o);
    defer log.shutdown();

    log.info("to stdout, for a container or a service manager to collect");
    return 0;
}
ktm app.ktm -o app
./app
2026-10-16T02:25:08.605Z INFO  to stdout, for a container or a service manager to collect

With a path as well, every line goes to the file and to stdout:

import log;

i32 main() {
    log.Options o = log.options();
    o.path = "app.log";
    o.toStdout = true;
    log.setup(&o);
    defer log.shutdown();

    log.info("written to app.log and to stdout");
    return 0;
}
ktm app.ktm -o app
./app
cat app.log
2026-10-16T02:24:20.965Z INFO  written to app.log and to stdout
2026-10-16T02:24:20.965Z INFO  written to app.log and to stdout

The first line is the one on stdout, the second the one cat shows from the file. A program that also prints with printf keeps its output and its log lines in the order it wrote them.

Shutting down

log.shutdown() closes the default logger. After it, log.info and the others write to stderr again, at the level the closed one had. Defer it in main, so it runs when the program ends. Deferred anywhere else, it runs too early:

import log;

void work() {
    log.Options o = log.options();
    o.path = "app.log";
    log.setup(&o);
    defer log.shutdown();
    log.info("working");
}

i32 main() {
    work();
    log.info("done");
    return 0;
}
ktm app.ktm -o app
./app
cat app.log
log: a line logged after log.shutdown() at app.ktm:13 goes to stderr (was the shutdown deferred in an inner block?)
2026-10-16T02:24:21.020Z INFO  done
2026-10-16T02:24:21.020Z INFO  working

The shutdown ran when work returned, so done went to stderr instead of app.log. The first line after a shutdown says where it came from, once. Move log.setup and the deferred log.shutdown into main to fix it.

When the file can't be opened

log.setup throws log.ERR_LOG when it can't open the file, with the reason. The logger that was there before stays, so a program can say what went wrong and keep going on stderr:

import log;

i32 main() {
    log.Options o = log.options();
    o.path = "/var/log/app/app.log";
    try {
        log.setup(&o);
    } catch (Error e) {
        log.error("%s; logging to stderr", e.message);
    }
    log.info("starting");
    return 0;
}
ktm app.ktm -o app
./app
2026-10-16T02:24:21.080Z ERROR log.open: can't open /var/log/app/app.log: No such file or directory; logging to stderr
2026-10-16T02:24:21.080Z INFO  starting

The log module doesn't make directories. Make /var/log/app when the program is installed, owned by the user it runs as. Without the try, the error stops the program at start-up with an uncaught error report, which is also a fine choice for a service that must have its log.

A write that fails later, on a full disk for example, doesn't stop the program either. The line is dropped and counted in the logger's failed field: log.logger().failed.

Rotation

A log file of a program that runs for months grows without end. o.maxBytes starts a new file before a line would take the current one past that size, and o.keep says how many old files to keep:

import log;

i32 main() {
    log.Options o = log.options();
    o.path = "app.log";
    o.maxBytes = 1000;   /* small, to see it rotate: use megabytes for real */
    o.keep = 3;
    log.setup(&o);
    defer log.shutdown();

    for (i64 i = 1; i <= 100; i++) {
        log.info("request %d done", i);
    }
    return 0;
}
ktm app.ktm -o app
./app
wc -c app.log*
 753 app.log
 987 app.log.1
 987 app.log.2
 987 app.log.3
3714 total
head -1 app.log.3
tail -1 app.log
2026-10-16T02:24:25.721Z INFO  request 22 done
2026-10-16T02:24:25.721Z INFO  request 100 done

A logger of your own

Some lines belong in a log of their own: an audit trail of money moving, a slow-query log. log.open makes a separate log.Logger from the same Options. Its methods are the same four calls:

import log;

/* Code that takes the Logger to write to */
void transfer(log.Logger *audit, u8 *from, u8 *to, i64 cents) {
    log.debug("transfer %s -> %s", from, to);
    audit.info("transfer from=%s to=%s cents=%d", from, to, cents);
}

i32 main() {
    log.Options o = log.options();
    o.path = "audit.log";
    log.Logger *audit = log.open(&o);
    defer audit.close();

    log.info("starting");
    transfer(audit, "ann", "bob", 2500);
    transfer(audit, "bob", "cat", 120);
    transfer(log.logger(), "dan", "eve", 990);   /* the default logger: stderr */

    audit.level = log.Level.warn;
    transfer(audit, "cat", "ann", 75);      /* below warn: not in audit.log */
    return 0;
}
ktm app.ktm -o app
./app
2026-10-16T02:25:07.408Z INFO  starting
2026-10-16T02:25:07.408Z INFO  transfer from=dan to=eve cents=990
cat audit.log
2026-10-16T02:25:07.408Z INFO  transfer from=ann to=bob cents=2500
2026-10-16T02:25:07.408Z INFO  transfer from=bob to=cat cents=120

Threads

Several threads can share one logger. Set o.threadSafe on it:

import log, thread;

struct Job {
    i64 id;
};

void worker(Job *job) {
    for (i64 i = 1; i <= 10000; i++) {
        log.info("worker %d: item %d", job.id, i);
    }
}

i32 main() {
    log.Options o = log.options();
    o.path = "app.log";
    o.threadSafe = true;
    log.setup(&o);
    defer log.shutdown();

    Job jobs[4];
    thread.Thread threads[4];
    for (i64 i = 0; i < 4; i++) {
        jobs[i].id = i + 1;
        threads[i] = thread.spawn(&worker, &jobs[i]);
    }
    for (i64 i = 0; i < 4; i++) {
        threads[i].join();
    }
    log.info("all workers done");
    return 0;
}
ktm app.ktm -o app
./app
wc -l app.log
tail -1 app.log
40001 app.log
2026-10-16T02:24:40.138Z INFO  all workers done

An HTTP server's access log

net.http writes through the default logger. accessLog in the server's Options adds an info line per request, and a handler that throws is logged as an error. The server answers on several threads, so the logger is thread safe:

import log, net.http;

const i64 ERR_NO_USER = 1;

void hello(http.Writer *w, http.Request *r) {
    u8[] name = r.query("name");
    if (!name.len) { name = "world"; }
    w.text(200, "hello, %s\n", name);
}

void order(http.Writer *w, http.Request *r) {
    log.warn("order %s: payment declined", r.param("id"));
    w.text(402, "payment declined\n");
}

void crash(http.Writer *w, http.Request *r) {
    throw(ERR_NO_USER, "no user %s", r.param("id"));
}

i32 main() {
    log.Options lo = log.options();
    lo.path = "access.log";
    lo.threadSafe = true;      /* the server answers on several threads */
    log.setup(&lo);
    defer log.shutdown();

    http.Mux mux;
    mux.handle("GET /hello", &hello);
    mux.handle("POST /orders/{id}", &order);
    mux.handle("GET /users/{id}", &crash);

    http.Options o;
    o.accessLog = true;
    log.info("listening on :8080");
    return http.listen(8080, &mux, null, &o);
}

Run it and send it a few requests from a second terminal:

ktm app.ktm -o app
./app
curl 'localhost:8080/hello?name=ada'
curl -X POST localhost:8080/orders/17
curl localhost:8080/users/7
curl localhost:8080/nope

Stop the server with Ctrl+C, then read the log:

cat access.log
2026-10-16T02:25:07.492Z INFO  listening on :8080
2026-10-16T02:25:07.998Z INFO  GET /hello?name=ada 200 11 0.006ms
2026-10-16T02:25:08.004Z WARN  order 17: payment declined
2026-10-16T02:25:08.004Z INFO  POST /orders/17 402 17 0.012ms
2026-10-16T02:25:08.010Z ERROR http: GET /users/7: the handler threw 0x1 at app.ktm:17: no user 7
2026-10-16T02:25:08.010Z INFO  GET /users/7 500 33 0.020ms
2026-10-16T02:25:08.016Z INFO  GET /nope 404 21 0.003ms

Reference

CallWhat it does
log.debug(fmt, ...), log.info, log.warn, log.errorone line on the default logger, formatted like printf
log.setLevel(level)the default logger's level, for the calls from now on
log.options()Options with the defaults: stderr, info, no file or function, no rotation
log.setup(&o)sets the default logger up from o; closes the one before; throws log.ERR_LOG
log.shutdown()closes the default logger; later lines go to stderr
log.logger()the default logger, as a log.Logger *
log.open(&o)a Logger of its own; throws log.ERR_LOG
lg.debug(fmt, ...), lg.info, lg.warn, lg.errorone line on that logger
lg.close()closes its file and frees it
OptionDefaultWhat it does
pathnullthe file to append to; null writes to stderr
toStdoutfalsestdout instead of stderr, or as well as the file
levellog.Level.infothe least important level written
showFilefalsethe call's file name and line
showFuncfalsethe function the call is in
maxBytes0rotate before the file would pass this size; 0 never
keep0how many rotated files to keep (path.1 is the newest)
threadSafefalsea lock around each line, for a logger threads share

A log.Logger has two fields to read: level, which can also be set, and failed, the lines a failed write dropped.

Rules of thumb