Oban/Telemetry error handling not capturing exceptions

Questions / Help
,
1

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!

1 Like
2

Hey @jonbo, you might be using an older version. The README is for the unreleased v2.0.0-rc, you can see the implementation of the error telemetry event for v1.2 here:

The documentation for the stable version can be found here: https://hexdocs.pm/oban/Oban.html#module-reporting-errors

Hope that helps.

4 Likes
3

That was it, many thanks @jeroenvisser101!

For the record, I attached the logger with:

:telemetry.attach_many(
  "oban-errors",
  [[:oban, :failure]],
  &Carriage.ErrorReporter.handle_event/4,
  nil
)

And the handler:

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

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

Thanks for solving this one @jeroenvisser101! This mismatch between the readme and the released version has been a persistent issue.

2 Likes
5

Not sure if it would help, but maybe adding a guides folder (like phoenix and others) and having the README just link to hexdocs would help?

1 Like
6

That’s the long term solution we’re aiming for. There is a guides folder and docs are moving over bit by bit.

1 Like