Logging is a fundamental tool in software development, providing insights into application operations by recording events as they occur. In Elixir, simple logging can be achieved with the IO module. For instance, IO.puts("This is a log message.") prints messages to the console, aiding in rapid development-phase debugging.

See the code

Read the docs

Using the Logger Module

For more sophisticated production-level logging, Elixir utilizes the Logger module. This module offers enhanced features such as log levels—info, debug, warning, error—which help categorize and filter messages. It also supports metadata inclusion and can direct logs to various destinations beyond the console.

Log Analysis with Grafana

Logs are invaluable in complex application environments, capturing crucial data about system operations and user interactions. These insights help teams detect and address issues promptly, improving system performance and user experience. Grafana stands out for its dynamic visualizations and advanced alerting features. It allows users to customize dashboards to reflect critical metrics and set alerts that help monitor system health proactively. Grafana does not actually manage logs, for that it needs an aggregation service.

Log Aggregation Essentials

Log aggregators consolidate logs from various sources into a single repository, simplifying access and management. These systems focus on enhancing the speed and efficiency of data retrieval, prioritizing consolidation over analysis.

Loki: Grafana’s Log Aggregator

Loki, designed to complement Grafana, is optimized for environments that produce large volumes of log data. While GameApp does not generate extensive data, Loki’s simplicity and open-source model make it easy to manage and scale. In development, Loki can be run locally using Docker, providing an accessible setup for testing and iteration. Production environments deploy Loki as a separate service, ensuring it can handle increased load without compromising performance.

See the configs

Custom Log Formatter for Loki

Loki works best with logs formatted as shallow key-value pairs. Below is a a custom formatter that converts Elixir’s logs to a more Loki friendly format.


defmodule GameApp.LogFormatter do
  def format(level, message, timestamp, metadata) do
    formatted_metadata = metadata
                         |> Enum.into(%{})
                         |> Map.put(:level, level)
                         |> Map.put(:message, to_string(message))
                         |> Map.put(:timestamp, format_timestamp(timestamp))
                         |> Enum.map_join(" ", fn {key, value} -> "#{key}=#{inspect(value)}" end)
    "#{formatted_metadata}\n"
  end

  defp format_timestamp({{year, month, day}, {hour, minute, second, millisecond}}) do
    with {:ok, naive_datetime} <- NaiveDateTime.new(year, month, day, hour, minute, second, {millisecond, 3}),
         {:ok, utc_datetime} <- DateTime.from_naive(naive_datetime, "Etc/UTC") do
      DateTime.to_iso8601(utc_datetime)
    else
      _error -> "Invalid timestamp"
    end
  end
end

Implementing Logger Backends

Logging operations must be fast and non-disruptive. In the beginning of a project, writing logs to the file system is reasonable strategy.

Setting Up Dependencies

Include logger_file_backend in the mix.exs file to enable file-based logging.

defp deps do
    [{:logger_file_backend, "~> 0.0.14"}]
end

Logger Configuration

To ensure proper logging in your Elixir application, set up the Logger module in config/config.exs. This setup uses shared metadata to maintain consistency and adhere to Credo’s code quality standards.

common_metadata = [
  :request_id,
  :trace_id,
  :span_id,
  :parent_span_id,
  :start_time,
  :end_time,
  :job_name,
  :worker,
  :attempt,
  :max_attempts,
  :queue,
  :status,
  :duration
]

config :logger, :file,
  path: "logs/prod.log",
  format: {GameApp.LogFormatter, :format},
  metadata: common_metadata,
  level: :info

config :logger,
  backends: [{LoggerFileBackend, :file}]

Common Metadata

Defines consistent metadata fields for every log entry, such as :trace_id and :start_time, to ensure uniformity across logs.

File Logger

Uses a custom formatter and directs logs to logs/prod.log for persistent storage.

Production Logger Backends

Configures the production environment to use only the file logger.

Development Logger Configuration

In the development environment, you can log to both the console and a file. Add the following to config/dev.exs:

common_metadata = [
  :request_id,
  :trace_id,
  :span_id,
  :parent_span_id,
  :start_time,
  :end_time,
  :job_name,
  :worker,
  :attempt,
  :max_attempts,
  :queue,
  :status,
  :duration
]

config :logger, :console,
  format: "$time $metadata[$level] $message\n",
  metadata: common_metadata,
  level: :debug

config :logger, :file,
  path: "logs/dev.log",
  format: {GameApp.LogFormatter, :format},
  metadata: common_metadata,
  level: :debug

config :logger,
  backends: [:console, {LoggerFileBackend, :file}]

Console Logger

Formats console logs with time, metadata, log level, and message, setting the log level to debug.

Development Logger Backends

Configures the development environment to use both the console and file loggers.

Grafana Promtail for Log Scraping

Now that we have local logs, we need an agent to scrape the information and send to Loki. In this case, Graphan’s Promtail will accomplish the task.

server:
  http_listen_port: 9080
  grpc_listen_port: 0

positions:
  filename: /tmp/positions.yaml

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:
  - job_name: game_app
    static_configs:
      - targets:
          - localhost
        labels:
          job: game_app
          __path__: /app/logs/*.log

Docker Compose Configuration

Here is the update to docker-compose.yml to include Loki, Promtail, and Grafana. Note, Loki and Grafana are typically a stand-alone service, they not part of the application environment.

version: '3.8'

services:
  loki:
    image: grafana/loki:2.8.0
    ports:
      - "3100:3100"
    command: -config.file=/etc/loki/local-config.yaml
    volumes:
      - ./loki-config:/etc/loki
      - ./loki-data:/loki
    restart: unless-stopped

  promtail:
    image: grafana/promtail:2.8.0
    volumes:
      - ./promtail-config:/etc/promtail
      - ./logs:/app/logs
    command: -config.file=/etc/promtail/promtail-config.yaml
    depends_on:
      - loki
    restart: unless-stopped

  grafana:
    image: grafana/grafana:latest
    ports:
      - "3000:3000"
    environment:
      - GF_SECURITY_ADMIN_PASSWORD=admin
    volumes:
      - grafana-data:/var/lib/grafana
    restart: unless-stopped

volumes:
  grafana-data:
  • Loki: Configured to run as a log aggregation service accessible on port 3100. It uses a local configuration file and stores data in a designated volume to ensure data persistence across restarts.
  • Promtail: Set up to tail logs and push them to Loki. It mounts a volume for configuration and another to access the application logs that need to be monitored.
  • Grafana: Runs the latest Grafana image with the web interface accessible on port 3000. A custom admin password is set through the environment variable for enhanced security. Data is stored persistently in a Docker volume.

This Docker Compose configuration is crucial for integrating these services into a coherent log management system, allowing for the effective monitoring, querying, and visualization of logs across your application.

Update to the Makefile

Below is an update to the Makefile for setting up and tearing down the Docker environment, ensuring the environment remains clean and that unwanted data and storage do not persist between setups.

up:
    @echo "Creating logs directory..."
    @mkdir -p ./logs
    @echo "Starting up all containers..."
    @docker compose up -d

down:
    @echo "Shutting down all containers..."
    @docker compose down
    @echo "Removing logs directory..."
    @rm -rf ./logs
    @echo "Removing loki-data..."
    @rm -rf ./loki-data
  • up:
    • @mkdir -p ./logs: Creates a logs directory if it does not already exist, ensuring there is a place on the filesystem to store log files.
    • @docker compose up -d: Launches all services defined in the Docker Compose file in detached mode, allowing them to run in the background.
  • down:
    • @docker compose down: Halts and removes all containers, networks, and default volumes, ensuring a clean state upon shutdown.
    • @rm -rf ./logs: Deletes the logs directory created during the up process, clearing all log files to prevent storage clutter.
    • @rm -rf ./loki-data: Eliminates the loki-data directory used by Loki for storing persistent data, helping to avoid potential data conflicts or corruption in future runs.

Shortcomings of this setup

  • Access: A section making sure there are access controls across the system.

  • Data Redaction: Automatic mechanisms to redacting sensitive data from logs.

  • Backup: No strategy to backup log data.

  • Memory Consumption: Logs will continually grow on the file-system, eventually causing the application itself to run out of memory. Mention rotation as a strategy.

  • Efficiency: The custom log formatter is a bottleneck, which for certain kinds of low-latency applications might matter.