Catching compile time Logger logs

I’ve been trying to test a project I’m working on where I emit compile-time logs through Logger, i.e., these Logger calls are inside macros that do some computations at compile-time.

Now I’m trying to test through ExUnit if these logs are being emitted correctly, through ExUnit.CaptureLog.capture_log/1. Since these are being logged at compile-time, when I run mix test my tests fail since no logs are being emitted at runtime.

I’ve been reading the docs but I can’t seem to find a way to test what is being emitted at compile-time. The Metaprogramming Elixir book also doesn’t cover this aspect of testing macros, I believe.

The only (and poor) way that I can think of is to write the output from the compilation process to a file and have my test suite check for the log messages in there through String.contains?.

What about using http://elixir-lang.org/docs/stable/elixir/Code.html#compile_string/2? :slight_smile:

1 Like

Using that function to compile the module and then trying to catch the logs? That seems logical! Gonna try that :slight_smile:

That is what I’d try, you have the compiling environment available when running tests, so… :slight_smile:

I’ve experimented with it and it does work! At least to a certain extent. I’ll have to experiment more to see how flexible this method can be. I’ll include an example below:

import ExUnit.CaptureLog
fun = fn -> Code.compile_string(File.read!("lib/example.ex") end
assert capture_log(fun) =~ "example log message 1"
assert capture_log(fun) =~ "example log message 2"

Right now the only downsides seem to be the need to run fun many times and not being able to separate the several compile-time logs into different test cases.

Nice! I’d always considered adding in tests for that but never got around to it yet, good to see that it works, even if a bit unwieldy. :slight_smile:

You should also be able to define modules inside the test and make sure those emit warnings:

test "hello" do
  assert capture_log(fn ->
    defmodule Hello do
      use SomeMacro
    end
  end) =~ "oops" 
end

That actually works?! I thought defmodules were always resolved by macros at compile-time. Hmm… Ideas…