rails / activerecord-session_store

Active Record's Session Store extracted from Rails
MIT License
541 stars 188 forks source link

NoMethodError: undefined method silence for Logger after 2.0.0 upgrade #176

Closed swanson closed 3 years ago

swanson commented 3 years ago

I'm attempting to upgrade to 2.0.0 to resolve the CVE, but I'm getting a bunch of exceptions like:

 NoMethodError:
       undefined method `silence' for #<Logger:0x0000555d12a49218>

in my test suite. I see the note in the README about logging, but I'm not doing anything fancy with the Rails logger nor do I seem to be able to find ActiveRecord::SessionStore::Extension::LoggerSilencer in the codebase anymore.

Could this be related to some of the underlying dependencies?

-    activerecord-session_store (1.1.3)
-      actionpack (>= 4.0)
-      activerecord (>= 4.0)
+    activerecord-session_store (2.0.0)
+      actionpack (>= 5.2.4.1)
+      activerecord (>= 5.2.4.1)
      multi_json (~> 1.11, >= 1.11.2)
-      rack (>= 1.5.2, < 3)
-      railties (>= 4.0)
+      rack (>= 2.0.8, < 3)
+      railties (>= 5.2.4.1)

Ruby 2.7.2 Rails 6.1.2.1

jeremyburks-sikich commented 3 years ago

I ran into the same issue. ActiveRecord::SessionStore::Extension::LoggerSilencer was removed in this commit

I replaced my use of ActiveRecord::SessionStore::Extension::LoggerSilencer with the following.

Rails.logger.class.include ActiveSupport::LoggerSilence
swanson commented 3 years ago

Thanks! That seemed to resolve things for me as well. I'm curious if this should be pulled into this gem directly? Feels weird to require changes to logging in consuming applications.

jeremyburks-sikich commented 3 years ago

@swanson Does your app use a logger other than the default? For example, mine does which is why I need to include ActiveSupport::LoggerSilence.

It looks like the default logger includes ActiveSupport::LoggerSilence.

swanson commented 3 years ago

@swanson Does your app use a logger other than the default? For example, mine does which is why I need to include ActiveSupport::LoggerSilence.

It looks like the default logger includes ActiveSupport::LoggerSilence.

Hmm, I didn't think I was using anything fancy, but I did notice that in my test environment I am setting config.logger = Logger.new(nil) which may be the problem.

swanson commented 3 years ago

@jeremyburks-sikich Thanks for the pointer, that was the problem in my case! :heart:

powerwlsl commented 3 years ago

Hi, I'm having the same issue after 2.0.0 upgrade. Where should I put the following code?

Rails.logger.class.include ActiveSupport::LoggerSilence

I don't see any ActiveRecord::SessionStore::Extension::LoggerSilencer in my repo.

swanson commented 3 years ago

Hi, I'm having the same issue after 2.0.0 upgrade. Where should I put the following code?

Rails.logger.class.include ActiveSupport::LoggerSilence

I don't see any ActiveRecord::SessionStore::Extension::LoggerSilencer in my repo.

You could put it in your initializer: config/initializers/session_store.rb

powerwlsl commented 3 years ago

Hey @swanson, thanks for the reply. I added that in the initializer file, but I still get the error.

NoMethodError: undefined method `silence' for #<Logger:0x000055de16b77330>

    /usr/local/bundle/gems/activerecord-session_store-2.0.0/lib/action_dispatch/session/active_record_store.rb:119:in `get_session_model'

    /usr/local/bundle/gems/activerecord-session_store-2.0.0/lib/action_dispatch/session/active_record_store.rb:147:in `find_session'

Oddly it only happens on staging, so I also added

    logger           = ActiveSupport::Logger.new(STDOUT)
    logger.formatter = config.log_formatter
    config.logger    = ActiveSupport::TaggedLogging.new(logger)

into config/environments/stage.rb, but the error didn't go away.

Do you have any idea? image

Ruby 2.5.3 Rails 6.0.3.5

swanson commented 3 years ago

@powerwlsl Maybe compare staging.rb to production.rb and see if you can isolate any differences. Not sure though, I only was having trouble in my test environment.

Not sure it helps but I have these logging related lines in my staging and production environment configs:

  # Use the lowest log level to ensure availability of diagnostic information
  # when problems arise.
  config.log_level = :debug

  # Prepend all log lines with the following tags.
  config.log_tags = [ :request_id ]

  # Use default logging formatter so that PID and timestamp are not suppressed.
  config.log_formatter = ::Logger::Formatter.new

  # Use a different logger for distributed setups.
  # require 'syslog/logger'
  # config.logger = ActiveSupport::TaggedLogging.new(Syslog::Logger.new 'app-name')

  if ENV["RAILS_LOG_TO_STDOUT"].present?
    logger           = ActiveSupport::Logger.new(STDOUT)
    logger.formatter = config.log_formatter
    config.logger    = ActiveSupport::TaggedLogging.new(logger)
  end

In my case, I removed the config.logger = Logger.new(nil) setting in my test environment and that solved the issue without add Rails.logger.class.include ActiveSupport::LoggerSilence.

evangallup commented 3 years ago

This causes issues with GELF and Lograge, previously we used

GELF::Logger.send :include, ActiveRecord::SessionStore::Extension::LoggerSilencer
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

which resulted in an error and a failed deploy, I tried changing this to

GELF::Logger.send :include, ActiveSupport::LoggerSilence
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

This no longer causes an error or failed deploy, but now we don't have any logs... which is obviously a huge problem.

Any ideas?

swanson commented 3 years ago

@byroot Any ideas?

evangallup commented 3 years ago

If anyone else is having this issue, I forked the project and added ActiveRecord::SessionStore::Extension::LoggerSilencer back in to version 2.0.0 with the CVE fix.

That fork is located here: https://github.com/egallup02360/activerecord-session_store

Can confirm my logging works through GELF/Lograge->Graylog and the session IDs are properly secured with this fork. Obviously we would want to continue with the official repo at some point if a workaround or solution is found for this particular issue.

byroot commented 3 years ago

@byroot Any ideas?

It's all explained in this issue and in my commit, ActiveRecord::Base.logger is expected to implement the logger silencer interface on its own. If it doesn't your are responsible for extending it yourself.

#<Logger:0x0000555d12a49218> is the stdlib logger, use ActiveSupport::Logger instead.

evangallup commented 3 years ago

It's all explained in this issue and in my commit, ActiveRecord::Base.logger is expected to implement the logger silencer interface on its own. If it doesn't your are responsible for extending it yourself.

#<Logger:0x0000555d12a49218> is the stdlib logger, use ActiveSupport::Logger instead.

Thanks for the reply, I tried changing

GELF::Logger.send :include, ActiveRecord::SessionStore::Extension::LoggerSilencer
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

to

GELF::Logger.send :include, ActiveSupport::Logger
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

And my deploy fails giving an error of (first message in traceback)

TypeError: wrong argument type Class (expected Module)

I already tried, what this issue suggests with

GELF::Logger.send :include, ActiveSupport::LoggerSilence
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

Deploy succeeds, but nothing is transmitted to our Graylog cluster.

I confirmed this by running ngrep -W byline -d any udp and host ENV['LOGGING_SERVER'] and dst port ENV['LOGGING_PORT'] and watching the output when navigating around our rails app.

We haven't upgraded the gem to 2.0 in our production environment yet (due to these issues we're having with our logging solution), so I ran the ngrep command above there and I see messages sent. I run the same command in our staging environment with gem version 2.0 and I see no messages being sent at all.

Clearly ActiveRecord::SessionStore::Extension::LoggerSilencer implements something in a way that ActiveSupport::LoggerSilence doesn't.

I should point out that your README still reads

Please note that you will need to manually include the silencer module to your custom logger if you are using a logger other than Logger and Syslog::Logger and their subclasses:

MyLogger.send :include, ActiveRecord::SessionStore::Extension::LoggerSilencer

This silencer is being used to silence the logger and not leaking private information into the log, and it is required for security reason.

But obviously that doesn't work anymore with the official gem at version 2.0.

I understand that this upgrade was of an urgent priority due to the nature of the CVE, but people who use custom logging solutions are going to have problems with the removal of the LoggerSilencer extension.

Could you take a deeper look at another way to rectify the situation?

Edit: Also, I'm not asking you to drop everything and fix this, it's not of an urgent priority. I'm just going to continue using our fork where I manually added ActiveRecord::SessionStore::Extension::LoggerSilencer back in, but like I said we would ideally want to be using the official gem.

byroot commented 3 years ago

GELF::Logger.send :include, ActiveSupport::Logger

I mentioned ActiveSupport::Logger as an answer to @swanson who pinged me not to you. Not sure what made you think AS::Logger could be included.

The AS module that can be included is https://api.rubyonrails.org/classes/ActiveSupport/LoggerSilence.html

evangallup commented 3 years ago

GELF::Logger.send :include, ActiveSupport::Logger

I mentioned ActiveSupport::Logger as an answer to @swanson who pinged me not to you. Not sure what made you think AS::Logger could be included.

The AS module that can be included is https://api.rubyonrails.org/classes/ActiveSupport/LoggerSilence.html

Using MyLogger.include ActiveSupport::LoggerSilence or more accurately for my use case GELF::Logger.include ActiveSupport::LoggerSilence or GELF::Logger.send :include, ActiveSupport::LoggerSilence does not work.

No errors in sight. I just stop receiving my application logs. Should I open a separate issue for this?

byroot commented 3 years ago

I just stop receiving my application logs.

It's either misconfigured (LoggerSilence makes the level a per thread variable, which might impact you configuration) or GELF::Logger is incompatible with LoggerSilence. Is GELF open source? Can you repo in isolation?

Should I open a separate issue for this?

No, this isn't a problem with activerecord-session_store, it expects a contract from ActiveRecord::Base.logger, and the logger in your app doesn't fulfil that contract. That's on you to figure it out.

Alternatively if you just want an easy way out, you can vendor the old ActiveRecord::SessionStore::Extension::LoggerSilencer in your app and just use that (you'll have to rename the method though).

evangallup commented 3 years ago

I just stop receiving my application logs.

It's either misconfigured (LoggerSilence makes the level a per thread variable, which might impact you configuration) or GELF::Logger is incompatible with LoggerSilence. Is GELF open source? Can you repo in isolation?

Should I open a separate issue for this?

No, this isn't a problem with activerecord-session_store, it expects a contract from ActiveRecord::Base.logger, and the logger in your app doesn't fulfil that contract. That's on you to figure it out.

Alternatively if you just want an easy way out, you can vendor the old ActiveRecord::SessionStore::Extension::LoggerSilencer in your app and just use that (you'll have to rename the method though).

That's fair, and I'm going to find my own way around this, I do appreciate your responses and suggestions. I'd just like to point out that prior to upgrading this gem, and only this gem, that logging worked perfectly for my use case.

This is just my opinion, but ripping an extension out that is documented in your README without a prior release that includes a depreciation warning is bad practice. Rails, in general, is really good about doing this, why is activerecord-session_store any different?

I understand patching the CVE was urgent, but that could have been fixed in a minor release rather than introducing almost two years worth of undocumented changes, since your last release, all at once. Again, just my opinion.

Thank you for your continued work on this project and I hope my opinions don't offend you or come off as rude, that's not my intention at all. We're on Github for collaboration and sharing our opinions, after all.

cnhuye commented 3 years ago

Since I upgraded to rails6.1, I met this problem. finally, I fixed by add this line in application.rb:

ActiveRecord::Base.logger.class.include ActiveSupport::LoggerSilence

because in my project, Rails.logger use ActiveSupport::Logger, but ActiveRecord::Base.logger use Logger.

JoBalk commented 3 years ago

The solution from @cnhuye works with ruby 2.7, but with ruby 3 it fails with:

class variable @@logger of ActiveRecord::Base is overtaken by Spawn (RuntimeError)

Has anyone experienced this issue?

robbanp commented 1 year ago

This causes issues with GELF and Lograge, previously we used

GELF::Logger.send :include, ActiveRecord::SessionStore::Extension::LoggerSilencer
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

which resulted in an error and a failed deploy, I tried changing this to

GELF::Logger.send :include, ActiveSupport::LoggerSilence
config.logger = GELF::Logger.new(ENV['LOGGING_SERVER'], ENV['LOGGING_PORT'], "WAN", { :facility => "Testing", :protocol => GELF::Protocol::UDP })

This no longer causes an error or failed deploy, but now we don't have any logs... which is obviously a huge problem.

Any ideas?

Hi, did you manage to solve this? I've spent a few days on this now without a solution :/