Skip to content

Folders and files

NameName
Last commit message
Last commit date

Latest commit

 

History

2 Commits
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 

Repository files navigation

yaklib/log

The fastest Go logger for workloads where every nanosecond counts. Async, writev(2)-batched, zero allocations, slog compatible.

Latency at data path

How long the calling goroutine is occupied per log at data path — bursts of 1500 records (message + 4 fields) to a real file, drain untimed between bursts (the app would be doing other work). Sync loggers pay encode + write(2) inline; here the caller only encodes and enqueues:

ns/log mean p50 p99 p99.9
yaklib/log (Event API) 34.1 29.1 89.4 118.8
yaklib/log (Field API) 58.1 48.2 147.3 174.8
phuslu/log 775.8 768.0 911.2 1902.2
rs/zerolog 845.1 839.4 941.9 1989.4
uber-go/zap 1152.3 1064.0 2007.3 2941.6
stdlib slog 1284.5 1268.3 1409.0 2461.8

With io.Discard instead of a file (no write(2) anywhere — pure encode vs encode+enqueue), the sync loggers recover most of the gap; the rest is their inline encoding vs our wire packing:

ns/log, p50 file io.Discard
yaklib/log (Event API) 29.1 29.3
yaklib/log (Field API) 48.2 50.3
phuslu/log 768.0 115.8
rs/zerolog 839.4 168.6
uber-go/zap 1064.0 320.7
stdlib slog 1268.3 536.1

Reproduce: cd benchmark && go test -run TestCallerLatency100 -v .

  • Fully async — the hot path only byte-packs the record and enqueues it; formatting and I/O happen on one background goroutine
  • Parking mailbox queue — producers lock-append-unlock, the consumer swaps the whole batch out under one lock and parks when idle (zero idle CPU — friendly to densely packed machines)
  • RDTSC timestamps — ~6ns at the call site, converted to wall time later by a calibrated clock; no time.Now in the hot path
  • Batched writev(2) — up to 1024 records per syscall instead of one write per line
  • Bounded memory, no loss — a fixed-capacity queue; producers block (never drop) when full, record sizes are capped so memory stays bounded
  • Zero dependencies, zero allocations on the log path; log/slog compatible via a bundled handler,.

Caveat — size limits. Record sizes are capped so queued memory stays bounded: string values and the message truncate at 8KB, keys at 1KB, 64 fields per record (slog records capped at 512KB total, excess attrs dropped). This is the price of bounded memory + no loss — pick two of {bounded memory, no loss, unlimited record size}. Long stack traces or payload dumps will be cut; raise the limits in wire.go if you need bigger records.

Design

goroutine A ─┐
goroutine B ─┼─► mailbox (batch-swap queue) ─► consumer: sort by TSC → format JSON → writev(2)
slog users  ─┘
  • Data path: stamp RDTSC (~6ns; invariant-TSC amd64, wall-clock fallback elsewhere), pack the record into a pooled scratch buffer (quill-style variable-length byte encoding — a 4-field record is ~60-130 contiguous bytes, so it touches 1-2 cache lines), append it to the mailbox under one mutex. No time.Now, no runtime.Callers, no formatting, no allocation.
  • The queue: a parking MPSC batch-swap mailbox. A channel send/receive each take the channel's internal runtime lock and the consumer receives one record per lock; the mailbox consumer instead swaps the whole batch out under one lock per batch and drains it lock-free. A producer wakes the parked consumer with a single token only when it was sleeping.
  • No loss: when the queue is full (QueueSize records, default 4096) the producer blocks until the consumer frees space. Nothing is ever dropped.
  • Consumer: swaps out the queued batch (≤1024 records per write cycle), sorts it by TSC so multi-goroutine output interleaves in time order (per-goroutine order is always exact), converts ticks via a frequency-calibrated clock, formats slog.JSONHandler-shaped JSON and writes the batch with one writev(2).

Usage

The simplest form — the package-level default logger (JSON to stderr, safe from any goroutine):

defer log.Close() // flush buffered records before exit

log.Info("request handled", log.Str("path", p), log.Int("status", 200))
log.Error("problem", log.Err(err))
log.Printf("stdlib-style: %d items", n) // Print/Printf/Println, Info level

To route the global slog — and, via slog's bridge, the stdlib "log" package — through this logger:

slog.SetDefault(slog.New(log.SlogHandler()))
slog.Info("now async", "k", 1)  // both go through the same queue/consumer
stdlog.Print("this too")

For your own output or level, create a Core:

core := log.New(os.Stderr, &log.Options{Level: log.LevelInfo})
defer core.Close() // flushes everything, stops the consumer

// goroutine-safe logger
l := core.Logger()
l.Info("request handled", log.Str("path", p), log.Int("status", 200))

// fastest — quill-macro-style static events: message, level and keys are
// registered ONCE (pre-rendered to JSON); a call packs values only
ev := log.NewEvent4[string, string, int, int64](l, log.LevelInfo,
	"request handled", "method", "path", "status", "bytes")
ev.Log("GET", "/api/v1/things", 200, 4096)

// standard slog front-end, same backend
slogger := slog.New(core.SlogHandler())

core.Flush() blocks until everything enqueued so far is written.

Benchmarks

Ryzen 7 8845HS, Go 1.26, 4-field record (2 strings + 2 ints), output /dev/null:

Scenario ns/op allocs
Event API, bursts of 100 73 (p50 73.7) 0
Event API, sustained end-to-end (format+writev incl.) 86 0
Event API, 2M records incl. final flush 76 0
Field API, bursts of 100 104 0
Field API, sustained end-to-end 106 0
Field API, 16 goroutines sustained 135 0
slog front-end, 4 attrs 370 0
msg-only, bursts 56 0

Caller cost (log.Caller())

Caller info is opt-in per log call, as a field — only the statements that ask for it pay for it:

l.Error("db query failed", log.Err(err), log.Caller())
// → ..."msg":"db query failed","error":"...","source":{"function":"main.handle","file":"...","line":42}

The call site captures one PC (runtime.Callers, evaluated in the caller's frame so it works at any wrapper depth); file/line resolution and formatting happen on the consumer, cached per call site:

ns/op allocs
Field API sustained, no Caller 106 0
Field API sustained + Caller() 224 0
stdlib slog.JSONHandler + AddSource 1391 6

+118ns only where used (~6x faster than stdlib doing the same job), zero cost everywhere else.

vs quill (C++)

Same machine, same record, quill v12.1 (g++ -O3 -march=native), default unbounded-blocking frontend, fair pattern (time + level + message only — no source location, no thread id, matching our output), FileSink → /dev/null. Both sides measured with identical methodology (wall-clock around 100-call bursts, drain untimed between):

Scenario quill (C++) yaklib/log (Event API)
bursts of 100 24.8 ns (p50 23.5) 92.3 ns (p50 73.7)
end-to-end 2M records incl. backend (text pattern) 299 ns 76 ns
end-to-end 2M records, JSON output both sides 644 ns 76 ns
msg-only burst100, p50 (data path only) 12.5 ns 43.7 ns

The JSON row uses quill's JsonFileSink with named placeholders — the closest quill gets to our output. Caveats both ways: quill's JSON adds file/line/thread/logger fields we don't emit, but renders values as strings ("status":"200") and the timestamp as raw nanoseconds, while we format typed values and RFC3339 time. Frontend numbers are format-independent (formatting is deferred on both sides).

Reading the burst rows: quill's backend busy-polls (~100% of one core when idle), so its frontend never pays a wake-up. We deliberately park the consumer instead (zero idle CPU on shared machines), so each burst's first log pays the scheduler wake-up — that, not queue mechanics, is the gap. End-to-end throughput is unaffected: 4× faster than quill (76 vs 299 ns), 8.5× on JSON. quill's default queue is also unbounded (it grew to 128MB during its enqueue test, no backpressure); our queue is bounded with blocking backpressure and no loss.

Tradeoffs

  • The consumer parks when idle: the first record after an idle period pays a scheduler wake-up. There is no busy-polling mode.
  • Timestamps come from the calibrated TSC (sub-millisecond accuracy), not time.Now at the call site. AddSource/ReplaceAttr are unsupported on the slog handler; caller info is opt-in per call via the log.Caller() field (stdlib-shaped "source" attr).
  • Any(...) values and slog KindAny/LogValuer attrs are JSON-encoded at the call site (records are byte-packed); prefer typed fields on hot paths.
  • Strings/values are truncated at 8KB, keys at 1KB, 64 fields per record.
  • Cross-goroutine ordering is exact within a drain cycle; per-goroutine order is always exact. Don't log after Close.
  • A write error on the output is fatal: the consumer panics with the error instead of silently dropping records — a logger with a broken sink cannot honor the no-loss contract any other way. Point it at storage that must not fail, or wrap your writer if you want different policy.

Passes testing/slogtest.TestHandler and go test -race.

About

The fastest Go logger for workloads where every nanosecond counts. Async, writev(2)-batched, zero allocations, slog compatible.

Resources

Stars

1 star

Watchers

0 watching

Forks

Releases

Packages

Contributors

Languages