Skip to content

Instantly share code, notes, and snippets.

@kares
Last active August 29, 2015 13:57
Show Gist options
  • Star 3 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save kares/9374772 to your computer and use it in GitHub Desktop.
Save kares/9374772 to your computer and use it in GitHub Desktop.
Silencing a Rails.logger is (still) not thread-safe ... these initializers will try it's best to avoid your loggers being silenced (and more)! Must have for JRuby.
# put this under **#{Rails.root}/config/initializers** directory
# `silence` is like Chuck Norris you can't kill it, this biuty got yet again
# re-invented in Rails 4 right after Logger#silence got deprecated in 3.2 :)
begin
require 'active_support/logger'
require 'active_support/logger_silence'
ActiveSupport::Logger.silencer = false # silence simply yields
# if 'active_support/core_ext/logger' is loaded
# the LoggerSilencer gets included into Logger
Logger.silencer = false if Logger.respond_to?(:silencer)
rescue LoadError
begin
require 'active_support/buffered_logger'
ActiveSupport::BufferedLogger.silencer = false
rescue LoadError
end
# it's deprecated since 4.0 but not on 3.2 (been around since 2.3)
require 'active_support/core_ext/logger'
Logger.silencer = false
end
# the final frontier is ActiveRecord::Base.silence (2.3 - 3.2)
# used mostly in ActiveRecord::SessionStore, that one comes
# from "abusing" the extended ActiveSupport::Benchmarkable
if ActiveSupport.const_defined?(:Benchmarkable)
ActiveSupport::Benchmarkable.module_eval do
# NOTE: there's no other way but to monkey-patch :
def silence
# if the logger manages to handle silence "thread-safe"
# it will work, otherwise the logger's silencer = false
if ( logger = self.logger ).respond_to?(:silence)
logger.silence { yield }
else
yield
end
end
end
else
ActiveRecord::Base.class_eval do
# Method implemented directly on AR::Base (2.3) :
def self.silence
# if the logger manages to handle silence thread-safe
# it will work, otherwise the logger's silencer = false
if ( logger = self.logger ).respond_to?(:silence)
logger.silence { yield }
else
yield
end
end
end if defined? ActiveRecord::Base.silence
end
# NOTE: a "simple" alternative for all of the above might be :
#
# logger = Rails.logger; def logger.level=(level) end
#
begin
require 'active_support/core_ext/kernel/reporting'
rescue LoadError
end
module Kernel
def warn(message)
super if is_current_thread_verbose?
end
def silence_warnings
verbose = is_current_thread_verbose?
set_current_thread_verbose(false)
yield
ensure
set_current_thread_verbose(verbose)
end
def enable_warnings
verbose = is_current_thread_verbose?
set_current_thread_verbose(true)
yield
ensure
set_current_thread_verbose(verbose)
end
# used from methods such as {#quietly} :
# silence_stream(STDOUT) do
# silence_stream(STDERR) do
# yield
# end
# end
# or {#silence_stderr} `silence_stream(STDERR) { yield }`
def silence_stream(stream)
do_silence_stream!(stream, true)
yield
ensure
do_silence_stream!(stream, false)
end
# since AS 3.1 {#silence} is aliased as {#capture},
# we leave `capture` as is but "re-invent" `silence`
def silence(stream); silence_stream(stream); nil end
private
# a `$VERBOSE = verbose` replacement
def set_current_thread_verbose(verbose)
verbose # not implemented
end
def is_current_thread_verbose?
$VERBOSE
end
# a `$VERBOSE = verbose` replacement
def do_silence_stream!(stream, silence)
return stream if silence || true # not implemented
end
end if defined? Kernel.silence_stream
@harikrishnan83
Copy link

I am using Puma with MRI. Not sure if I need this because MRI has a GIL. Just thinking if one of the Puma threads gets pre-empted can this issue happen even in MRI?

@jjb
Copy link

jjb commented Mar 27, 2014

@kares what are the pros and cons of the "simple' alternative" that you mention?

@kares
Copy link
Author

kares commented Mar 27, 2014

@harikrishnan83 I think some of it might be reproduced with MRI as well although it might be seen less - one thread enters the silencing block changing the level, than does IO so another thread might run Ruby code entering silence as well but it sees the "original" logger.level as ERROR (changed by the first one) ... etc.

currently mostly seen to happen with AR 4.0's store rails/activerecord-session_store#19

@jjb the obvious pro is it's a one liner the con is logger.level= will never really work which I personally dislike

@harikrishnan83
Copy link

@kares Thanks for the clarification. On Puma this issue is very frequent. When I changed Puma configuration to one Thread per Process, this problem disappeared.

So if we have to use Puma with Threading even on MRI your Gist is necessary.

I am curious about how your Gist impacts the amount logs that get generated. Will keep you posted on how it goes.

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