440 Fundamental

440: Log Pattern Macros

Functional Programming

Tutorial Video

Text description (accessibility)

This video demonstrates the "440: Log Pattern Macros" functional Rust example. Difficulty level: Fundamental. Key concepts covered: Functional Programming. Logging requires consistent metadata: timestamp, level, file, line number, and the actual message. Key difference from OCaml: 1. **Location capture**: Rust uses `file!()` and `line!()` macros in the expansion; OCaml uses `__LOC__` string (containing file:line:col).

Tutorial

The Problem

Logging requires consistent metadata: timestamp, level, file, line number, and the actual message. Writing eprintln!("[INFO] {}:{}: {}", file!(), line!(), msg) at every log site is verbose and inconsistent. Log macros capture this metadata automatically at the call site using file!() and line!() built-in macros. The log crate standardizes this with log::info!, log::warn!, log::error! macros that also support multiple backends. Understanding the underlying macro pattern explains why log calls show the correct source location.

Log macros appear in virtually every serious Rust codebase via the log crate, tracing for structured logging, and custom logging macros for specific output formats.

🎯 Learning Outcomes

• Understand how file!() and line!() capture the call site location in macros

• Learn how format!($($arg:tt)*) inside a macro passes format strings and arguments through

• See how convenience macros (info!, warn!, error!) wrap a general log! macro

• Understand trace_fn! as a structural logging pattern for function entry/exit tracking

• Learn how the log crate abstracts over logging backends using the same macro interface

Code Example

#![allow(clippy::all)]
//! Log Pattern Macros
//!
//! Logging and tracing utilities.

/// Log with level and location.
#[macro_export]
macro_rules! log {
    ($level:expr, $($arg:tt)*) => {
        eprintln!(
            "[{}] {}:{}: {}",
            $level,
            file!(),
            line!(),
            format!($($arg)*)
        );
    };
}

/// Convenience macros.
#[macro_export]
macro_rules! info { ($($arg:tt)*) => { log!("INFO", $($arg)*); }; }

#[macro_export]
macro_rules! warn { ($($arg:tt)*) => { log!("WARN", $($arg)*); }; }

#[macro_export]
macro_rules! error { ($($arg:tt)*) => { log!("ERROR", $($arg)*); }; }

/// Trace function entry/exit.
#[macro_export]
macro_rules! trace_fn {
    ($name:expr, $body:block) => {{
        eprintln!("--> Entering {}", $name);
        let result = $body;
        eprintln!("<-- Exiting {}", $name);
        result
    }};
}

pub fn example_logged() -> i32 {
    // Would use: info!("Starting computation");
    42
}

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn test_example_logged() {
        assert_eq!(example_logged(), 42);
    }

    #[test]
    fn test_trace_fn() {
        let result = trace_fn!("test", { 1 + 2 });
        assert_eq!(result, 3);
    }

    #[test]
    fn test_format_in_log() {
        // Just verify it compiles
        let x = 5;
        log!("DEBUG", "value = {}", x);
    }

    #[test]
    fn test_info_macro() {
        info!("test message");
    }

    #[test]
    fn test_nested_trace() {
        let result = trace_fn!("outer", { trace_fn!("inner", { 10 }) });
        assert_eq!(result, 10);
    }
}

(* 440. Logging macros – OCaml *)

type level = Debug | Info | Warn | Error

let level_to_int = function Debug->0 | Info->1 | Warn->2 | Error->3
let level_str    = function Debug->"DEBUG" | Info->"INFO" | Warn->"WARN" | Error->"ERROR"

let min_level = ref Info

let log level fmt =
  if level_to_int level >= level_to_int !min_level then
    Printf.ksprintf (fun s ->
      Printf.eprintf "[%s] %s\n%!" (level_str level) s
    ) fmt
  else
    Printf.ksprintf ignore fmt

let () =
  log Info "Starting v%s" "1.0";
  log Debug "This is hidden";  (* below min level *)
  log Warn "Low memory: %d MB" 42;
  log Error "Fatal: %s" "disk full";
  min_level := Debug;
  log Debug "Debug now visible"

Key Differences

Location capture: Rust uses file!() and line!() macros in the expansion; OCaml uses __LOC__ string (containing file:line:col).

Format passthrough: Rust's $($arg:tt)* passes format arguments through; OCaml's functions use ('a, Format.formatter, unit) format types.

Level-as-macro: Rust's info!(...) and warn!(...) are macros, not functions; OCaml's Logs.info and Logs.warn are functions with callbacks.

Structured logging: tracing crate adds spans and structured fields to Rust logs; OCaml's Logs is simpler, lacking structured fields without PPX.

OCaml Approach

OCaml's Logs library provides level-based logging with Logs.info, Logs.warn, Logs.err. Source location is captured via __LOC__ special value. Ppx_log provides [%log.info ...] syntax capturing locations automatically. The tracing ecosystem doesn't have a direct OCaml equivalent, though Eio's traces come close for structured concurrent tracing.

Full Source

#![allow(clippy::all)]
//! Log Pattern Macros
//!
//! Logging and tracing utilities.

/// Log with level and location.
#[macro_export]
macro_rules! log {
    ($level:expr, $($arg:tt)*) => {
        eprintln!(
            "[{}] {}:{}: {}",
            $level,
            file!(),
            line!(),
            format!($($arg)*)
        );
    };
}

/// Convenience macros.
#[macro_export]
macro_rules! info { ($($arg:tt)*) => { log!("INFO", $($arg)*); }; }

#[macro_export]
macro_rules! warn { ($($arg:tt)*) => { log!("WARN", $($arg)*); }; }

#[macro_export]
macro_rules! error { ($($arg:tt)*) => { log!("ERROR", $($arg)*); }; }

/// Trace function entry/exit.
#[macro_export]
macro_rules! trace_fn {
    ($name:expr, $body:block) => {{
        eprintln!("--> Entering {}", $name);
        let result = $body;
        eprintln!("<-- Exiting {}", $name);
        result
    }};
}

pub fn example_logged() -> i32 {
    // Would use: info!("Starting computation");
    42
}

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn test_example_logged() {
        assert_eq!(example_logged(), 42);
    }

    #[test]
    fn test_trace_fn() {
        let result = trace_fn!("test", { 1 + 2 });
        assert_eq!(result, 3);
    }

    #[test]
    fn test_format_in_log() {
        // Just verify it compiles
        let x = 5;
        log!("DEBUG", "value = {}", x);
    }

    #[test]
    fn test_info_macro() {
        info!("test message");
    }

    #[test]
    fn test_nested_trace() {
        let result = trace_fn!("outer", { trace_fn!("inner", { 10 }) });
        assert_eq!(result, 10);
    }
}

(* 440. Logging macros – OCaml *)

type level = Debug | Info | Warn | Error

let level_to_int = function Debug->0 | Info->1 | Warn->2 | Error->3
let level_str    = function Debug->"DEBUG" | Info->"INFO" | Warn->"WARN" | Error->"ERROR"

let min_level = ref Info

let log level fmt =
  if level_to_int level >= level_to_int !min_level then
    Printf.ksprintf (fun s ->
      Printf.eprintf "[%s] %s\n%!" (level_str level) s
    ) fmt
  else
    Printf.ksprintf ignore fmt

let () =
  log Info "Starting v%s" "1.0";
  log Debug "This is hidden";  (* below min level *)
  log Warn "Low memory: %d MB" 42;
  log Error "Fatal: %s" "disk full";
  min_level := Debug;
  log Debug "Debug now visible"

✓ Tests Rust test suite

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn test_example_logged() {
        assert_eq!(example_logged(), 42);
    }

    #[test]
    fn test_trace_fn() {
        let result = trace_fn!("test", { 1 + 2 });
        assert_eq!(result, 3);
    }

    #[test]
    fn test_format_in_log() {
        // Just verify it compiles
        let x = 5;
        log!("DEBUG", "value = {}", x);
    }

    #[test]
    fn test_info_macro() {
        info!("test message");
    }

    #[test]
    fn test_nested_trace() {
        let result = trace_fn!("outer", { trace_fn!("inner", { 10 }) });
        assert_eq!(result, 10);
    }
}

Deep Comparison

OCaml vs Rust: macro log pattern

See example.rs and example.ml for side-by-side implementations.

Key Points

Rust macros operate at compile time

OCaml uses ppx for similar metaprogramming

Both languages support powerful code generation

Rust's macro_rules! is built into the language

OCaml's approach requires external tooling

Exercises

Log to file: Extend the log! macro to accept an optional writer: impl Write argument: log_to!(writer, INFO, "message: {}", value). Default to eprintln! when no writer is specified.

Structured log: Create slog!(level = "INFO", component = "db", "query {}", sql) that outputs {"level":"INFO","component":"db","file":"...","line":...,"msg":"..."} as JSON. Use serde_json or manual formatting.

Tracing span: Implement span!(name, { /* body */ }) that generates a unique span ID, logs entry with the span ID, executes the body, then logs exit with elapsed time and the same span ID — enabling correlation of nested spans in logs.

Open Source Repos

functional-rust

View the source for this example on GitHub — OCaml and Rust side by side in the repo.

Rust