Usage Guide

A comprehensive guide to using LoggerLogfmt for structured logging in Elixir applications.

Table of Contents

• Quick Start
• Configuration
• Format Options
• Metadata Handling
• Timestamp Formats
• Advanced Usage
• Best Practices

Quick Start

# Add to mix.exs
{:logger_logfmt, "~> 1.0"}

# Configure in config/config.exs
config :logger, :console,
  format: {Logger.Backends.Logfmt, :format},
  metadata: :all

# Use in your code
require Logger
Logger.info("Application started")

Configuration

Basic Configuration

# config/config.exs
config :logger, :console,
  format: {Logger.Backends.Logfmt, :format},
  metadata: [:request_id, :user_id, :module]

Complete Configuration

config :logger, :console,
  format: {Logger.Backends.Logfmt, :format},
  metadata: :all

config :logger, :logfmt,
  # Which fields to include in output
  format: [:timestamp, :level, :message, :metadata],

  # Metadata filtering
  metadata: [:request_id, :user_id],
  mode: :whitelist,

  # Timestamp configuration
  timestamp_format: :iso8601

Environment-Specific Configuration

# config/dev.exs
config :logger, :logfmt,
  format: [:timestamp, :level, :message, :file, :line, :metadata],
  mode: :blacklist,
  metadata: [:password]  # Exclude sensitive fields

# config/prod.exs
config :logger, :logfmt,
  format: [:timestamp, :level, :message, :node, :metadata],
  timestamp_format: :iso8601,
  mode: :whitelist,
  metadata: [:request_id, :user_id, :trace_id]

Format Options

Available Fields

Customizing Format

# Minimal format
config :logger, :logfmt,
  format: [:level, :message]
# Output: level=info message="Hello"

# Development format with source location
config :logger, :logfmt,
  format: [:timestamp, :level, :message, :file, :line, :metadata]
# Output: timestamp="..." level=info message="Hello" file="lib/app.ex" line=25

# Production format with node info
config :logger, :logfmt,
  format: [:timestamp, :level, :node, :message, :metadata]
# Output: timestamp="..." level=info node="app@server1" message="Hello"

Metadata Handling

Whitelist Mode

Only include specified metadata keys:

config :logger, :logfmt,
  metadata: [:request_id, :user_id, :trace_id],
  mode: :whitelist

# Usage
Logger.info("Request handled",
  request_id: "abc123",
  user_id: 42,
  internal_data: "ignored"  # Not included
)
# Output: ... request_id=abc123 user_id=42

Blacklist Mode

Include all metadata except specified keys:

config :logger, :logfmt,
  metadata: [:password, :token, :credit_card],
  mode: :blacklist

# Usage
Logger.info("User authenticated",
  user_id: 42,
  password: "secret",  # Excluded
  email: "user@example.com"
)
# Output: ... user_id=42 email="user@example.com"

Dynamic Metadata

# Set metadata for current process
Logger.metadata(request_id: "abc123")

# All subsequent logs include this metadata
Logger.info("Processing request")
# Output: ... request_id=abc123

Logger.info("Request complete")
# Output: ... request_id=abc123

Nested Metadata

Logger.info("User action",
  user: %{id: 123, name: "Alice"},
  action: "login"
)
# Output: ... user.id=123 user.name=Alice action=login

Timestamp Formats

Elixir Format (Default)

config :logger, :logfmt,
  timestamp_format: :elixir

# Output: timestamp="2024-01-15 10:30:45.123"

ISO 8601 Format

config :logger, :logfmt,
  timestamp_format: :iso8601

# Output: timestamp="2024-01-15T10:30:45.123"

Unix Epoch Format

config :logger, :logfmt,
  timestamp_format: :epoch_time

# Output: timestamp=1705315845

Advanced Usage

Struct Values

Struct values are encoded in one of two ways, depending on whether the struct implements the String.Chars protocol:

• If it does, the value is encoded via to_string/1.
• Otherwise, it's encoded like a map: as nested dot-notation keys, with __struct__ stripped.

defmodule MyApp.Money do
  defstruct [:amount, :currency]
end

defimpl String.Chars, for: MyApp.Money do
  def to_string(%{amount: amount, currency: currency}), do: "#{amount} #{currency}"
end

Logger.info("Charged card", total: %MyApp.Money{amount: 12.5, currency: "EUR"})
# Output: ... total="12.5 EUR"

defmodule MyApp.Address do
  defstruct [:city, :zip]
end

Logger.info("Shipping to", address: %MyApp.Address{city: "Berlin", zip: "10115"})
# Output: ... address.city=Berlin address.zip=10115

DateTime and NaiveDateTime are special-cased ahead of this rule and always use the timestamp formatting described below, regardless of whether they implement String.Chars.

DateTime and NaiveDateTime Values

DateTime and NaiveDateTime values in metadata are handled specially with the metadata_timestamp_format option:

config :logger, :logfmt,
  metadata_timestamp_format: :epoch_time  # default

Logger.info("Event", timestamp: DateTime.utc_now())
# Output: ... timestamp=1705318245

The time unit for epoch timestamps is auto-detected from the key suffix:

# Seconds (default)
Logger.info("Event", created_at: DateTime.utc_now())
# Output: ... created_at=1705318245

# Milliseconds
Logger.info("Event", created_at_ms: DateTime.utc_now())
# Output: ... created_at_ms=1705318245123

# Microseconds
Logger.info("Event", created_at_us: DateTime.utc_now())
# Output: ... created_at_us=1705318245123456

# Nanoseconds
Logger.info("Event", created_at_ns: DateTime.utc_now())
# Output: ... created_at_ns=1705318245123456000

Log Level Formatting

Logger.debug("Debug message")
# Output: ... level=debug ...

Logger.info("Info message")
# Output: ... level=info ...

Logger.warning("Warning message")
# Output: ... level=warning ...

Logger.error("Error message")
# Output: ... level=error ...

Special Characters

Values with special characters are automatically quoted and escaped:

Logger.info("User search", query: "hello world")
# Output: ... query="hello world"

Logger.info("Path accessed", path: "/api/users?name=John&age=30")
# Output: ... path="/api/users?name=John&age=30"

Logger.info("Quote test", message: "He said \"hello\"")
# Output: ... message="He said \"hello\""

List Values

Logger.info("Multiple items", tags: [:urgent, :important])
# Output: ... tags="[:urgent, :important]"

Empty and Nil Values

Logger.info("Test", value: nil, empty: "")
# Output: ... value="" empty=""

Best Practices

1. Consistent Metadata Keys

# Good - consistent naming
Logger.metadata(request_id: request_id, user_id: user_id)

# Avoid - inconsistent naming
Logger.metadata(reqId: req_id, userId: user_id)

2. Structured Error Logging

# Good - structured error info
Logger.error("Database error",
  error_type: "connection_timeout",
  error_message: "Failed to connect",
  retry_count: 3
)

# Avoid - unstructured
Logger.error("Database error: connection_timeout, Failed to connect, 3 retries")

3. Request Context

defmodule MyApp.RequestLogger do
  def with_context(conn, fun) do
    Logger.metadata(
      request_id: conn.assigns.request_id,
      user_id: conn.assigns[:current_user_id],
      path: conn.request_path,
      method: conn.method
    )

    result = fun.()

    Logger.metadata(
      request_id: nil,
      user_id: nil,
      path: nil,
      method: nil
    )

    result
  end
end

4. Performance Metrics

def process_request(request) do
  start_time = System.monotonic_time(:millisecond)

  result = do_process(request)

  duration = System.monotonic_time(:millisecond) - start_time

  Logger.info("Request processed",
    duration_ms: duration,
    status: :success
  )

  result
end

5. Sensitive Data Protection

# Configure blacklist for sensitive fields
config :logger, :logfmt,
  mode: :blacklist,
  metadata: [:password, :token, :api_key, :credit_card, :ssn]

# Or sanitize before logging
defp sanitize_user(user) do
  %{id: user.id, email: mask_email(user.email)}
end

Logger.info("User created", user: sanitize_user(user))

6. Log Levels Appropriately

# Debug - detailed development info
Logger.debug("Cache lookup", key: key, hit: hit?)

# Info - normal operations
Logger.info("User logged in", user_id: user_id)

# Warning - unexpected but handled
Logger.warning("Rate limit approaching", current: count, limit: max)

# Error - failures requiring attention
Logger.error("Payment failed", order_id: order_id, error: reason)

For more examples, see EXAMPLES.md and the README.