Add debug info for log device

[TonyCTHsu]

What does this PR do?

Adding debug info for Logger::LogDevice

Motivation:

We have seen this flaky specs in CircleCI, especially with JRuby.

log writing failed. closed stream

The error cannot be reproduce locally but it seems to be pretty generic when trying to write to a closed stream.

logger = Logger.new('t.log')
logger.close       # => nil
logger.info('foo') # Prints "log writing failed. closed stream"

Source: https://github.com/ruby/ruby/blob/master/lib/logger/log_device.rb#L48

[ivoanjo]

Thanks for picking this up! Left a few notes :)

[ivoanjo]

I would suggest applying this in spec_helper.rb, as we have a few other similar tweaks for the test suite there; applying it via RUBYOPT may collide with other things we may be testing in the test suite. (Because it affects every ruby process that gets run, including e.g. bundler and whatnot)

[ivoanjo]

I would suggest using the same warn(...) mechanism that the logger does, because we're not actually sure that $stdout is open at this time -- it may have been closed.

Also, I'd suggest printing every thread (Thread.list) and their backtrace, so you'll know what may be staying over and perhaps making the app not quit.

Also, instrumenting every write and close may get a bit slow/chatty? I'd suggest instrumenting only when there's an exception, e.g. when we know the issue has been triggered.

[p-datadog]

warn should also output to standard error rather than standard output which I think would be more correct?

[lloeki]

• $stdout or STDOUT may also be taken over (say by some mock or stub). File.open(/dev/stdout)? (or err)?
• either or both of $stdout/err may or may not be closed. Might be worth querying and logging their state via $stdout.closed? as well?
• what about logging to a file?

Also, instrumenting every write and close may get a bit slow/chatty?

Let's get some (any) output first and see if we're having some patterns emerge (do we have logs? do logs continue after or stop at "the end"? do pids/tids match before and after "the end"?)

instrumenting only when there's an exception, e.g. when we know the issue has been triggered.

We dont' know what's causing it, or do we? Seems speculative to tie log output to a hypothetical.

[ivoanjo]

Is this change needed because of the RUBYOPT change? 🤔

[ivoanjo]

Also, you may want to check that the monkey patch works by e.g. creating a logger on a new stream (such as StringIO) and then closing it, and then checking we get all the relevant info :)

[codecov-commenter]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 98.11%. Comparing base (d673469) to head (163f5c7).
Report is 22 commits behind head on master.

Additional details and impacted files

@@           Coverage Diff           @@
##           master    #3699   +/-   ##
=======================================
  Coverage   98.11%   98.11%           
=======================================
  Files        1225     1225           
  Lines       72743    72743           
  Branches     3479     3479           
=======================================
  Hits        71371    71371           
  Misses       1372     1372           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.