Error is raised when logging first occurs in a signal trap

[keithrbennett]

Environment

• Ruby Version: Probably all MRI versions, 2.7.6 and 3.1.2 were tested. (Error does not occur in JRuby.)
• Semantic Logger Version: 4.1.2

Expected Behavior

• When the application's first logging is done in a signal trap, no error should be raised.

Actual Behavior

• @eviljoel discovered that when the application's first logging is done in a signal trap, an error is raised.

In MRI Ruby, requires executed in a signal trip result in error. I am pasting two Ruby scripts at the bottom of this issue report that illustrate this, one with and the other without SemanticLogger, but below is a simple way to trigger the error in irb or pry:

Signal.trap('USR1') { require 'set' }
`kill -USR1 #{Process.pid}`

The result is:

...
ThreadError (can't be called from trap context)

It's not likely in most use cases I know of that no logging will be done in the entire application, nor that the timing of the loading would be significant, so my first choice to resolve this would be to eagerly load the files, i.e. require them instead of autoload them.

Unless and until that happens, here is a workaround. The method below needs to be called before the signal handling traps are set.

  # SemanticLogger autoloads much of its code, and requires cannot be done in a signal trap,
  # so if the first logging statement of the application occurs in a signal trap, an error
  # will be raised.
  #
  # To eliminate this risk, this method can be called before signal handling is registered.
  #
  # It creates and installs a dummy appender, logs to it, then removes it.
  #
  # Although it is not necessary to add the appender to SemanticLogger, doing so guarantees that
  # any cleanup work defined in SemanticLogger.remove_appender (now and in the future)
  # will be executed.
def self.load_semantic_logger_autoloads
  appender = SemanticLogger::Appender::IO.new(StringIO.new)
  SemanticLogger.add_appender(appender: appender)
  appender.fatal 'Discarded log message to avoid load errors in traps.'
  SemanticLogger.remove_appender(appender)
end

Then, in the application setup (this is not a Rails application), we have something like this:

OurApp::SemanticLoggerHelper.load_semantic_logger_autoloads
OurApp::CLI::Signals.setup_traps

Is there any possibility we can change the behavior not to use autoload? Would this be a problem for anyone?

Pull Request

Not yet provided, as it is a nontrivial effort and requires some design discussion before implementation.

Full Scripts Used to Test This Issue

#!/usr/bin/env ruby

# require-in-signal-trap-raises-error.rb

Signal.trap('USR1') { require 'set' }
`kill -USR1 #{Process.pid}`
sleep 10

#!/usr/bin/env ruby

# require-in-signal-trap-raises-error-sl.rb

require 'semantic_logger'
require 'stringio'

SemanticLogger.add_appender(io: StringIO.new)
logger = SemanticLogger['demo']

Signal.trap('USR1') { logger.fatal 'fatal' }

`kill -USR1 #{Process.pid}`
sleep 10