[close #22917] Don't output to STDOUT twice

When `rails console` or `rails server` are used along with a logger set to output to `STDOUT` then the contents will show up twice. This happens because the logger is extended with `ActiveSupportLogger.broadcast` with a destination of STDOUT even if it is already outputting to `STDOUT`.

Previously PR #22592 attempted to fix this issue, but it ended up causing NoMethodErrors. A better approach than relying on adding a method and flow control is to inspect the log destination directly. For this `ActiveSupport::Logger.logger_outputs_to?` was introduced

```ruby
logger = Logger.new(STDOUT)
ActiveSupport::Logger.logger_outputs_to?(logger, STDOUT)
# => true
```

To accomplish this we must look inside of an instance variable of standard lib's Logger `@logdev`. There is a related Ruby proposal to expose this method in a standard way: https://bugs.ruby-lang.org/issues/11955
This commit is contained in:
schneems 2016-01-05 16:23:43 -06:00
parent 9dcb1b9b07
commit 3d10d9d6c3
4 changed files with 29 additions and 7 deletions

@ -57,8 +57,10 @@ class Railtie < Rails::Railtie # :nodoc:
console do |app|
require "active_record/railties/console_sandbox" if app.sandbox?
require "active_record/base"
console = ActiveSupport::Logger.new(STDERR)
Rails.logger.extend ActiveSupport::Logger.broadcast console
unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT)
console = ActiveSupport::Logger.new(STDERR)
Rails.logger.extend ActiveSupport::Logger.broadcast console
end
end
runner do

@ -1,4 +1,3 @@
require 'active_support/core_ext/module/attribute_accessors'
require 'active_support/logger_silence'
require 'logger'
@ -6,6 +5,17 @@ module ActiveSupport
class Logger < ::Logger
include LoggerSilence
# Returns true if the logger destination matches one of the sources
#
# logger = Logger.new(STDOUT)
# ActiveSupport::Logger.logger_outputs_to?(logger, STDOUT)
# # => true
def self.logger_outputs_to?(logger, *sources)
logdev = logger.instance_variable_get("@logdev")
logger_source = logdev.dev if logdev.respond_to?(:dev)
sources.any? { |source| source == logger_source }
end
# Broadcasts logs to multiple loggers.
def self.broadcast(logger) # :nodoc:
Module.new do

@ -17,6 +17,14 @@ def setup
@logger = Logger.new(@output)
end
def test_log_outputs_to
assert Logger.logger_outputs_to?(@logger, @output), "Expected logger_outputs_to? @output to return true but was false"
assert Logger.logger_outputs_to?(@logger, @output, STDOUT), "Expected logger_outputs_to? @output or STDOUT to return true but was false"
assert_not Logger.logger_outputs_to?(@logger, STDOUT), "Expected logger_outputs_to? to STDOUT to return false, but was true"
assert_not Logger.logger_outputs_to?(@logger, STDOUT, STDERR), "Expected logger_outputs_to? to STDOUT or STDERR to return false, but was true"
end
def test_write_binary_data_to_existing_file
t = Tempfile.new ['development', 'log']
t.binmode
@ -65,7 +73,7 @@ def test_should_log_debugging_message_when_debugging
def test_should_not_log_debug_messages_when_log_level_is_info
@logger.level = Logger::INFO
@logger.add(Logger::DEBUG, @message)
assert ! @output.string.include?(@message)
assert_not @output.string.include?(@message)
end
def test_should_add_message_passed_as_block_when_using_add
@ -129,7 +137,7 @@ def test_silencing_everything_but_errors
@logger.error "THIS IS HERE"
end
assert !@output.string.include?("NOT THERE")
assert_not @output.string.include?("NOT THERE")
assert @output.string.include?("THIS IS HERE")
end

@ -133,11 +133,13 @@ def create_tmp_directories
def log_to_stdout
wrapped_app # touch the app so the logger is set up
console = ActiveSupport::Logger.new($stdout)
console = ActiveSupport::Logger.new(STDOUT)
console.formatter = Rails.logger.formatter
console.level = Rails.logger.level
Rails.logger.extend(ActiveSupport::Logger.broadcast(console))
unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDOUT)
Rails.logger.extend(ActiveSupport::Logger.broadcast(console))
end
end
end
end