ExUnit.CaptureLog assert capture_log/2 not capturing level "info"

Can you please confirm how you are calling Logger.info? The API used in your example above is invalid and will raise an ArgumentError.

Oops, that was a type, now fixed. The test runs with the following result:

  1) test rate_limit plug rate_limit/2 puts 429 status if rate limit is exceeded (Api.RateLimitTest)
     test/lib/api/rate_limit_test.exs:20
     Assertion with =~ failed
     code:  capture_log([level: :info], fn ->
              conn = Api.RateLimit.rate_limit(conn, opts)
              assert(conn.status() == 429)
            end) =~ "Rate limit violation for bucket"
     left:  ""
     right: "Rate limit violation for bucket"
     stacktrace:
       test/lib/api/rate_limit_test.exs:24: anonymous fn/5 in Api.RateLimitTest.test rate_limit plug rate_limit/2 puts 429 status if rate limit is exceeded/1
       test/lib/api/rate_limit_test.exs:22: (test)

Can you please provide a sample application that reproduces the error? Because for all intents and purposes it should just work.

Sure thing! Here’s my sample application: GitHub - wfgilman/log_capture_test: Example App Testing ExUnit.CaptureLog capture_log/2 assertion. · GitHub

There’s two tests to demonstrate: one for warn and one for info. The first passes and the other does not.

@wfgilman Have you looked at: log_capture_test/config/test.exs at master · wfgilman/log_capture_test · GitHub

# Print only warnings and errors during test
config :logger, level: :warn

And considering the test that is not passing runs this code: log_capture_test/lib/log_capture/rate_limit.ex at master · wfgilman/log_capture_test · GitHub

def rate_limit(conn, _opts) do
  Logger.info(fn -> "Rate limit violation" end)
  conn
end

It will not print anything, hence why it does not pass. ^.^

You need to adjust the test config to be :info instead of :warn or so.

Ah, yes I overlooked that. I updated the config and that test passed. Thanks for spotting that. By default, capture_log/2 is supposed to capture all logs, but I need to make sure the application is emitting all logs for that to work

Lol, I’ve hit the exact same thing before. It is ‘interesting’ since the config completely eliminates the calls altogether once compiled.

I had this exact issue, changing to level: :info worked wonders.

However, now my test output is really noisy. Any way to get the benefits of warn with respect to test output but still able to capture info?

Am I reading this incorrectly? elixir/lib/ex_unit/lib/ex_unit/capture_log.ex at v1.7.4 · elixir-lang/elixir · GitHub

It is possible to configure the level to capture with :level , which will set the capturing level for the duration of the capture, for instance, if the log level is set to :error any message with the lower level will be ignored. The default level is nil , which will capture all messages. The behaviour is undetermined if async tests change Logger level.

I would expect that, even if config :logger, level: :warn is set, that

capture_log([level: :info], fn ->
  Logger.info "..."
end)

would still capture, though that would seemingly contradict

The Logger.info/2 macro emits the provided message at the :info level. Note the arguments given to info/2 will only be evaluated if a message is logged. For instance, if the Logger level is set to :warn , :info messages are never logged and therefore the arguments given above won’t even be executed.

At the risk of terrible necroposting and of stating the obvious: I ran into this same problem and saw that the OP’s last remarks went unanswered. I found a solution, so maybe other googlers are helped by this:

Our test.exs had

config :logger,
 level: :warn 

and only by setting it to :info I could get my capture_log assertions to capture the relevant logs.

However, it totally polluted the test output. As described, setting the log level to :warn actually removes the :debug and :info level log statements from the compiled code entirely.

Fortunately, there’s a way around this:

# capture all logs...
config :logger,
  level: :debug

# ... but show only warnings and up on the console
config :logger, :console, 
  level: :warn

This works because Logger’s default backend, console, can be separately configured to filter log levels. That way the Logger.info calls etc are not removed from the code, but the console output is still sane.

I found it all to be documented pretty well in the Logger docs btw: Logger — Logger v1.20.2

Best. Necropost. Ever.

I must have missed it, so thank you for stating the obvious!

My logs are now much less noisy