Oban/Telemetry error handling not capturing exceptions

Hi all,

Trying to figure out exceptions raised within an Oban task are not being caught by my error handler, even after registering it through Telemetry. I’m following along with the guide on the repo.

My handler (pretty much copied form docs):

defmodule MyApp.ErrorReporter do
  require Logger

  def handle_event([:oban, :job, :exception], measure, meta, _) do
    context =
      meta
      |> Map.take([:id, :args, :queue, :worker])
      |> Map.merge(measure)

    Logger.info("handling Oban exception")
    IO.inspect(meta, lablel: "meta")
    Honeybadger.notify(meta.error, context, meta.stack)
  end

  def handle_event([:oban, :circuit, :trip], _measure, meta, _) do
    context = Map.take(meta, [:name])

    Honeybadger.notify(meta.error, context, meta.stack)
  end
end

:ok = :telemetry.attach_many(
  "oban-errors",
  [[:oban, :job, :exception], [:oban, :circuit, :trip]],
  &Carriage.ErrorReporter.handle_event/4,
  nil
)

(Note that it’s a little odd that the attach_many call is happening here, instead of application.ex.. However, it does fire, as seen when wrapping it with IO.inspect()) and the docs have it in the error handler as well.

My Oban task:

defmodule MyApp.SendEmailAsync do
  use Oban.Worker, queue: :email, max_attempts: 1

  require Logger

  def perform(%{"param1" => param1}, _job) do
    Logger.info("the task is running!")
    raise "something went wrong"
  end

  def timeout(_job), do: :timer.seconds(60)
end

application.ex:

defmodule MyApp.Application do

  use Application
  
  def start(_type, _args) do

    ...

    :ok = Oban.Telemetry.attach_default_logger()

    ...

end

After running the server and executing the task, here’s what I see in logs:

[info] {"args":{"param1":"test"},"event":"started","queue":"email","source":"oban","start_time":1593026760599233,"worker":"MyApp.SendEmailAsync"}
[info] the task is running!
[info] {"args":{"param1":"test"},"duration":45834,"event":"failure","queue":"email","source":"oban","worker":"MyApp.SendEmailAsync"}

Output from the oban_jobs table:

 17 | discarded | email | MyApp.SendEmailAsync | {"param1": "test} | {"{\"at\": \"2020-06-24T19:26:00.602926Z\", \"error\": \"** (RuntimeError) something went wrong\\n    (my_app 0.2.0) lib/my_app/queues/email_sender.ex:20: MyApp.SendEmailAsync.perform/2\\n    (oban 1.2.0) lib/oban/queue/executor.ex:46: Oban.Queue.Executor.perform_inline/2\\n    (elixir 1.10.2) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2\\n    (elixir 1.10.2) lib/task/supervised.ex:35: Task.Supervised.reply/5\\n    (stdlib 3.11) proc_lib.erl:249: :proc_lib.init_p_do_apply/3\\n\", \"attempt\": 1}"}                                                                |       1 |            1 | 2020-06-24 19:26:00.586236 | 2020-06-24 19:26:00.586236 | 2020-06-24 19:26:00.592488 | 2020-06-24 19:26:00.602913 | {JonsMacbookPro,email,jjvmltj4} |              |        0 | {}

It’s clear that the Telemetry logging is working as expected, the task runs, and that it hits the exception.

However, my ErrorReporter handle_event/4 functions were never called (I don’t see meta in logs, nor did the Honeybadger error get reported).

I might be missing something pretty simple. Any help appreciated!