fix: first log message not in JSON format when JSON logging is configured #15

Closed
opened 2026-04-12 19:10:18 +02:00 by arcodange · 0 comments
Owner

Problem

When the application server is configured to use JSON log format (logging.json: true or DLC_LOGGING_JSON=true), the first few log messages emitted during config loading are still in human-readable console format instead of JSON.

Affected log messages

In pkg/config/config.go, LoadConfig() sets up a console writer before reading the config:

// Line 133-134 — console writer set unconditionally
consoleWriter := zerolog.ConsoleWriter{Out: os.Stderr}
log.Logger = log.Output(consoleWriter)

The following logs are then emitted while the logger is still in console format:

  • "Using custom config file path" (when DLC_CONFIG_FILE is set)
  • "Error reading config file, using defaults" (on config file error)
  • "Config file loaded" ← always emitted when a config file is found

The logger is only switched to JSON format after v.Unmarshal() at line 231, so by that point the "Config file loaded" message has already been written in text format.

Expected behaviour

All log messages, including those emitted during config loading, should respect the logging.json setting. If JSON logging is configured, every log line — including the very first — must be valid JSON.

Root cause

Classic chicken-and-egg: the logger format depends on the config, but the config load itself emits logs.

Proposed fix

Peek at the JSON logging setting before the first log is emitted, by:

  1. Checking the DLC_LOGGING_JSON env var directly via os.Getenv() (highest priority, zero cost)
  2. If not set, doing a minimal pre-read of the config file with a temporary viper instance to read only logging.json

This allows the logger to be configured in the correct format before any output is produced. The existing format-switch block after unmarshal becomes a no-op for stderr (idempotent) and is left in place for clarity.

## Problem When the application server is configured to use JSON log format (`logging.json: true` or `DLC_LOGGING_JSON=true`), the first few log messages emitted during config loading are still in human-readable console format instead of JSON. ### Affected log messages In `pkg/config/config.go`, `LoadConfig()` sets up a console writer **before** reading the config: ```go // Line 133-134 — console writer set unconditionally consoleWriter := zerolog.ConsoleWriter{Out: os.Stderr} log.Logger = log.Output(consoleWriter) ``` The following logs are then emitted while the logger is still in console format: - `"Using custom config file path"` (when `DLC_CONFIG_FILE` is set) - `"Error reading config file, using defaults"` (on config file error) - `"Config file loaded"` ← always emitted when a config file is found The logger is only switched to JSON format **after** `v.Unmarshal()` at line 231, so by that point the "Config file loaded" message has already been written in text format. ### Expected behaviour All log messages, including those emitted during config loading, should respect the `logging.json` setting. If JSON logging is configured, **every** log line — including the very first — must be valid JSON. ## Root cause Classic chicken-and-egg: the logger format depends on the config, but the config load itself emits logs. ## Proposed fix Peek at the JSON logging setting **before** the first log is emitted, by: 1. Checking the `DLC_LOGGING_JSON` env var directly via `os.Getenv()` (highest priority, zero cost) 2. If not set, doing a minimal pre-read of the config file with a temporary `viper` instance to read only `logging.json` This allows the logger to be configured in the correct format before any output is produced. The existing format-switch block after unmarshal becomes a no-op for stderr (idempotent) and is left in place for clarity.
Sign in to join this conversation.
No Label
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: arcodange/dance-lessons-coach#15