rails loggers debugging logs

Question

I've inheritted a medium sized Rails app with lots of different logging approaches spread across the codebase. It's a bit of a mess and I'm lost why some logs are outputed and why some not.

Is there a way for the loggers to "announce themselves"/log some status information when being created? In a similar way to what logback does when you set debug="true"

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/aleksander.sumowski/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/aleksander.sumowski/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
11:28:33,076 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
11:28:33,076 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
11:28:33,076 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/aleksander.sumowski/projects/insurance/car-insurance-aggregator/resources/logback.xml]
11:28:33,168 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/Users/aleksander.sumowski/projects/insurance/car-insurance-aggregator/resources/logback.xml]
11:28:33,168 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 1 seconds
11:28:33,172 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
11:28:33,175 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
11:28:33,179 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
11:28:33,214 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
11:28:33,218 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
11:28:33,225 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1006624255 - Will use gz compression
11:28:33,228 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1006624255 - Will use the pattern log/archive/car-insurance-aggregator.%d{yyyy-MM-dd}.log for the active file
11:28:33,231 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern 'log/archive/car-insurance-aggregator.%d{yyyy-MM-dd}.log.gz'.
11:28:33,231 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
11:28:33,234 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Wed Nov 22 11:28:33 UTC 2017
11:28:33,235 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
11:28:33,236 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: log/car-insurance-aggregator.log
11:28:33,236 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [log/car-insurance-aggregator.log]
11:28:33,238 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [business_events] to INFO
11:28:33,238 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[business_events]
11:28:33,238 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
11:28:33,238 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
11:28:33,238 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
11:28:33,239 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@6ea1bcdc - Registering current configuration as safe fallback point
SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]
2017-11-22 11:28:34,266 [main] INFO  org.eclipse.jetty.util.log - Logging initialized @3093ms

Answer 1

Yeah, this is the beauty and the pain of ruby. I would start with overriding Rails.logger= method in config/application.rb with some (like you say) "announce".

Just add to config/application.rb something like that and watch the logs:

Rails.singleton_class.send('alias_method', :old_logger=, :logger=)
module Rails
  def self.logger=(value)
    puts "Hey logger '#{value.inspect}' starting!"
    self.old_logger = value
  end
end

Or what about just investigating of value of Rails.logger?