Trouble capturing logs from with Task.start/1 calls

Questions / Help
1

Hi!

I’m trying to test the log output from a function that wraps Task.start/1 and capture_log/2 is failing to capture the log output.

defmodule Foo do
  require Logger
  def async_and_log do
    Task.start(fn ->
      # stuff
      # more stuff
      Logger.info("Hi there")
    )
  end
end

defmodule FooTest do
  use ExUnit.Case, async: true
  import ExUnit.CaptureLog

  test "async_and_log/0" do
    log =
      capture_log(fn ->
        Foo.async_and_log()
      end)

    assert log =~ "Hi" # fails
  end
end

I saw @josevalim’s SO post on the topic, but I thought capture_log/2 was supposed to handle this case? Maybe I’m reading the docs incorrectly.

However, capture_log does not guarantee to capture log messages originated from processes spawned using a low level Kernel spawn function (e.g. Kernel.spawn/1 ) and such processes exit with an exception or a throw. Therefore, prefer using a Task , or other OTP process, will send explicit logs before its exit or monitor signals and will not cause VM generated log messages.

Maybe there’s a different pattern I should be using here?

Thanks for your help!

2

An option would be to lift the Task.start/1 call up to the caller… maybe that’s what I’ll do for now, though I’m still curious if my first example is supposed to work or I’m being a little dense.

3

Your first example is not supposed to work. The async_and_log function returns immediately while doing all of the work (and logging) in a separate process. Consequently the anonymous function you’re passing to capture_log also returns immediately, and then the test itself quits. Meanwhile your spawned process does work, and may well log after the entire test has finished.

4 Likes