Adding logger metadata to Oban jobs with telemetry

At work we make heavy use of Oban for asynchronous reliable processes. We have many different workers that perform as many different tasks, and it is common to log information from those jobs.

We take advantage of logger metadata to enrich the log entries with some useful context such as the job ID, queue, arguments and attempt. Initially we did include the metadata on every logger call:

def MyApp.CustomWorker do
  use Oban.Worker

  require Logger

  def perform(job = %Oban.Job{}) do
    Logger.info("Doing the magic...",
      job_id: job.id,
      job_queue: job.queue,
      job_args: job.args,
      job_attempt: job.attempt
    )

    # Do the magic...

    Logger.info("Magic done!",
      job_id: job.id,
      job_queue: job.queue,
      job_args: job.args,
      job_attempt: job.attempt
    )
  end
end

As you can see this becomes a burden quickly as we need to repeat the metadata every time. Fortunately there is a better way if we leverage Oban’s telemetry events.

When Oban starts a job it emits the [:oban, :job, :start] event. We can attach our code to that event and set the relevant logger metadata for that process. This way anything that we log inside the worker will include that metadata.

defmodule MyApp.ObanTelemetry do
  # Take a look at https://hexdocs.pm/telemetry/readme.html
  # to se how to attach this event handler to the telemetry.
  def handle_event([:oban, :job, :start], _measures, %{job: job}, nil) do
    Logger.metadata(
      job_id: job.id,
      job_queue: job.queue,
      job_args: job.args,
      job_attempt: job.attempt
    )
  end
end

Since this happens automatically for every Oban job, we can now remove the logger metadata as it is already set for the current process.

def MyApp.CustomWorker do
  use Oban.Worker

  require Logger

  def perform(job = %Oban.Job{}) do
    Logger.info("Doing the magic...")

    # Do the magic...

    Logger.info("Magic done!")
  end
end