Logs not appearing in Oban for Finch requests

Questions / Help
1

I have 2 modules involved with a oban job with debug loggers, all of them are being logged into the console, except my finch request response

 def perform(%Oban.Job{attempt: attempt, meta: meta} = job) do
    Logger.debug("initing job....")
    Logger.debug(job.args)
    address = job.args["address"]
    target_value = job.args["target_value"]

    meta = Map.put_new_lazy(meta || %{}, "retrys", fn -> 0 end)

    case perform_request(address) do
      {:ok, response_value}-> handle_check_balance(response_value, target_value)
      {:error, :rate_limit} ->  choose_retry_queue(meta, attempt);
      {:error, reason} -> {:error, reason}
    end
  end

  def handle_check_balance(response_value, target_value) do
    CompareRealm.both_decimals_3floatpoints(response_value, target_value)
  end

  defp perform_request(address) do
    with {:ok, api_url} <- ApiLoadBalancerBlockchain.pick_api(),
         {:ok, response} <- RequestBalanceFileSolana.get_balance(address, api_url) do
      Logger.debug("Resposta do saldo: #{response}")
      {:ok, response}
    else
      {:error, :rate_limit} ->
        Logger.warning("Rate limit atingido")
        {:error, :rate_limit}

      {:error, reason} ->
        Logger.error("Erro na requisição: #{inspect(reason)}")
        {:error, reason}
    end
  end

  def choose_retry_queue(meta, attempt) do
    retrys = meta["retrys"]

    if retrys < @allowed_retrys do

      backoff = calculate_backoff(attempt)
      new_meta = Map.put(meta, "retrys", retrys + 1)

      {:snooze, backoff, meta: new_meta}
    else
      {:error, "Maximum rate limit retries (#{@allowed_retrys}) reached"}
    end
  end

  defp calculate_backoff(attempt) do
    # Backoff exponencial com limite máximo
    min(trunc(:math.pow(2, attempt) * 5), 300) # 5s, 10s, 20s... até 5 minutos
  end
end

request file

def get_balance(wallet_address, api_url) do
    Logger.debug("init request..")
    build_request(wallet_address, api_url)
    |> send_request()
    |> handle_response()
    |> extract_value()
  end
  def extract_value({:ok, value}), do: value
  def extract_value({:error, reason}), do: {:error, reason}

  defp build_request(address, api_url) do
    body =
      %{
        jsonrpc: "2.0",
        id: 1,
        method: "getBalance",
        params: [address]
      }
      |> Jason.encode!()

    Finch.build(:post, api_url, @headers, body)
  end

  defp send_request(request) do
    case Finch.request(request, Testespay.Finch) do
      {:ok, response} ->
        Logger.debug("Resposta recebida: #{inspect(response)}") # Log formatado
        {:ok, response}

      {:error, reason} ->
        Logger.error("Erro na requisição: #{inspect(reason)}")
        {:error, reason}
    end
  end

  defp handle_response({:ok, %{status: 200, body: body}}) do
    Logger.debug("Resposta HTTP 200: #{body}") # Log do corpo bruto

    case Jason.decode(body) do
      {:ok, %{"result" => %{"value" => value}}} ->
        Logger.debug("Saldo extraído: #{value}")
        {:ok, value}

      {:ok, %{"error" => error}} ->
        Logger.error("Erro na resposta da Solana: #{inspect(error)}")
        {:error, error}

      {:error, reason} ->
        Logger.error("Falha ao decodificar JSON: #{inspect(reason)}")
        {:error, reason}
    end
  end

  defp handle_response({:ok, %{status: status}}) do
    {:error, "HTTP Error: #{status}"}
  end

  defp handle_response({:error, reason}) do
    {:error, reason}
  end
end

dev env outputs

kr9AwnPKYcixMEf3y", chain: "btc", coin: "btc", ref_id: 1}}
[debug] %{"amount" => Decimal.new("0.0699"), "chain" => "btc", "coin" => "btc", "pubkey" => "7e59NVw7P7Sk3ZsPRdUxdLNN4aokr9AwnPKYcixMEf3y", "ref_id" => 1, "time_limit" => ~N[2025-02-25 18:45:59.215817]}
[debug] initing job....
picking
[debug] [{"contract", %{"amount" => "0.0699", "chain" => "btc", "coin" => "btc", "pubkey" => "7e59NVw7P7Sk3ZsPRdUxdLNN4aokr9AwnPKYcixMEf3y", "ref_id" => 1, "time_limit" => "2025-02-25T18:45:59.215817"}}]
[debug] init request..

the job can be started several times, and all others logs show up
when I use IEX to do the request, everything logs

[info] No unexpired contracts found in Mnesia.
iex(2)> Testespay.Oban.RequestBalanceFileSolana.get_balance("DRnPr3qejHdMQj3ztjjRzyaCm9XTac3Zk9yAnWhfbAJ2", "https://rpc.ankr.com/solana_devnet/ae321adefbcd42cb37d0790c522ce876c7e9f19dbfece1d44b9e90845e855100")
[debug] init request..
[debug] Resposta recebida: %Finch.Response{status: 200, body: "{\"id\":1,\"jsonrpc\":\"2.0\",\"result\":{\"context\":{\"apiVersion\":\"2.1.14\",\"slot\":363559086},\"value\":0}}", headers: [{"date", "Tue, 25 Feb 2025 18:49:23 GMT"}, {"content-type", "application/json"}, {"content-length", "96"}, {"connection", "keep-alive"}, {"strict-transport-security", "max-age=15724800; includeSubDomains"}, {"access-control-allow-origin", "*"}, {"access-control-allow-credentials", "true"}, {"access-control-allow-methods", "GET, PUT, POST, DELETE, PATCH, OPTIONS"}, {"access-control-allow-headers", "DNT,Keep-Alive,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Range,Authorization,solana-client"}, {"access-control-max-age", "1728000"}], trailers: []}
0
[debug] Resposta HTTP 200: {"id":1,"jsonrpc":"2.0","result":{"context":{"apiVersion":"2.1.14","slot":363559086},"value":0}}
[debug] Saldo extraído: 0
2 
defmodule Testespay.Resources.ConvertRealm do
require Logger

  def convert_to_decimal_3points(value) when is_number(value) and value >= 0 do
    result =
      value
    |> Decimal.new()
    |> Decimal.round(3)

    Logger.debug(result)
  end

I tried to pipe the result into another module to check if it was some async communication to the terrminal issue, but still no log

3

It looks like this question was incidentally answered for the same codebase here:

There is a runtime error in your code, preventing it from reaching those log lines, but as you have not set up telemetry for your Oban runtime it is not obvious that’s what’s happening. For future Oban users’ benefit, per the linked github issue,

We strongly recommend attaching the default logger in order to see errors as they happen. Alternatively, you can attach an error handler to have errors reported externally.

3 Likes
4

do you know how can I diagnose this error? I got no oban configuration on my runtime.exs, just phoenix

5

put this in your application.exs
in the function , start. As oban catchs all the crashes

  :telemetry.attach_many(
      "oban-errors",
      [[:oban, :job, :exception], [:oban, :circuit, :trip]],
      &Jobs.ErrorReporter.handle_event/4,
      %{}
    )

the impl

defmodule Jobs.ErrorReporter do
  def handle_event(
        [:oban, :job, :exception],
        timing_data,
        %{job: job, error: error, stacktrace: stacktrace},
        _
      ) do
    extra =
      job
      |> Map.take([:id, :args, :meta, :queue, :worker])
      |> Map.merge(timing_data)

    formatted_stacktrace =
      stacktrace
      |> Exception.format_stacktrace()
      |> String.split("\n")
      |> Enum.map_join("\n", &("    " <> &1))

    Logger.error("""
    [Oban][Error]:

    Error:
      #{inspect(error)}

    Stacktrace:
    #{formatted_stacktrace}

    Job Info:
      #{inspect(extra, pretty: true)}
    """)
  end

  def handle_event(
        [:oban, :circuit, :trip],
        _timing_data,
        %{error: error, stacktrace: stacktrace} = meta,
        _
      ) do
    formatted_stacktrace =
      stacktrace
      |> Exception.format_stacktrace()
      |> String.split("\n")
      |> Enum.map_join("\n", &("    " <> &1))

    Logger.error("""
    [Oban][Error]: Circuit Trip

    Error:
      #{inspect(error)}

    Stacktrace:
    #{formatted_stacktrace}

    Additional Info:
      #{inspect(meta, pretty: true)}
    """)
  end
end
1 Like
6

You can write tests for the function, turn on logging to see the errors, or write a custom error handler as shown in the Error Handling guide

There hasn’t been a circuit event for many years now, since before Oban 2.0 IIRC.

1 Like