Skip to content

Add SemanticLogger support#66

Open
douglas wants to merge 9 commits intosilva96:mainfrom
douglas:main
Open

Add SemanticLogger support#66
douglas wants to merge 9 commits intosilva96:mainfrom
douglas:main

Conversation

@douglas
Copy link

@douglas douglas commented Dec 5, 2025

Summary

Adds support for SemanticLogger format alongside the existing Lograge format. SemanticLogger is recommended by Datadog for better log ingestion and provides rich JSON-formatted logs with additional context.

Changes

Core Features

  • SemanticLogger Parser: New parser that converts human-readable SemanticLogger format to JSON

    • Handles both nested payload structure and top-level fields
    • Supports ANSI color code stripping
    • Extracts duration, request_id, and HTTP request details
  • Dual Format Support: LogBench now seamlessly supports both formats

    • Lograge: Flat JSON with top-level fields (default)
    • SemanticLogger: Nested JSON with payload object
    • Auto-detection based on configuration
  • Configuration: New logger_type option

    • :lograge (default) - maintains backward compatibility
    • :semantic_logger - enables SemanticLogger parsing
    • Renamed configure_lograge_automaticallyconfigure_logger_automatically
  • CLI Enhancement: Added --logger_type flag

    • Specify format via command line: log_bench --logger_type=semantic_logger
    • Logger type displayed in TUI header for clarity

Code Quality Improvements

  • Removed redundant comments and AI-generated noise
  • Refactored private class methods to use idiomatic class << self pattern
  • Optimized regex usage for better performance
  • Simplified guard clauses for better readability
  • Enhanced test infrastructure with proper Rails stubs

Documentation

  • Comprehensive setup guide for both logger types
  • Clear migration path from Lograge to SemanticLogger
  • CLI usage examples
  • Test fixtures for both formats

Testing

All existing tests pass. Added 296 new tests covering:

  • SemanticLogger JSON parsing
  • Human-readable format conversion
  • HTTP request extraction from nested payloads
  • SQL and cache operation detection
  • Request/log correlation

Backward Compatibility

✅ Fully backward compatible

  • Lograge remains the default
  • No breaking changes to existing configurations
  • Existing log files continue to work

Example Usage

# config/initializers/log_bench.rb
LogBench.setup do |config|
  config.logger_type = :semantic_logger
end
# CLI
log_bench --logger_type=semantic_logger
log_bench log/production.log --logger_type=lograge

Add parser infrastructure to convert human-readable SemanticLogger format to JSON.
Supports both nested payload structure and top-level fields.
Includes test fixtures for both lograge and SemanticLogger formats.
Introduce logger_type option (:lograge or :semantic_logger) in configuration.
Update railtie to configure the selected logger type.
Refactor configure_lograge_automatically to configure_logger_automatically.
Update Entry and Request to extract fields from both lograge and SemanticLogger formats.
Add detection for SemanticLogger request format (nested payload).
Convert human-readable SemanticLogger logs to JSON when configured.
Add comprehensive tests for SemanticLogger parsing.
Add --logger_type flag to CLI to specify logger format.
Display logger type in TUI header.
Update help documentation with usage examples.
Add comprehensive documentation for SemanticLogger support.
Document both Lograge and SemanticLogger configuration options.
Improve Rails stub in tests to support module_parent_name.
@silva96
Copy link
Owner

silva96 commented Dec 5, 2025

@douglas this looks great, give me a few days to review it please, thanks a lot for your contributions!

Also, please run rake standard:fix

@douglas
Copy link
Author

douglas commented Dec 8, 2025

@douglas this looks great, give me a few days to review it please, thanks a lot for your contributions!

Also, please run rake standard:fix

Thanks @silva96! No worries (and not rush) at all, take your time to review it and thank you so much for such great project, it is really helpful ❤️

Copy link
Owner

@silva96 silva96 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One more thing, there are a bunch of configuration validations that check for lograge, we need to do the same (conditionally) for semantic_logger

otherwise you get this:

❌ LogBench Configuration Error:
❌ Lograge is not enabled

LogBench requires lograge to be enabled in your Rails application.
...
LogBench will be disabled until this is fixed.

@douglas
Copy link
Author

douglas commented Dec 9, 2025

One more thing, there are a bunch of configuration validations that check for lograge, we need to do the same (conditionally) for semantic_logger

otherwise you get this:

❌ LogBench Configuration Error:
❌ Lograge is not enabled

LogBench requires lograge to be enabled in your Rails application.
...
LogBench will be disabled until this is fixed.

Sure! I'll get to it this week, thanks for the early review 👍

Update ConfigurationValidator to check logger_type and run appropriate
validations. When using semantic_logger, users no longer see the
"Lograge is not enabled" error.

- Add SEMANTIC_LOGGER_ERROR_CONFIGS with relevant error messages
- Validate SemanticLogger is defined and configured as Rails logger
- Handle Rails 7.1+ BroadcastLogger wrapping
- Add tests for validator behavior and error config structure
@douglas
Copy link
Author

douglas commented Dec 15, 2025

Hello @silva96!

I updated the code to follow your review comment, take your time to review it as I'm not in a rush - I'll also push two other PRs:

  • One adding syntax highlight to the logs 💅
  • One drastically improving the application boot time by improving the parsing logic and using the oj gem.

@silva96
Copy link
Owner

silva96 commented Dec 15, 2025

Hey @douglas , thanks for the update. I tried it but I'm not sure how to locally configure SemanticLogger to produce json logs with the request_id as one of the keys (which is mandatory for LogBench)

here's a demo log:

{"host":"gtr9-ubuntu","application":"Semantic Logger","environment":"development","timestamp":"2025-12-15T18:46:44.023475Z","level":"trace","level_index":0,"pid":47182,"thread":"SemanticLogger::Appenders","name":"SemanticLogger::Appenders","message":"Async: Appender thread active"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.378004Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"Rack","message":"Started","payload":{"method":"GET","path":"/","ip":"127.0.0.1"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.395355Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":1.7451980002224445,"duration":"1.745ms","name":"ActiveRecord","payload":{"sql":"CREATE TABLE \"schema_migrations\" (\"version\" varchar NOT NULL PRIMARY KEY) /*application='TestLog'*/","allocations":14,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.399658Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":0.0900759999640286,"duration":"0.090ms","name":"ActiveRecord","payload":{"sql":"CREATE TABLE \"ar_internal_metadata\" (\"key\" varchar NOT NULL PRIMARY KEY, \"value\" varchar, \"created_at\" datetime(6) NOT NULL, \"updated_at\" datetime(6) NOT NULL) /*application='TestLog'*/","allocations":4,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.453600Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":0.15482199983671308,"duration":"0.155ms","name":"ActiveRecord","message":"ActiveRecord::SchemaMigration Load","payload":{"sql":"SELECT \"schema_migrations\".\"version\" FROM \"schema_migrations\" ORDER BY \"schema_migrations\".\"version\" ASC /*application='TestLog'*/","allocations":13,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.516625Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"HomeController","message":"Processing #index"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.531418Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"HomeController#index before TestJob at 2025-12-15 15:48:24 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.549318Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"Enqueued TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) to Async(default) at 2025-12-15 18:48:26 UTC"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.550528Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"↳ app/controllers/home_controller.rb:4:in 'HomeController#index'"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.550554Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"HomeController#index after TestJob at 2025-12-15 15:48:24 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.560992Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"ActionView","message":"Rendering layout","payload":{"template":"layouts/application.html.erb"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.561097Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"ActionView","message":"Rendering","payload":{"template":"home/index.html.erb"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.563037Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":1.0628959997557104,"duration":"1.063ms","name":"ActionView","message":"Rendered","payload":{"template":"home/index.html.erb","within":"layouts/application","allocations":253}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.571517Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","duration_ms":53.425919000059366,"duration":"53.4ms","name":"HomeController","message":"Completed #index","payload":{"controller":"HomeController","action":"index","format":"HTML","method":"GET","path":"/","status":200,"view_runtime":12.74,"db_runtime":0.0,"queries_count":0,"cached_queries_count":0,"allocations":34242,"status_message":"OK"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.552873Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"Performing TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) from Async(default) enqueued at 2025-12-15T18:48:24.545330184Z"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.553687Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"TestJob#perform at 2025-12-15 15:48:26 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.553973Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"Performed TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) from Async(default) in 1.02ms"}

Added this to the development.rb

config.rails_semantic_logger.format = :json

# Optional: Configure log level and other SemanticLogger options
config.log_level = :debug

This commit adds support for SemanticLogger's JSON format output, which
requires a different configuration approach than the human-readable format.

## Background

SemanticLogger supports two output formats:

1. **Human-readable format** (default):
   - Request ID appears in tags: {request_id: abc-123, ...}
   - Already supported by existing REQUEST_ID_PATTERN regex
   - Works out of the box (e.g., Campaigns application)

2. **JSON format** (configured with config.rails_semantic_logger.format = :json):
   - Produces structured JSON output
   - Requires config.log_tags to include request_id
   - Request ID appears in named_tags field: {"named_tags": {"request_id": "abc-123"}}

## Changes

1. **Documentation** (README.md):
   - Added official rails_semantic_logger configuration using config.log_tags
   - This is the recommended approach per SemanticLogger documentation
   - Reference: https://logger.rocketjob.io/rails.html

2. **Parser Enhancement** (lib/log_bench/log/entry.rb):
   - Added support for extracting request_id from named_tags field
   - Now checks three locations:
     * Top-level request_id (Lograge format)
     * payload.request_id (SemanticLogger payload format)
     * named_tags.request_id (SemanticLogger JSON format with log_tags)

3. **Test Coverage** (test/test_log_bench.rb):
   - Added test for named_tags request_id extraction

## Why This Change

Without this change, users who want to use SemanticLogger's JSON format
(recommended by Datadog) would not be able to correlate logs by request_id,
even after configuring log_tags according to the official documentation.

Addresses feedback from PR review: silva96#66 (comment)
@douglas
Copy link
Author

douglas commented Dec 16, 2025

Hey @douglas , thanks for the update. I tried it but I'm not sure how to locally configure SemanticLogger to produce json logs with the request_id as one of the keys (which is mandatory for LogBench)

here's a demo log:

{"host":"gtr9-ubuntu","application":"Semantic Logger","environment":"development","timestamp":"2025-12-15T18:46:44.023475Z","level":"trace","level_index":0,"pid":47182,"thread":"SemanticLogger::Appenders","name":"SemanticLogger::Appenders","message":"Async: Appender thread active"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.378004Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"Rack","message":"Started","payload":{"method":"GET","path":"/","ip":"127.0.0.1"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.395355Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":1.7451980002224445,"duration":"1.745ms","name":"ActiveRecord","payload":{"sql":"CREATE TABLE \"schema_migrations\" (\"version\" varchar NOT NULL PRIMARY KEY) /*application='TestLog'*/","allocations":14,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.399658Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":0.0900759999640286,"duration":"0.090ms","name":"ActiveRecord","payload":{"sql":"CREATE TABLE \"ar_internal_metadata\" (\"key\" varchar NOT NULL PRIMARY KEY, \"value\" varchar, \"created_at\" datetime(6) NOT NULL, \"updated_at\" datetime(6) NOT NULL) /*application='TestLog'*/","allocations":4,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.453600Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":0.15482199983671308,"duration":"0.155ms","name":"ActiveRecord","message":"ActiveRecord::SchemaMigration Load","payload":{"sql":"SELECT \"schema_migrations\".\"version\" FROM \"schema_migrations\" ORDER BY \"schema_migrations\".\"version\" ASC /*application='TestLog'*/","allocations":13,"cached":null}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.516625Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"HomeController","message":"Processing #index"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.531418Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"HomeController#index before TestJob at 2025-12-15 15:48:24 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.549318Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"Enqueued TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) to Async(default) at 2025-12-15 18:48:26 UTC"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.550528Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"↳ app/controllers/home_controller.rb:4:in 'HomeController#index'"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.550554Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","name":"Rails","message":"HomeController#index after TestJob at 2025-12-15 15:48:24 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.560992Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"ActionView","message":"Rendering layout","payload":{"template":"layouts/application.html.erb"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.561097Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","name":"ActionView","message":"Rendering","payload":{"template":"home/index.html.erb"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.563037Z","level":"debug","level_index":1,"pid":47182,"thread":"puma srv tp 001","duration_ms":1.0628959997557104,"duration":"1.063ms","name":"ActionView","message":"Rendered","payload":{"template":"home/index.html.erb","within":"layouts/application","allocations":253}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:24.571517Z","level":"info","level_index":2,"pid":47182,"thread":"puma srv tp 001","duration_ms":53.425919000059366,"duration":"53.4ms","name":"HomeController","message":"Completed #index","payload":{"controller":"HomeController","action":"index","format":"HTML","method":"GET","path":"/","status":200,"view_runtime":12.74,"db_runtime":0.0,"queries_count":0,"cached_queries_count":0,"allocations":34242,"status_message":"OK"}}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.552873Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"Performing TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) from Async(default) enqueued at 2025-12-15T18:48:24.545330184Z"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.553687Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"TestJob#perform at 2025-12-15 15:48:26 -0300"}
{"host":"gtr9-ubuntu","application":"test_log","environment":"development","timestamp":"2025-12-15T18:48:26.553973Z","level":"info","level_index":2,"pid":47182,"thread":"worker-1","name":"Rails","message":"Performed TestJob (Job ID: 50866315-9a92-4987-948a-f93e1dea1aa1) from Async(default) in 1.02ms"}

Added this to the development.rb

config.rails_semantic_logger.format = :json

# Optional: Configure log level and other SemanticLogger options
config.log_level = :debug

Hello @silva96!

Sorry, I forgot to handle the default case where an application is not configured to support request_id, as the application I'm using to test it already supports it.

I added a section in the README about configuring it, but here is how to configure:

  # config/environments/development.rb
  Rails.application.configure do
    config.rails_semantic_logger.format = :json
    config.log_level = :debug

    # IMPORTANT: Add request_id to log tags (Rails 5+)
    # This is the official rails_semantic_logger approach
    config.log_tags = {
      request_id: :request_id
    }
  end

I added more information in the commit description in case you want to review it individually.

@silva96
Copy link
Owner

silva96 commented Dec 21, 2025

Hey @douglas i've been testing the PR using this demo app:

https://github.com/silva96/test_log_bench (I created a semantic-logger-test branch)

can you clone it and use it "as is" to check until logs look the same as in the main branch, particularly improve the sidekiq and activejob integration because request id is not propagating down as we do with lograge.

with your branch you get this logs in the / request

CleanShot 2025-12-21 at 09 05 20@2x

And with lograge (main branch) you get

CleanShot 2025-12-21 at 08 56 03@2x

To test this, clone the demo app in the same parent folder as the log_bench gem is located

Example

/home/projects/log_bench
/home/projects/test_log_bench

now cd into test_log_bench

run bundle install && gem install foreman
run bin/dev

in another tab in the same folder run: ../log_bench/exe/log_bench ./log/development.log

now

go to http://127.0.0.1:3000/

and check log_bench UI

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants