Skip to content

Conversation

@kaylareopelle
Copy link
Contributor

@kaylareopelle kaylareopelle commented May 14, 2024

Description

This an OpenTelemetry logs bridge for Ruby's standard Logger library.

It also includes patches to ActiveSupport::Logger.broadcast and the ActiveSupport::BroadcastLogger to emit only one log record for a broadcast.

@khushijain21 is a co-author of this PR and contributed functionality as part of her LFX mentorship with OpenTelemetry in 2024.

Closes #668

kaylareopelle and others added 30 commits September 19, 2023 08:37
Appraisal can't install gems from a git source.
Since the appraisal is only necessary for active_support_logger,
disable those tests while working on other features.
chore: Allow logger patch tests to run
@fguillen
Copy link

fguillen commented May 1, 2025

Hello @tomash I also would like to test this in my Rails project. Can you share your integration? Especially interested in the lograge integration. Thanks!

UPDATE: forget it, I see it just work out of the box after installing the gem with your gem call piece of art and requiring the gem.

I am sharing here my configurations:

# Gemfile
gem "opentelemetry-exporter-otlp-logs"
gem "opentelemetry-exporter-otlp-metrics"
gem "opentelemetry-exporter-otlp"
gem "opentelemetry-instrumentation-all"
gem "opentelemetry-sdk"
gem "opentelemetry-instrumentation-logger",
  git: "https://github.com/kaylareopelle/opentelemetry-ruby-contrib.git",
  branch: "logger-instrumentation",
  glob: "instrumentation/logger/opentelemetry-instrumentation-logger.gemspec"
# config/initializers/lograge.rb
Rails.application.configure do
  config.lograge.enabled = true
  config.lograge.formatter = Lograge::Formatters::Json.new

  # User id and host (this is very personal for my project)
  config.lograge.custom_payload do |controller|
    user_id = nil
    user_id = controller.send(:current_front_user).try(:uuid) if controller.respond_to?(:current_front_user, true)
    user_id ||= controller.send(:current_tester_user).try(:uuid) if controller.respond_to?(:current_tester_user, true)
    user_id ||= controller.send(:current_admin_user).try(:uuid) if controller.respond_to?(:current_admin_user, true)
    {
      host: controller.request.host,
      user_id:
    }
  end

  config.lograge.custom_options = lambda do |event|
    context = OpenTelemetry::Trace.current_span.context
    {
      trace_id: context.valid? ? context.hex_trace_id : nil,
      span_id: context.valid? ? context.hex_span_id : nil,
      user_id: event.payload[:user_id], # if available
      host: event.payload[:host],
      remote_ip: event.payload[:remote_ip],
      params: event.payload[:params].except("controller", "action")
    }
  end
end
# config/initializers/opentelemetry.rb
ENV["OTEL_TRACES_EXPORTER"] ||= "otlp"
ENV["OTEL_METRICS_EXPORTER"] ||= "otlp"
ENV["OTEL_LOGS_EXPORTER"] ||= "otlp"
ENV["OTEL_EXPORTER_OTLP_ENDPOINT"] ||= "https://myendpoint:4318"
ENV["OTEL_LOG_LEVEL"] ||= "info"

# Basic auth (I haven't test this yet)
username = "MyUser"
password = "MyPass"
basic_auth_hash = Base64.strict_encode64("#{username}:#{password}")
basic_auth_header = "Authorization=Basic #{basic_auth_hash}"s
ENV["OTEL_EXPORTER_OTLP_HEADERS"] = basic_auth_header

require "opentelemetry-metrics-sdk"
require "opentelemetry-logs-sdk"
require "opentelemetry/sdk"
require "opentelemetry/exporter/otlp"
require "opentelemetry/instrumentation/all"
require "opentelemetry-instrumentation-logger"

OpenTelemetry::SDK.configure do |c|
  c.service_name = "app.playcocola.com"
  c.use_all() # enables all instrumentation!
end

UPDATE 2: I see the author or the PR has a proper Rails demo published

@fguillen
Copy link

fguillen commented May 1, 2025

Funny behaviour. If I have activated ENV["OTEL_LOG_LEVEL"] ="debug". When a log is exported another DEBUG log is generated like:

D, [2025-05-01T22:42:17.912579 #95172] DEBUG -- : Successfully exported 1 log records

And it gets into an infinite loop. It may be expected. But just for you to take into consideration :)

@tomash
Copy link

tomash commented May 2, 2025

@fguillen I was about to write an answer but you figured it all out in the meantime!

Sharing my slightly-different lograge.rb initializer:

Rails.application.configure do
  config.lograge.enabled = true

  # the hotwire connect-disconnect logs are just noise
  config.lograge.ignore_actions = [
    "Turbo::StreamsChannel#subscribe",
    "Turbo::StreamsChannel#unsubscribe",
    "Hotwire::Livereload::ReloadChannel#subscribe",
    "Hotwire::Livereload::ReloadChannel#unsubscribe",
    "ApplicationCable::Connection#connect",
    "ApplicationCable::Connection#disconnect",
    "ApplicationCable::Connection#reconnect",
    "ActionCable::Connection::Base#connect",
    "ActionCable::Connection::Base#disconnect",
  ]
  config.lograge.custom_payload do |controller|
    {
      params: controller.request.filtered_parameters,
    }
  end
end

In opentelemetry.rb initializer we also have this line, as I saw it in this PR's example code:

  at_exit do
    OpenTelemetry.logger_provider.shutdown
  end

Why do you use OTEL_LOG_LEVEL instead of application-global log level?

@fguillen
Copy link

fguillen commented May 13, 2025

hi @tomash:

Why do you use OTEL_LOG_LEVEL instead of application-global log level?

As explained in a previous comment, I can not set OTEL_LOG_LEVEL=debug and also activate OTEL_LOGS_EXPORTER. Because the system enters an infinite loop of noticing the debug log that has been sent, and by this, generating another debug log, and so on.

And regarding:

at_exit do
    OpenTelemetry.logger_provider.shutdown
end

I haven't seen it is done in the Rails demo project. So I am not doing it. Don't know if it is necessary :/

@fguillen
Copy link

I am having an issue when loading the logs in Grafana (Rails -> OtelCollector -> Loki -> Grafana). I don't know if it is related to this logger plugin or by my configuration or it is the expected behaviour.

The case is that in Grafana I see the logs like this:

{
  "body": "{\"method\":\"GET\",\"path\":\"/admin/invitations\",\"format\":\"html\",\"controller\":\"Admin::InvitationsController\",\"action\":\"index\",\"status\":200,\"allocations\":847384,\"duration\":470.19,\"view\":351.69,\"db\":86.12,\"trace_id\":\"7d5334a61dc66894a9c6ef508529de6e\",\"span_id\":\"c02fc38d3c0b7580\",\"user_id\":\"257b4cba-d430-4db7-9406-fdd08c495571\",\"host\":\"localhost\",\"remote_ip\":null,\"params\":{},\"environment\":\"development\",\"request_id\":null}",
  "flags": 1,
  "instrumentation_scope": {
    "name": "opentelemetry-instrumentation-logger",
    "version": "0.1.0"
  },
  "resources": {
    "process.command": "bin/rails",
    "process.pid": 81016,
    "process.runtime.description": "ruby 3.2.4 (2024-04-23 revision af471c0e01) [arm64-darwin24]",
    "process.runtime.name": "ruby",
    "process.runtime.version": "3.2.4",
    "service.name": "app.playcocola.com",
    "telemetry.sdk.language": "ruby",
    "telemetry.sdk.name": "opentelemetry",
    "telemetry.sdk.version": "1.8.0"
  },
  "severity": "INFO",
  "spanid": "c02fc38d3c0b7580",
  "traceid": "7d5334a61dc66894a9c6ef508529de6e"
}

The message has been created in a proper JSON format, but when it arrives at Grafana, it is in the body value and it is stringified, and I can not do proper queries on it.

I have tried many different lograge configurations but have had no luck. The body is always stringified.

@kaylareopelle
Copy link
Contributor Author

SIG discussion 06/22/25 - Move this out of instrumentation, into a separate bridges package to make it easier to disable if people don't want to use it.

@kaylareopelle
Copy link
Contributor Author

@xuan-cao-swi - I've looked into move the logger instrumentation into a separate bridge directory and have some concerns. I'd like to get your feedback.

  1. If we move out of the instrumentation directory, should we still allow this instrumentation to depend on the opentelemetry-instrumentation-base gem? Currently, the logger instrumentation leverages the install/present/compatible methods provided by this gem. Eventually, we may want to add configuration options too, which would also use these APIs. Right now, nothing outside the instrumentation directory depends on the base gem.

  2. If we move the logger logic into bridges, should we have a separate registry for bridges? Personally, I'd prefer to have one registry that holds all the possible prepended modules.

  3. We'll eventually need to include creating a logger into instrumentation-base for AI events since it seems like they will be logs with the event_name attribute. This also reveals that an unnecessary tracer is being instantiated for the logger instrumentation because it depends on the instrumentation-base gem, but we could update the internals to make creating a tracer conditional.

At the moment, I'd like to keep the logger instrumentation out of all at least until the logs implementation is stable, which would add some barriers to installing it accidentally.

@wsmoak
Copy link
Contributor

wsmoak commented Oct 2, 2025

As discussed in... https://cloud-native.slack.com/archives/C01NWKKMKMY/p1759439218858049

I'm interested in trying this out... if you have time could you please merge in the latest changes?

@ericmustin
Copy link
Contributor

lgtm once the branch conflicts r resolved

@kaylareopelle
Copy link
Contributor Author

@ericmustin @robbkidd @xuan-cao-swi -- Made the updates we discussed in the SIG today. The logger instrumentation is no longer included in opentelemetry-instrumentation-all. Also made a few tweaks for alignment with the rest of the repo. Please take a look when you can!

@kaylareopelle
Copy link
Contributor Author

Also, the markdown link checker will fail until this PR is merged, because there's a link related to content in the PR. https://github.com/kaylareopelle/opentelemetry-ruby-contrib/actions/runs/18325633495/job/52189286587#step:3:262

Copy link
Member

@robbkidd robbkidd left a comment

Choose a reason for hiding this comment

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

It's GOOD!

@kaylareopelle kaylareopelle merged commit 4d13ce3 into open-telemetry:main Oct 8, 2025
64 checks passed
@github-project-automation github-project-automation bot moved this from Pending PR to Done in Ruby - Logs Oct 8, 2025
@ericmustin
Copy link
Contributor

Sorry I missed this, lgtm (in hindsight!)

americodls pushed a commit to intercom/opentelemetry-ruby-contrib that referenced this pull request Oct 12, 2025
* WIP initial commit logger instrumentation

* Rubocop require_relative

* Add :: to find Ruby logger instead of OTel logger

* Remove commented out option LOC

* Add skip_instrumenting? method

* Skip ActiveSupport::Logger#broadcast loggers

* Add logger instrumentation library and version

* Update severity_number logic, return orig value

* Make instrumentation name a constant

* WIP test active support logger

* Map logger level to OTel level

* Install WIP logs dependencies from git, not local

* Update rubocop dependencies

* Disable active_support_logger tests

Appraisal can't install gems from a git source.
Since the appraisal is only necessary for active_support_logger,
disable those tests while working on other features.

* maps otel log level

* Use the updated method name to emit, `on_emit`

* Update tests referencing severity numbers

* Loosen dependency version restrictions

* fix: Remove NAME constant from gemspec

* chore: Address Rubocop require_relative linter

* Rubocop

* fix: Bring back the NAME constant

It's used in the instrumentation when on_emit is called

* chore: Correct version number, add TODOs in README

* fix: Revert version for now

* change

* move options

* accomodated changes

* removed configuring logger_provider

* removed corresponding test

* chore: Add tests for name and version config

* chore: Rubocop

* add check for logs sdk

* test: Reinstate active support logger tests

* style: Add language to code fence

* Update instrumentation/logger/lib/opentelemetry/instrumentation.rb

* docs: add some config info

* feat: Remove config options

* chore: Add TODO for version number update

* feat: Update example and readme

* test: remove appraisals for eol'd rails versions

* feat: Support ActiveSupport::BroadcastLogger

Rails 7.1+ uses ActiveSupport::BroadcastLogger. This needs to protect
against emitting duplicate logs in a different way than
ActiveSupport::Logger.broadcast.

Emits the log record for the first logger in the broadcast,
skip the others. Reset everything at the end of the method call.

* test: Remove config option tests

* chore: Prepare bridge for review

* Add references to released logs gems
* Test Rails 7.0 - 8.0
* Rubocop
* Set gem version

* chore: Rename skip_instrumenting to skip_otel_emit

* chore: Bump instrumentation-logger version in all

* chore: Remove simplecov

* test: Update ActiveSupportLogger tests

Test the outcome rather than the presence of variables

* test: Add missing variable

* chore: Update gem to include changes from main

* move dev dependencies to Gemfile
* require 'logger' in test helper
* set min version to Ruby 3.1

* chore: Raise rubocop, rubocop-performance versions

* Remove logger instrumentation from all

* test: Exclude logger from all Gemfile/tests

* chore: Match dependency-related files with repo

* raise min tested Rails version
* use constants for Ruby version and post-install message
* update internal dep versions for consistency

* chore: Remove extra requires from all

---------

Co-authored-by: khushijain21 <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

keep Ensures stale-bot keeps this issue/PR open

Projects

Status: Done

Development

Successfully merging this pull request may close these issues.

Add instrumentation for Ruby Logger leveraging Log Records

8 participants