--- title: 'Structured Logging' source: 'https://academia.sh/en/courses/go-applications/structured-logging' course: 'The Standard Library and Network Applications' language: en updated: '2026-09-14T10:59:31+00:00' license: 'CC BY-SA 4.0' objectives: - "Measures how many fields can be reliably extracted from the same event's plain-text and key-value log lines" - 'Shows that the key-value format is independent of field order, by searching by field name' - "Limits by showing that a field extracted from the log stays as text, and rebuilding it requires the reading side's own schema" --- # Structured Logging The same event is written to a log in two formats: plain text and a key-value based log. The key-value format is measured to carry field names even when the field order changes, preserving the parseability that plain text loses. The limiting measurement shows that even though field names are preserved, types are not: an integer also arrives as text, and rebuilding it requires the reading side's own schema. The previous lesson showed that a time value carries no field name when it turns into text, only producing a raw representation that can be inferred from position. This lesson asks the same boundary question about a log record: is it possible to also carry field names while writing an event to text, and what does carrying them change? The concept of structured logging itself — why logs are kept, what a level is, how a logging pipeline is built — was established in the Observability and Operations course and the Build, Testing and the Ecosystem course, and is not rebuilt here. This lesson's share is narrow: putting the same event's two representations side by side and measuring which representation leaves which field parseable. Where this distinction matters in practice is not the code writing the log, but the side reading it afterward. A log record is usually not read immediately by a human the moment it is written; it is accumulated, searched, filtered — when a search tool asks a question like "show records where count is greater than 10," that tool needs to know which word in the log line is "count." Plain text leaves this question to the human, while the key-value format gives the tool itself something to hold onto. **Determinism note:** the logged event's timestamp is the same fixed text as the previous lesson (`2026-08-23T10:00:00Z`); the real clock is not read in this lesson either. ## The Same Event, Two Formats The `Event` struct below carries a single event to be written to a log: a user name, a number, a success state, a timestamp. This event is turned into text with two separate functions — one builds a sentence in natural language, the other lays out field names one after another in `name=value` format. **SD13.** — The same `Event` value is printed in two formats, and how many parts each line splits into when divided by whitespace is counted. ```go // two-formats.go — the same event is written as plain text and as key-value package main import ( "fmt" "strings" ) type Event struct { User string Count int Success bool Time string } func plainText(e Event) string { return fmt.Sprintf("user %s performed %d unit operations, success=%v (%s)", e.User, e.Count, e.Success, e.Time) } func keyValue(e Event) string { return fmt.Sprintf("time=%s user=%s count=%d success=%t", e.Time, e.User, e.Count, e.Success) } func main() { event := Event{User: "alice", Count: 12, Success: true, Time: "2026-08-23T10:00:00Z"} plain := plainText(event) kv := keyValue(event) fmt.Println("plain text :", plain) fmt.Println("key-value :", kv) plainParts := strings.Fields(plain) kvParts := strings.Fields(kv) fmt.Println("plain text whitespace-separated part count :", len(plainParts)) fmt.Println("key-value whitespace-separated part count :", len(kvParts)) namedFields := 0 for _, part := range kvParts { if _, _, found := strings.Cut(part, "="); found { namedFields++ } } fmt.Println("named field count inside key-value :", namedFields) } ``` ``` plain text : user alice performed 12 unit operations, success=true (2026-08-23T10:00:00Z) key-value : time=2026-08-23T10:00:00Z user=alice count=12 success=true plain text whitespace-separated part count : 8 key-value whitespace-separated part count : 4 named field count inside key-value : 4 ``` The same four fields (user, count, success state, time) spread across eight separate whitespace-divided parts in the plain-text version — "12" and "unit" are separate parts, "operations," is one part together with its punctuation mark. Answering the question "what was the count" retroactively from this line requires knowing the sentence's syntax: which word position holds the number, where the punctuation falls. The key-value version instead splits the four fields into four parts, and each part carries its own name; the reading side does not have to know the sentence's structure, it only looks for the `=` sign. This difference looks small when reading a single log line by hand — a human understands the phrase "12 unit" from context. But a logging pipeline's real scale is a stream of thousands of lines, and the side reading that stream is often not a human, but a tool that filters or counts by field name. For such a tool, every sentence pattern in plain text is a separate special case: is the word "performed" always in the third position, or the fourth for some event types? In the key-value format this question is never asked, because what the tool looks for is a name, not a position. ## Order Independence A real-world property of a logging pipeline: the same event type can be written in different orders from different code paths — time then user in one place, the exact opposite in another. This difference is not a deliberate inconsistency; a logging call is usually laid out in the order the function obtains the values it needs, and this order varies by the calling function. In plain text this means the sentence changes completely; in the key-value format, as long as the field names stay fixed, the order remains unimportant. **SD14.** — The same event is printed with two different field orders; a search function finds the `count` field by name from both lines. ```go // order-independence.go — the key-value format is searched independent of field order package main import ( "fmt" "strings" ) type Event struct { User string Count int Success bool Time string } func keyValueOrdered(e Event, order []string) string { parts := make([]string, 0, len(order)) for _, name := range order { switch name { case "time": parts = append(parts, "time="+e.Time) case "user": parts = append(parts, "user="+e.User) case "count": parts = append(parts, fmt.Sprintf("count=%d", e.Count)) case "success": parts = append(parts, fmt.Sprintf("success=%t", e.Success)) } } return strings.Join(parts, " ") } func findField(log, name string) (string, bool) { for _, part := range strings.Fields(log) { key, value, found := strings.Cut(part, "=") if found && key == name { return value, true } } return "", false } func main() { event := Event{User: "alice", Count: 12, Success: true, Time: "2026-08-23T10:00:00Z"} line1 := keyValueOrdered(event, []string{"time", "user", "count", "success"}) line2 := keyValueOrdered(event, []string{"success", "count", "user", "time"}) fmt.Println("first code path's log :", line1) fmt.Println("second code path's log :", line2) count1, _ := findField(line1, "count") count2, _ := findField(line2, "count") fmt.Println("count field the same from both orders:", count1 == count2) } ``` ``` first code path's log : time=2026-08-23T10:00:00Z user=alice count=12 success=true second code path's log : success=true count=12 user=alice time=2026-08-23T10:00:00Z count field the same from both orders: true ``` `line1` and `line2` are completely different from each other as text — no field is in the same position. Yet `findField` finds the same `count` value from both, because what it looks for is a name, not a position. This search would not be possible in plain text: the only way to tell whether the word "12" is the count or some other number is to know the sentence's exact structure, and if two different code paths produce two different sentence structures, the same parser cannot work for both. ## When the Value Itself Contains a Space The measurement above assumed that none of the field values contain a space. `findField` only splits on whitespace with `strings.Fields`; when a value itself contains a space, this assumption breaks, and the result is not an error but a **silent truncation**. **SD15.** — The `user` field is given a two-word value (`"alice smith"`); the same `findField` function searches for both this field and the unaffected `count` field. ```go // spaced-value.go — when a value contains a space, the field is silently truncated package main import ( "fmt" "strings" ) func findField(log, name string) (string, bool) { for _, part := range strings.Fields(log) { key, value, found := strings.Cut(part, "=") if found && key == name { return value, true } } return "", false } func main() { logLine := fmt.Sprintf("time=2026-08-23T10:00:00Z user=%s count=%d success=%t", "alice smith", 12, true) fmt.Println("log line:", logLine) user, _ := findField(logLine, "user") fmt.Printf("extracted user field : %q (expected: %q)\n", user, "alice smith") count, _ := findField(logLine, "count") fmt.Printf("extracted count field : %q\n", count) } ``` ``` log line: time=2026-08-23T10:00:00Z user=alice smith count=12 success=true extracted user field : "alice" (expected: "alice smith") extracted count field : "12" ``` The `user` field is silently truncated to `"alice"` — the word "smith" is left on its own, as a part with no name, and `findField` does not return an error. The `count` field is not affected in this example, because the truncation before it changes the number of whitespace-separated parts, but the following fields' own `=` signs still sit in the right place — but this is by luck, not a guarantee of the format itself. The key-value format being named and order-independent never guarantees that values will not carry the separator character (a space, in this example) inside themselves; production systems that make this format genuinely reliable use a notation that quotes values and protects them with escape characters — this lesson does not show that, because the goal is not the format itself, but measuring the basic difference between unnamed plain text and named key-value. A notation that removes this fragility entirely was already measured in the Networking and Data Formats topic: JSON encodes every field with its name and with explicit boundaries (quotes, commas, curly braces), so a space inside a value never shifts any field. That measurement is not rebuilt here; what is emphasized here is that a simple `name=value` layout does not carry this guarantee on its own — being named is one thing, having explicit boundaries is another. ## Limiting Measurement: Field Names Are Preserved, Types Are Not The key-value format being order-independent and named shows that field names are preserved. But only the name is preserved; the field's own Go type (`int`, `bool`) is never written to the log, all of it turns into text. **SD16.** — The `count` field is extracted from the log and its type is read with `%T`; then code that only looks at the field name assumes the likely target type (`int`) with its own schema and rebuilds the value. ```go // type-loss.go — the field name is preserved, the type is not; rebuilding relies on the reader's own schema package main import ( "fmt" "strconv" "strings" ) func findField(log, name string) (string, bool) { for _, part := range strings.Fields(log) { key, value, found := strings.Cut(part, "=") if found && key == name { return value, true } } return "", false } func main() { logLine := "time=2026-08-23T10:00:00Z user=alice count=12 success=true" countText, found := findField(logLine, "count") fmt.Printf("count value extracted from the log: %q type=%T found=%t\n", countText, countText, found) countNum, parseErr := strconv.Atoi(countText) fmt.Printf("rebuilt with the schema (strconv.Atoi): type=%T value=%d noError=%t\n", countNum, countNum, parseErr == nil) successText, _ := findField(logLine, "success") _, wrongTypeErr := strconv.Atoi(successText) fmt.Println("reading the success field with the int schema gave an error:", wrongTypeErr != nil) } ``` ``` count value extracted from the log: "12" type=string found=true rebuilt with the schema (strconv.Atoi): type=int value=12 noError=true reading the success field with the int schema gave an error: true ``` The first line confirms the expected result on the topic's measurement axis: the value `findField` returns comes back from the log as a `string`, even though the `count` field is an `int` on the Go side — `%T` shows it as `string`. Because the field name sits in the log, `findField` finds the right line, but because the field's type is never written to the log, the reading side has to guess it again. The `strconv.Atoi` call makes this guess concrete: it converts the text to an `int`, and this time succeeds, because the calling side already knows the `count` field is a number — this knowledge does not come from the log, it comes from the contract of the code that writes the log. The last line shows this guess can be wrong: the `success` field is the text `"true"`, and trying to read it with an integer schema gives an error — the wrong schema comes not from the log itself, but from the reading code's assumption. This error is at least **explicit**: `strconv.Atoi` returns an error value, the program does not crash or silently produce the wrong number. But this explicitness only shows up when the wrong schema is actually tried; code that only looks at the log itself finds no marker anywhere that says in advance which field should be read with which schema. The answer to where this schema comes from is not in the log itself. The code calling `findField` does not learn that the `count` field is a number from the log line — it learns this by looking at the source of the code that writes the log, or from a contract document. As long as the two sides (writer and reader) share this contract, the system works correctly; when the contract changes (if `count` is one day converted to a decimal number), the log itself gives no notice of this at all — `strconv.Atoi` will also reject the new format as "not a valid integer," but it will not say why it changed. ## Summary - The same event turns into eight whitespace-separated parts as plain text and four as key-value; in the key-value format, all four parts arrive together with their name. - The key-value format is independent of field order: the same event written in two different orders gives the same value when searched by the same field name. - There is no reliable way to find a field by name in plain text; you have to know the sentence's exact structure, and that structure can change by code path. - A simple `name=value` layout can be silently truncated when a value itself contains a space; being named is not the same thing as having explicit boundaries. - Limiting measurement: the key-value format preserves field names but not their types — even an `int` field comes back as text, rebuilding it requires the reading side's own schema. - A wrong schema (trying to read a `bool` field as an `int`) does not pass silently, it is rejected with an explicit error — but this rejection only shows up once the wrong schema is actually tried. ## Next Step In this lesson, field names were preserved but types always turned into text; the reading side had to infer which field corresponds to which Go type from its own knowledge. This schema always sat outside the code, in human knowledge or in a contract document — the log itself never said anything like "this field is an integer." The next lesson, this topic's last lesson, measures a boundary where the type is reduced this time not to text, but to a narrow type set the standard library itself recognizes: what types can a row passing through a database driver arrive in, and what does the target type rebuild from that row, and how? This time the schema will not sit in text, but in the type of the target variable the caller hands to the `Scan` call — the role `strconv.Atoi` plays in this lesson will be taken on there by the standard library itself.