Tagged_logging breaks indefinite evaluation of block parameters #14374

Closed
k00ka opened this Issue Mar 13, 2014 · 4 comments

Comments

Projects
None yet
4 participants

k00ka commented Mar 13, 2014

One of the great things about the logger and block parameters is that the blocks are not evaluated if the logged message is at a level below the current logger level. This makes, for instance, expensive debugging evaluations disappear when logged in production. With TaggedLogging, the blocks are evaluated before the determination of logger level, meaning this benefit is lost. Options are:

  1. surround the logger call with a test (ugly),
  2. replace the default logger with something different.

I suspect for many people no. 2 is the option, since many people would log using the SysLogger. For those who are not, the evaluation of the block is unexpected and not obvious (since nothing gets logged). They are silently paying the price and missing out on the benefit.

To reproduce, I used the following block with the debugger gem in an environment with config.log_level = :info:
logger.debug { debugger }
With TaggedLogging (default logger) the breakpoint will be hit. With the BufferedLogger alone, the block is not evaluated.

@senny senny added the activesupport label Mar 17, 2014

Member

senny commented Mar 17, 2014

@k00ka I tried to reproduce this in our test suite but wasn't able to. I used the following test-case:

  test "does not evaluate blocks with ignored log level" do
    @logger.level = Logger::WARN
    @logger.tagged "OMG" do
      @logger.info do
        fail "DAMN!"
      end
    end
  end

this test passed. It failed when I changed the level to something that is logged, like DEBUG or INFO. Can you paste a modified test that reproduces your error?

The test-case is here: https://github.com/rails/rails/blob/master/activesupport/test/tagged_logging_test.rb

This seems to be version-dependent. I can reproduce the bug with activesupport 3.2.17 but not with 4.0.3.

k00ka commented Mar 18, 2014

Thanks Kliuless. I was going try to with edge rails, but had no gotten to it yet. You are correct, the issue came from my use of 3.2.17.
Looking at how TaggedLogging is implemented in 3.2, it's apparent that the complaint I have is a necessity (because of the way the wrapper works, the tags must be added outside the actual logger). I assume that this limitation is either fixed or worked-around in 4.x.
If so, I am ok to withdraw the bug, with the caveat that others using 3.2.17 may run into the same issue and feel the need to report it (or at least spend the time to dig into the issue as I have).

Owner

rafaelfranca commented Mar 18, 2014

I'm closing since it is not a Rails 4 issue

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment