Merge pull request #49417 from Edouard-chin/ec-logger-fix

Fix the BroadcastLogger being initialized too late:
This commit is contained in:
Rafael Mendonça França 2023-09-29 15:45:03 -04:00 committed by GitHub
commit db2ef1d250
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
9 changed files with 87 additions and 6 deletions

@ -67,7 +67,7 @@ class Railtie < Rails::Railtie # :nodoc:
unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT) unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT)
console = ActiveSupport::Logger.new(STDERR) console = ActiveSupport::Logger.new(STDERR)
console.level = Rails.logger.level console.level = Rails.logger.level
Rails.logger = ActiveSupport::BroadcastLogger.new(Rails.logger, console) Rails.logger.broadcast_to(console)
end end
ActiveRecord.verbose_query_logs = false ActiveRecord.verbose_query_logs = false
end end

@ -202,5 +202,17 @@ def fatal!
def dispatch(&block) def dispatch(&block)
@broadcasts.each { |logger| block.call(logger) } @broadcasts.each { |logger| block.call(logger) }
end end
def method_missing(name, *args)
loggers = @broadcasts.select { |logger| logger.respond_to?(name) }
if loggers.none?
super(name, *args)
elsif loggers.one?
loggers.first.send(name, *args)
else
loggers.map { |logger| logger.send(name, *args) }
end
end
end end
end end

@ -14,9 +14,16 @@ class Logger < ::Logger
# ActiveSupport::Logger.logger_outputs_to?(logger, STDOUT) # ActiveSupport::Logger.logger_outputs_to?(logger, STDOUT)
# # => true # # => true
def self.logger_outputs_to?(logger, *sources) def self.logger_outputs_to?(logger, *sources)
logdev = logger.instance_variable_get(:@logdev) loggers = if logger.is_a?(BroadcastLogger)
logger_source = logdev.dev if logdev.respond_to?(:dev) logger.broadcasts
sources.any? { |source| source == logger_source } else
[logger]
end
logdevs = loggers.map { |logger| logger.instance_variable_get(:@logdev) }
logger_sources = logdevs.filter_map { |logdev| logdev.dev if logdev.respond_to?(:dev) }
(sources & logger_sources).any?
end end
def initialize(*args, **kwargs) def initialize(*args, **kwargs)

@ -244,6 +244,30 @@ def info(msg, &block)
assert_not_predicate(@logger, :fatal?) assert_not_predicate(@logger, :fatal?)
end end
test "calling a method that no logger in the broadcast have implemented" do
assert_raises(NoMethodError) do
@logger.non_existing
end
end
test "calling a method when *one* logger in the broadcast has implemented it" do
logger = BroadcastLogger.new(CustomLogger.new)
assert(logger.foo)
end
test "calling a method when *multiple* loggers in the broadcast have implemented it" do
logger = BroadcastLogger.new(CustomLogger.new, CustomLogger.new)
assert_equal([true, true], logger.foo)
end
test "calling a method when a subset of loggers in the broadcast have implemented" do
logger = BroadcastLogger.new(CustomLogger.new, FakeLogger.new)
assert(logger.foo)
end
class CustomLogger class CustomLogger
attr_reader :adds, :closed, :chevrons attr_reader :adds, :closed, :chevrons
attr_accessor :level, :progname, :formatter, :local_level attr_accessor :level, :progname, :formatter, :local_level
@ -258,6 +282,10 @@ def initialize
@formatter = nil @formatter = nil
end end
def foo
true
end
def debug(message, &block) def debug(message, &block)
add(::Logger::DEBUG, message, &block) add(::Logger::DEBUG, message, &block)
end end

@ -28,6 +28,16 @@ def test_log_outputs_to
assert_not Logger.logger_outputs_to?(@logger, STDOUT, STDERR), "Expected logger_outputs_to? to STDOUT or STDERR 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 end
def test_log_outputs_to_with_a_broadcast_logger
logger = ActiveSupport::BroadcastLogger.new(Logger.new(STDOUT))
assert(Logger.logger_outputs_to?(logger, STDOUT))
assert_not(Logger.logger_outputs_to?(logger, STDERR))
logger.broadcast_to(Logger.new(STDERR))
assert(Logger.logger_outputs_to?(logger, STDERR))
end
def test_write_binary_data_to_existing_file def test_write_binary_data_to_existing_file
t = Tempfile.new ["development", "log"] t = Tempfile.new ["development", "log"]
t.binmode t.binmode

@ -3416,7 +3416,7 @@ Below is a comprehensive list of all the initializers found in Rails in the orde
* `load_active_support`: Requires `active_support/dependencies` which sets up the basis for Active Support. Optionally requires `active_support/all` if `config.active_support.bare` is un-truthful, which is the default. * `load_active_support`: Requires `active_support/dependencies` which sets up the basis for Active Support. Optionally requires `active_support/all` if `config.active_support.bare` is un-truthful, which is the default.
* `initialize_logger`: Initializes the logger (an `ActiveSupport::Logger` object) for the application and makes it accessible at `Rails.logger`, provided that no initializer inserted before this point has defined `Rails.logger`. * `initialize_logger`: Initializes the logger (an `ActiveSupport::BroadcastLogger` object) for the application and makes it accessible at `Rails.logger`, provided that no initializer inserted before this point has defined `Rails.logger`.
* `initialize_cache`: If `Rails.cache` isn't set yet, initializes the cache by referencing the value in `config.cache_store` and stores the outcome as `Rails.cache`. If this object responds to the `middleware` method, its middleware is inserted before `Rack::Runtime` in the middleware stack. * `initialize_cache`: If `Rails.cache` isn't set yet, initializes the cache by referencing the value in `config.cache_store` and stores the outcome as `Rails.cache`. If this object responds to the `middleware` method, its middleware is inserted before `Rack::Runtime` in the middleware stack.

@ -56,6 +56,10 @@ module Bootstrap
end end
Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase) Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase)
broadcast_logger = ActiveSupport::BroadcastLogger.new(Rails.logger)
broadcast_logger.formatter = Rails.logger.formatter
Rails.logger = broadcast_logger
unless config.consider_all_requests_local unless config.consider_all_requests_local
Rails.error.logger = Rails.logger Rails.error.logger = Rails.logger
end end

@ -80,7 +80,7 @@ def log_to_stdout
console.level = Rails.logger.level console.level = Rails.logger.level
unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT) unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT)
Rails.logger = ActiveSupport::BroadcastLogger.new(Rails.logger, console) Rails.logger.broadcast_to(console)
end end
end end

@ -3,6 +3,7 @@
require "abstract_unit" require "abstract_unit"
require "console_helpers" require "console_helpers"
require "plugin_helpers" require "plugin_helpers"
require "net/http"
class Rails::Engine::CommandsTest < ActiveSupport::TestCase class Rails::Engine::CommandsTest < ActiveSupport::TestCase
include ConsoleHelpers include ConsoleHelpers
@ -57,6 +58,25 @@ def test_server_command_work_inside_engine
ensure ensure
kill(pid) kill(pid)
end end
def test_server_command_broadcast_logs
primary, replica = PTY.open
pid = spawn_command("server", replica, env: { "RAILS_ENV" => "development" })
assert_output("Listening on", primary)
Net::HTTP.new("127.0.0.1", 3000).tap do |net|
net.get("/")
end
in_plugin_context(plugin_path) do
logs = File.read("test/dummy/log/development.log")
assert_match("Processing by Rails::WelcomeController", logs)
end
assert_output("Processing by Rails::WelcomeController", primary)
ensure
kill(pid)
end
end end
private private