1. Useful fields in structured logs
When you’re just starting out, it feels like the most important part of a log is the “human” phrase: “couldn’t add a task.” But as soon as you have a few commands, a few functions, and at least one user, it turns out you’re not looking for a phrase—you’re looking for an event: which operation? on which entity? how long did it take? And this is where fields win.
Imagine two situations.
The first: you have a log line.
// "task added: id=42 in 3ms"Looks nice, but it’s “just text.” The second: you have a log record where operation=task_add, id=42, duration=3ms. Now you can:
- quickly filter only operation=task_add;
- group by operation;
- find all events for a specific id;
- build stats by duration.
And the best part: you don’t need to “parse with your eyes” or use regexes to rip pieces out of a sentence.
In log/slog, fields are not decoration—they are the main point of structured logging. log/slog is part of the standard library, which means it’s not a “trendy external dependency,” but an official tool of the language.
Mini key dictionary: operation, id, duration
For logs to actually work, a simple principle matters: one meaning—one key. If today you write op, tomorrow operation, and the day after tomorrow action, searching turns into archaeology: “in which century did we log this and what did we call it?”
We lock in a minimal dictionary of three keys:
| Key | Type (usually) | Meaning | Example value |
|---|---|---|---|
|
|
“What we did” (a short operation name) | |
|
int or string | “What we did it to” (the entity identifier) | |
|
|
“How long it took” (operation execution time) | |
This doesn’t mean there can’t be other fields. It just means that if you start with exactly these three, your logs will already become far more useful—and then you’ll add fields intentionally, not “because we can.”
2. The operation field: a stable scenario name
operation is your “anchor” in the logs: a short label that answers “what was happening at all?” A good operation helps you quickly separate “a log about adding tasks” from “a log about listing tasks” without reading every message.
The practical goal of operation: so you can, either by eye (in text logs) or with a filter (in JSON logs), gather all records for a single scenario.
Example: logging the “add task” operation
Let’s start with the smallest example: one Info record with the operation field.
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
logger.Info(
"started command",
slog.String("operation", "task_add"),
)
// Example output (roughly):
// time=... level=INFO msg="started command" operation=task_add
}
What matters here is that "started command" is short text, and we don’t bake “which exact command” into the string—we put it into operation.
How to choose operation values
There are a few very practical rules that save you from chaos—even if you didn’t think about them in advance.
First, operation should be short and stable. If you generate operation dynamically (for example, "task_add_title_"+title), you’ll end up with an infinite number of different values, and filtering becomes meaningless.
Second, it’s convenient to choose operation as a “scenario name,” not a “function name.” You will rename and split functions, but the scenario “add a task” will remain “add a task.”
Third, don’t make operation a sentence. "adding new task to list" already looks like a message. operation is more of a label than text. Good options: "task_add", "task_done", "task_list".
3. The id field: correlating events with an entity
As soon as you have an entity (for us, it’s a “task” in a todo app), you almost always need to be able to answer: “which task is this about?” And this is where id becomes your best friend. Even if you’re not storing tasks in a database, you will still have some identifier: a number, a string, a UUID.
The main idea: id is the field that connects different events in the logs to the same entity.
Example: logging id for a created task
Suppose you already got taskID := 42. Let’s log it.
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
taskID := 42
logger.Info(
"task created",
slog.String("operation", "task_add"),
slog.Int("id", taskID),
)
// time=... level=INFO msg="task created" operation=task_add id=42
}Here we use slog.Int, because our id is numeric.
id as int or as string: which to choose
Within this course and for a small CLI, it’s usually convenient to start with int. It’s easier to parse from arguments, easier to print, and easier to compare.
But sometimes id is naturally a string—for example, "a7f3c9" or a UUID. Then it’s totally fine to do this:
logger.Info("task loaded",
slog.String("operation", "task_get"),
slog.String("id", "a7f3c9"),
)What matters more than “the type from the textbook” is type stability. If today you log id as a number and tomorrow as a string, log analysis becomes a surprise: “why are some records id=42, while others are id="042"?”
Multiple identifiers: when you need a second key
Yes, sometimes one id isn’t enough. But in this lecture we keep it minimal: one id.
If you need more identifiers, it’s better to introduce more specific keys: task_id, user_id, file_id. That’s the next level of the “field dictionary.” Here we’re practicing discipline: at least one identifier, but always.
4. The duration field: measuring execution time
If operation answers “what did we do?”, and id answers “what did we do it to?”, then duration answers “how long did it take?” And this field quickly becomes a favorite, because it catches performance regressions before anyone has time to file an angry issue saying “your app is slow.”
In Go, duration measurement is typically done via start := time.Now() and then time.Since(start). A nice nuance: time in Go can use the monotonic clock, so time.Since(start) works correctly even if the system wall clock “jumps.”
Example: duration as a field
package main
import (
"log/slog"
"os"
"time"
)
func main() {
logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
start := time.Now()
time.Sleep(10 * time.Millisecond)
logger.Info(
"operation finished",
slog.String("operation", "demo_sleep"),
slog.Duration("duration", time.Since(start)),
)
// time=... level=INFO msg="operation finished" operation=demo_sleep duration=10ms
}Notice: we do not write “finished in 10ms” in the message text. We put the duration into the duration field. The text stays stable.
Micro-pattern: a helper for duration
To avoid writing time.Since(start) by hand everywhere, it’s convenient to add a small helper that returns slog.Attr. Then the logging code becomes “cleaner to read.”
package main
import (
"log/slog"
"time"
)
func durationAttr(start time.Time) slog.Attr {
return slog.Duration("duration", time.Since(start))
}This helper is small, but it enforces discipline: you always name the field the same (duration), and you always put exactly a time.Duration there.
5. Wiring operation/id/duration into a CLI todo app
Now let’s assemble everything into pieces that look like real CLI code. We won’t build a complex architecture (that’s a separate topic), but we’ll do enough for you to feel: “ah, this is where these fields actually live.”
The scenario is: the add command creates a task and logs an event with operation, id, duration.
Model and a simple in-memory store
Let’s start with a mini store that yields an auto-incrementing ID.
package main
import "time"
type Task struct {
ID int
Title string
CreatedAt time.Time
}
type TaskStore struct {
nextID int
tasks []Task
}
func (s *TaskStore) Add(title string) Task {
s.nextID++
t := Task{ID: s.nextID, Title: title, CreatedAt: time.Now()}
s.tasks = append(s.tasks, t)
return t
}The code is intentionally simple: no files, no databases, no magic. Right now, logs matter more than durable task storage (otherwise we’d accidentally end up doing a lecture about persistence, and that’s a different series).
Setting up slog and a baseline logger
Let’s build a logger that writes to stderr so it doesn’t interfere with the command result.
package main
import (
"log/slog"
"os"
)
func newLogger() *slog.Logger {
return slog.New(slog.NewTextHandler(os.Stderr, nil))
}Yes, it’s “two lines.” And yes, that’s how it should be: a good logger is not necessarily “100 lines of configuration,” especially in an educational CLI.
The add command: logging operation, id, duration
Now for the fun part: we wrap command execution with time measurement and write a structured log.
package main
import (
"fmt"
"log/slog"
"time"
)
func runAdd(logger *slog.Logger, store *TaskStore, title string) {
start := time.Now()
task := store.Add(title)
// stdout: the command result contract
fmt.Printf("%d\n", task.ID) // for example: 1
// stderr: diagnostics (logs)
logger.Info(
"task added",
slog.String("operation", "task_add"),
slog.Int("id", task.ID),
slog.Duration("duration", time.Since(start)),
)
}Here you can clearly see the separation of responsibilities: fmt.Printf prints the “result” (the task ID), while logger.Info prints “what happened inside.”
Mini main: wiring everything into one program
Let’s make a very simple main that expects add <title>. We’re not using flag, because that’s a separate set of lectures about CLI design, and our task is log fields.
package main
import (
"fmt"
"os"
)
func main() {
logger := newLogger()
store := &TaskStore{}
if len(os.Args) < 3 || os.Args[1] != "add" {
fmt.Fprintln(os.Stderr, "usage: todo add <title>")
return
}
title := os.Args[2]
runAdd(logger, store, title)
}In a real program, you’d also handle errors, support more commands, store tasks between runs, and so on. But even on this “skeleton,” you can already see that operation, id, duration fit naturally into the code.
A small diagram: what we did
Sometimes it helps to see it as an event flow: where we measure time and where we write fields.
flowchart TD
A["User: todo add 'milk'"] --> B["runAdd: start := time.Now()"]
B --> C["store.Add -> Task{ID}"]
C --> D[stdout: print ID]
D --> E[stderr: logger.Info with operation/id/duration]
E --> F[End]
If you’ve ever hit the bug “why did my stdout output break?”, this kind of diagram fixes it fast: you literally see where the boundary is—“result contract” vs “diagnostics.”
6. Common mistakes when working with operation, id, duration
Mistake #1: operation changes every time and turns into an endless zoo.
It’s very tempting to make operation “pretty” and include details there: username, task title, filter parameters. As a result, you get thousands of unique operation values, and filtering by them loses meaning. operation should be short, from a small fixed set, and details should go into separate fields.
Mistake #2: id is sometimes a number, sometimes a string—and nobody knows how to search.
Today you log id as 42, tomorrow as "42", the day after tomorrow as "042". A human can still kind of cope, but automated log analysis starts to suffer. Pick a type and a format and keep it stable: if your id is an int, log it as slog.Int("id", id) everywhere.
Mistake #3: duration is hidden in the message text, and the field key is named t here, elapsed there, and time_ms somewhere else.
When duration is inside a string, you can’t aggregate and compare timings properly. When the key is named differently, you can’t reliably filter and build stats. Make duration a separate field and name it consistently: duration.
Mistake #4: measuring duration “randomly” and getting weird numbers.
A common bug is setting start := time.Now() too late (after half the work is already done) or too early (before parsing arguments, even though you only wanted to measure store work). There isn’t a single correct answer, but there is a rule: measure what you actually want to compare. And yes, time.Since(start) in Go is a solid baseline approach—it accounts for monotonic time.
Mistake #5: mixing stdout with logs, and then being surprised when tests and scripts break.
If you print “task ID” to stdout, and also add “DEBUG: task added…” right next to it, any user script that expected a single number suddenly gets a mess. Keep discipline: command result goes to stdout, logs go to stderr.
GO TO FULL VERSION