reidmorrison / rails_semantic_logger

Rails Semantic Logger replaces the Rails default logger with Semantic Logger
https://logger.rocketjob.io/rails
Apache License 2.0
320 stars 114 forks source link

Incompatible with Rails 7.1 #207

Open xathien opened 11 months ago

xathien commented 11 months ago

Rails 7.1 introduced new Broadcast logging, including a .broadcast_to command which SemanticLogger doesn't seem to appreciate much.

Environment

Rails.logger = SemanticLogger["APP"]

* Full Stack Trace:

/Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/activerecord-7.1.0/lib/active_record/railtie.rb:70:in block in <class:Railtie>': undefined methodbroadcast_to' for #<SemanticLogger::Logger:0x00000001159cea30 @filter=nil, @name="APP", @level_index=nil, @level=nil> (NoMethodError)

    Rails.logger.broadcast_to(console)
                ^^^^^^^^^^^^^
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/railtie.rb:273:in `block in run_console_blocks'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/railtie.rb:298:in `each'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/railtie.rb:298:in `each_registered_block'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/railtie.rb:273:in `run_console_blocks'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/application.rb:586:in `block in run_console_blocks'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/engine/railties.rb:15:in `each'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/engine/railties.rb:15:in `each'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/application.rb:586:in `run_console_blocks'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/engine.rb:449:in `load_console'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/commands/console/console_command.rb:32:in `initialize'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/commands/console/console_command.rb:16:in `new'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/commands/console/console_command.rb:16:in `start'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/commands/console/console_command.rb:106:in `perform'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/thor-1.2.2/lib/thor/command.rb:27:in `run'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/thor-1.2.2/lib/thor/invocation.rb:127:in `invoke_command'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/command/base.rb:178:in `invoke_command'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/thor-1.2.2/lib/thor.rb:392:in `dispatch'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/command/base.rb:73:in `perform'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/command.rb:71:in `block in invoke'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/command.rb:149:in `with_argv'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/command.rb:69:in `invoke'
from /Users/xathien/.asdf/installs/ruby/3.1.4/lib/ruby/gems/3.1.0/gems/railties-7.1.0/lib/rails/commands.rb:18:in `<top (required)>'
from bin/rails:4:in `require'
from bin/rails:4:in `<main>'


### Expected Behavior

* I'd sure like to be able to run `rails c` and get a console

### Actual Behavior

* Stacktrace, as above
joshRpowell commented 10 months ago

a recent (unreleased) patch in rails may resolve the issue: https://github.com/rails/rails/pull/49621

  gem "rails", git: "https://github.com/rails/rails.git", branch: "7-1-stable"
xathien commented 10 months ago

Regrettably, it does not resolve the issue.

An update to rails_semantic_logger may also fix the problem, tracked by this bug.

dgmora commented 10 months ago

@reidmorrison I'm tracking this issue for some weeks, and I've noticed a lack of interaction with this and semantic rails logger. I understand that this is OS and there isn't anything guaranteed, but are you still aiming to actively maintain the project?

reidmorrison commented 10 months ago

rails_semantic_logger v 4.13.0 has been published and includes several community contributions to get it working with Rails 7.1. Please try the new version and comment here if the problem persists.

alexinman commented 9 months ago

Not this issue specifically, but I just upgraded to rails_semantic_logger v4.13.0 and then tried upgrading to rails v7.1.1 and I'm getting this error:

ArgumentError: Invalid level:#<Proc:0x00007f63cc977cf0 /home/runner/work/fuzzy-barnacle/fuzzy-barnacle/vendor/bundle/ruby/3.2.0/gems/activesupport-7.1.2/lib/active_support/log_subscriber.rb:90 (lambda)> being requested. Must be one of [:trace, :debug, :info, :warn, :error, :fatal] (ArgumentError)

        raise(ArgumentError, "Invalid level:#{level.inspect} being requested. Must be one of #{LEVELS.inspect}")
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
/home/runner/work/fuzzy-barnacle/fuzzy-barnacle/vendor/bundle/ruby/3.2.0/gems/semantic_logger-4.15.0/lib/semantic_logger/levels.rb:28:in `index'
/home/runner/work/fuzzy-barnacle/fuzzy-barnacle/vendor/bundle/ruby/3.2.0/gems/rails_semantic_logger-4.[13](https://github.com/alexinman/fuzzy-barnacle/actions/runs/6863225921/job/18662566667?pr=103#step:5:14).0/lib/rails_semantic_logger/extensions/active_support/log_subscriber.rb:8:in `silenced?'
xathien commented 9 months ago

Rails 7.1.2 fixed one compatibility issue and broke another. See https://github.com/reidmorrison/rails_semantic_logger/issues/200

reidmorrison commented 9 months ago

Rails Semantic Logger v4.14.0 has been published with support for Rails v7.1.2, thanks to https://github.com/reidmorrison/rails_semantic_logger/issues/200

rgaufman commented 9 months ago

I am getting this error:

     # NoMethodError:
     #   undefined method `info' for nil:NilClass
     #   ./app/models/camera.rb:325:in `handle_changes'

I have this in my class definition:

class Camera < ApplicationRecord
  include SemanticLogger::Loggable

And doing this in my class method:

  def handle_changes
    logger.warn("test")
  end

Any ideas?

I'm using:

rails_semantic_logger (4.14.0)
semantic_logger (4.15.0)
rails (7.1.2)

It works fine downgrading to Rails 7.0.8

rgaufman commented 8 months ago

Any ideas please? - still happening now. Is Semantic Logger not supported on Rails 7.1?

rgaufman commented 7 months ago

Turns out my issue was entirely unrelated to semantic_logger and in fact it was me setting the good_job logger to Rails.logger. Removing that fixed the problem. Apologies for the false alarm. Semantic logger is working correctly for me with Rails 7.1

pboling commented 5 months ago

Trying to understand why most of the documented settings are having no effect, or an unexpected effect. Some examples:

  1. tags are non-sensical:

    2024-04-05 07:16:15.608812 D [17246:puma srv tp 001] [request_id] [request_id] [ip] [remote_ip] [pathkey] [#<Proc:0x000000010c770378 /Users/pboling/src/apps/my_app/config/application.rb:55 (lambda)>] Rails -- [following-redirect]-----200
  2. No matter the formatter I choose I get the exact same output, as the default hash:

    2024-04-05 07:16:16.421403 I [17246:puma srv tp 001] [request_id] [request_id] [ip] [remote_ip] [pathkey] [#<Proc:0x000000010c770378 /Users/pboling/src/apps/my_app/config/application.rb:55 (lambda)>] (10.011s) LandingController -- Completed #index -- { :controller => "LandingController", :action => "index", :params => { "path_key" => "my_path" }, :format => "HTML", :method => "GET", :path => "/my_path", :status => 200, :view_runtime => 283.38, :db_runtime => 26.68, :host => "localhost", :x_forwarded_for => nil, :allocations => 465375, :status_message => "OK" }
  3. Turning off asset logging has no effect:

    2024-04-05 07:21:25.088378 I [17246:puma srv tp 002] [request_id] [request_id] [ip] [remote_ip] [pathkey] [#<Proc:0x000000010c770378 /Users/pboling/src/apps/my_app/config/application.rb:55 (lambda)>] Rails -- Started GET "/assets/root/favicon-1464818f1e9ce8573686b0d31b6d977a5a139ff34df99e1379d2bbb289de848e.png" for ::1 at 2024-04-05 07:21:25 +0700
pboling commented 5 months ago

Probably relevant to this still open issue in Rails 7.1 between tagged logging, log silencer, and broadcast logging: https://github.com/rails/rails/issues/49745

reidmorrison commented 2 months ago

The rails_semantic_logger gem already patches Rails to use Semantic Logger, so the following config lines above should not be necessary, and are probably causing issues:

ActionController::Base.logger = SemanticLogger["ActionController"]
ActiveRecord::Base.logger = SemanticLogger["ActiveRecord"]
ActionMailer::Base.logger = SemanticLogger["ActionMailer"]
Sidekiq.logger = SemanticLogger["Sidekiq"]

Rails.logger = SemanticLogger["APP"]