kotovalexarian-likes-github/rails--rails
1
0
Fork 0
mirror of https://github.com/rails/rails.git synced 2022-11-09 12:12:34 -05:00
Code Releases Activity

* ActiveSupport::BufferedLogger#silence is deprecated. If you want to squelch

Browse source 
logs for a certain block, change the log level for that block.

*   ActiveSupport::BufferedLogger#open_log is deprecated.  This method should
    not have been public in the first place.

*   ActiveSupport::BufferedLogger's behavior of automatically creating the
    directory for your log file is deprecated.  Please make sure to create the
    directory for your log file before instantiating.

*   ActiveSupport::BufferedLogger#auto_flushing is deprecated.  Either set the
    sync level on the underlying file handle like this:

        f = File.open('foo.log', 'w')
        f.sync = true
        ActiveSupport::BufferedLogger.new f

    Or tune your filesystem.  The FS cache is now what controls flushing.

*   ActiveSupport::BufferedLogger#flush is deprecated.  Set sync on your
    filehandle, or tune your filesystem.
This commit is contained in:
Aaron Patterson 2011-12-09 16:03:18 -08:00
parent f79b257e0b
commit 04ef93dae6
6 changed files with 95 additions and 240 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

22
activesupport/CHANGELOG.md
View file

@ -47,6 +47,28 @@
* ActiveSupport::OrderedHash now has different behavior for #each and
\#each_pair when given a block accepting its parameters with a splat. *Andrew Radev*
* ActiveSupport::BufferedLogger#silence is deprecated. If you want to squelch
logs for a certain block, change the log level for that block.
* ActiveSupport::BufferedLogger#open_log is deprecated. This method should
not have been public in the first place.
* ActiveSupport::BufferedLogger's behavior of automatically creating the
directory for your log file is deprecated. Please make sure to create the
directory for your log file before instantiating.
* ActiveSupport::BufferedLogger#auto_flushing is deprecated. Either set the
sync level on the underlying file handle like this:
f = File.open('foo.log', 'w')
f.sync = true
ActiveSupport::BufferedLogger.new f
Or tune your filesystem. The FS cache is now what controls flushing.
* ActiveSupport::BufferedLogger#flush is deprecated. Set sync on your
filehandle, or tune your filesystem.
## Rails 3.1.0 (August 30, 2011) ##
* ActiveSupport::Dependencies#load and ActiveSupport::Dependencies#require now

110
activesupport/lib/active_support/buffered_logger.rb
View file

@ -1,5 +1,8 @@
require 'thread'
require 'logger'
require 'active_support/core_ext/class/attribute_accessors'
require 'active_support/deprecation'
require 'fileutils'
module ActiveSupport
# Inspired by the buffered logger idea by Ezra
@ -25,40 +28,35 @@ module ActiveSupport
# Silences the logger for the duration of the block.
def silence(temporary_level = ERROR)
if silencer
old_logger_level = @tmp_levels[Thread.current]
begin
@tmp_levels[Thread.current] = temporary_level
yield self
logger = self.class.new @log_dest, temporary_level
yield logger
ensure
if old_logger_level
@tmp_levels[Thread.current] = old_logger_level
else
@tmp_levels.delete(Thread.current)
end
logger.close
end
else
yield self
end
end
deprecate :silence
attr_writer :level
attr_reader :auto_flushing
deprecate :auto_flushing
def initialize(log, level = DEBUG)
@level = level
@tmp_levels = {}
@buffer = Hash.new { |h,k| h[k] = [] }
@auto_flushing = 1
@guard = Mutex.new
@log_dest = log
if log.respond_to?(:write)
@log = log
elsif File.exist?(log)
@log = open_log(log, (File::WRONLY | File::APPEND))
else
FileUtils.mkdir_p(File.dirname(log))
@log = open_log(log, (File::WRONLY | File::APPEND | File::CREAT))
unless log.respond_to?(:write)
unless File.exist?(File.dirname(log))
ActiveSupport::Deprecation.warn(<<-eowarn)
Automatic directory creation for '#{log}' is deprecated. Please make sure the directory for your log file exists before creating the logger.
eowarn
FileUtils.mkdir_p(File.dirname(log))
end
end
@log = open_logfile log
end
def open_log(log, mode)
@ -67,20 +65,18 @@ module ActiveSupport
open_log.sync = true
end
end
deprecate :open_log
def level
@tmp_levels[Thread.current] || @level
@log.level
end
def level=(l)
@log.level = l
end
def add(severity, message = nil, progname = nil, &block)
return if level > severity
message = (message || (block && block.call) || progname).to_s
# If a newline is necessary then create a new message ending with a newline.
# Ensures that the original message is not mutated.
message = "#{message}\n" unless message[-1] == ?\n
buffer << message
auto_flush
message
@log.add(severity, message, progname, &block)
end
# Dynamically add methods such as:
@ -104,62 +100,20 @@ module ActiveSupport
# never auto-flush. If you turn auto-flushing off, be sure to regularly
# flush the log yourself -- it will eat up memory until you do.
def auto_flushing=(period)
@auto_flushing =
case period
when true; 1
when false, nil, 0; MAX_BUFFER_SIZE
when Integer; period
else raise ArgumentError, "Unrecognized auto_flushing period: #{period.inspect}"
end
end
deprecate :auto_flushing=
def flush
@guard.synchronize do
write_buffer(buffer)
# Important to do this even if buffer was empty or else @buffer will
# accumulate empty arrays for each request where nothing was logged.
clear_buffer
# Clear buffers associated with dead threads or else spawned threads
# that don't call flush will result in a memory leak.
flush_dead_buffers
end
end
deprecate :flush
def close
flush
@log.close if @log.respond_to?(:close)
@log = nil
@log.close
end
protected
def auto_flush
flush if buffer.size >= @auto_flushing
end
def buffer
@buffer[Thread.current]
end
def clear_buffer
@buffer.delete(Thread.current)
end
# Find buffers created by threads that are no longer alive and flush them to the log
# in order to prevent memory leaks from spawned threads.
def flush_dead_buffers #:nodoc:
@buffer.keys.reject{|thread| thread.alive?}.each do |thread|
buffer = @buffer[thread]
write_buffer(buffer)
@buffer.delete(thread)
end
end
def write_buffer(buffer)
buffer.each do |content|
@log.write(content)
end
end
private
def open_logfile(log)
Logger.new log
end
end
end

3
activesupport/lib/active_support/tagged_logging.rb
View file

@ -38,9 +38,8 @@ module ActiveSupport
EOM
end
def flush(*args)
def flush
@tags.delete(Thread.current)
@logger.flush(*args) if @logger.respond_to?(:flush)
end
def method_missing(method, *args)

47
activesupport/test/benchmarkable_test.rb
View file

@ -3,8 +3,23 @@ require 'abstract_unit'
class BenchmarkableTest < ActiveSupport::TestCase
include ActiveSupport::Benchmarkable
def teardown
logger.send(:clear_buffer)
attr_reader :buffer, :logger
class Buffer
include Enumerable
def initialize; @lines = []; end
def each(&block); @lines.each(&block); end
def write(x); @lines << x; end
def close; end
def last; @lines.last; end
def size; @lines.size; end
def empty?; @lines.empty?; end
end
def setup
@buffer = Buffer.new
@logger = ActiveSupport::BufferedLogger.new(@buffer)
end
def test_without_block
@ -40,35 +55,7 @@ class BenchmarkableTest < ActiveSupport::TestCase
logger.level = ActiveSupport::BufferedLogger::DEBUG
end
def test_without_silencing
benchmark('debug_run', :silence => false) do
logger.info "not silenced!"
end
assert_equal 2, buffer.size
end
def test_with_silencing
benchmark('debug_run', :silence => true) do
logger.info "silenced!"
end
assert_equal 1, buffer.size
end
private
def logger
@logger ||= begin
logger = ActiveSupport::BufferedLogger.new(StringIO.new)
logger.auto_flushing = false
logger
end
end
def buffer
logger.send(:buffer)
end
def assert_last_logged(message = 'Benchmarking')
assert_match(/^#{message} \(.*\)$/, buffer.last)
end

139
activesupport/test/buffered_logger_test.rb
View file

@ -7,6 +7,7 @@ require 'active_support/buffered_logger'
class BufferedLoggerTest < Test::Unit::TestCase
include MultibyteTestHelpers
include ActiveSupport::Testing::Deprecation
Logger = ActiveSupport::BufferedLogger
@ -23,7 +24,10 @@ class BufferedLoggerTest < Test::Unit::TestCase
t.write 'hi mom!'
t.close
logger = Logger.new t.path
f = File.open(t.path, 'w')
f.binmode
logger = Logger.new f
logger.level = Logger::DEBUG
str = "\x80"
@ -32,7 +36,6 @@ class BufferedLoggerTest < Test::Unit::TestCase
end
logger.add Logger::DEBUG, str
logger.flush
ensure
logger.close
t.close true
@ -40,7 +43,10 @@ class BufferedLoggerTest < Test::Unit::TestCase
def test_write_binary_data_create_file
fname = File.join Dir.tmpdir, 'lol', 'rofl.log'
logger = Logger.new fname
f = File.open(fname, 'w')
f.binmode
logger = Logger.new f
logger.level = Logger::DEBUG
str = "\x80"
@ -49,7 +55,6 @@ class BufferedLoggerTest < Test::Unit::TestCase
end
logger.add Logger::DEBUG, str
logger.flush
ensure
logger.close
File.unlink fname
@ -104,34 +109,6 @@ class BufferedLoggerTest < Test::Unit::TestCase
assert_equal message_copy, @message
end
[false, nil, 0].each do |disable|
define_method "test_disabling_auto_flush_with_#{disable.inspect}_should_buffer_until_explicit_flush" do
@logger.auto_flushing = disable
4.times do
@logger.info 'wait for it..'
assert @output.string.empty?, "@output.string should be empty but it is #{@output.string}"
end
@logger.flush
assert !@output.string.empty?, "@logger.send(:buffer).size.to_s should not be empty but it is empty"
end
define_method "test_disabling_auto_flush_with_#{disable.inspect}_should_flush_at_max_buffer_size_as_failsafe" do
@logger.auto_flushing = disable
assert_equal Logger::MAX_BUFFER_SIZE, @logger.auto_flushing
(Logger::MAX_BUFFER_SIZE - 1).times do
@logger.info 'wait for it..'
assert @output.string.empty?, "@output.string should be empty but is #{@output.string}"
end
@logger.info 'there it is.'
assert !@output.string.empty?, "@logger.send(:buffer).size.to_s should not be empty but it is empty"
end
end
def test_should_know_if_its_loglevel_is_below_a_given_level
Logger::Severity.constants.each do |level|
@logger.level = Logger::Severity.const_get(level) - 1
@ -139,56 +116,17 @@ class BufferedLoggerTest < Test::Unit::TestCase
end
end
def test_should_auto_flush_every_n_messages
@logger.auto_flushing = 5
4.times do
@logger.info 'wait for it..'
assert @output.string.empty?, "@output.string should be empty but it is #{@output.string}"
end
@logger.info 'there it is.'
assert !@output.string.empty?, "@output.string should not be empty but it is empty"
end
def test_should_create_the_log_directory_if_it_doesnt_exist
tmp_directory = File.join(File.dirname(__FILE__), "tmp")
log_file = File.join(tmp_directory, "development.log")
FileUtils.rm_rf(tmp_directory)
@logger = Logger.new(log_file)
assert_deprecated do
@logger = Logger.new(log_file)
end
assert File.exist?(tmp_directory)
end
def test_logger_should_maintain_separate_buffers_for_each_thread
@logger.auto_flushing = false
a = Thread.new do
@logger.info("a"); Thread.pass;
@logger.info("b"); Thread.pass;
@logger.info("c"); @logger.flush
end
b = Thread.new do
@logger.info("x"); Thread.pass;
@logger.info("y"); Thread.pass;
@logger.info("z"); @logger.flush
end
a.join
b.join
assert @output.string.include?("a\nb\nc\n")
assert @output.string.include?("x\ny\nz\n")
end
def test_flush_should_remove_empty_buffers
@logger.send :buffer
@logger.expects :clear_buffer
@logger.flush
end
def test_buffer_multibyte
@logger.auto_flushing = 2
@logger.info(UNICODE_STRING)
@logger.info(BYTE_STRING)
assert @output.string.include?(UNICODE_STRING)
@ -198,57 +136,4 @@ class BufferedLoggerTest < Test::Unit::TestCase
end
assert byte_string.include?(BYTE_STRING)
end
def test_silence_only_current_thread
@logger.auto_flushing = true
run_thread_a = false
a = Thread.new do
while !run_thread_a do
sleep(0.001)
end
@logger.info("x")
run_thread_a = false
end
@logger.silence do
run_thread_a = true
@logger.info("a")
while run_thread_a do
sleep(0.001)
end
end
a.join
assert @output.string.include?("x")
assert !@output.string.include?("a")
end
def test_flush_dead_buffers
@logger.auto_flushing = false
a = Thread.new do
@logger.info("a")
end
keep_running = true
Thread.new do
@logger.info("b")
while keep_running
sleep(0.001)
end
end
@logger.info("x")
a.join
@logger.flush
assert @output.string.include?("x")
assert @output.string.include?("a")
assert !@output.string.include?("b")
keep_running = false
end
end

14
railties/lib/rails/application/bootstrap.rb
View file

@ -24,9 +24,18 @@ module Rails
initializer :initialize_logger, :group => :all do
Rails.logger ||= config.logger || begin
path = config.paths["log"].first
logger = ActiveSupport::TaggedLogging.new(ActiveSupport::BufferedLogger.new(path))
unless File.exist? File.dirname path
FileUtils.mkdir_p File.dirname path
end
f = File.open path, 'w'
f.binmode
f.sync = !Rails.env.production? # make sure every write flushes
logger = ActiveSupport::TaggedLogging.new(
ActiveSupport::BufferedLogger.new(f)
)
logger.level = ActiveSupport::BufferedLogger.const_get(config.log_level.to_s.upcase)
logger.auto_flushing = false if Rails.env.production?
logger
rescue StandardError
logger = ActiveSupport::TaggedLogging.new(ActiveSupport::BufferedLogger.new(STDERR))
@ -37,7 +46,6 @@ module Rails
)
logger
end
at_exit { Rails.logger.flush if Rails.logger.respond_to?(:flush) }
end
# Initialize cache early in the stack so railties can make use of it.