Logger not printing released running as eval Cli.update_statuses()

Hello, I have this weird error on our production server, we have cron that will run ./path/to/binary eval Cli.update_statuses() and it will run some stuff. Problem is that some logger messages are missing. For instance if I connect to beam and run that command from iex, I get those messages in log, but when I run it using eval I don’t get them. Here is little bit obfuscated implementation of Cli module, logs that are made inside Task.async are missing:

defmodule Cli do
  alias App.Services

  require Logger

  @log_app "cli"

  @start_apps [
    :crypto,
    :ssl
    :postgrex,
    :ecto,
    :ecto_sql,
    :appsignal,
    :timex,
    :logger
  ]

  @repos Application.get_env(:app, :ecto_repos, [])

  def update_statuses do
    handle_error(fn ->
      start_services()

      Services.list_pending()
      |> Enum.group_by(& &1.integration.name)
      |> map_async_grouped_by(fn order ->
        Logger.metadata(app: @log_app, order: inspect(order.id))
        update_status(order)
      end)

      Logger.info("finished updating statuses")
    end)
  end

  defp update_status(order) do
    case Services.update(order) do
      {:ok, %{}} ->
        :ok

      result ->
        Logger.warn("updating failed #{inspect(result)}")

        with {:error, %{errors: errors}} <- Services.mark_not_update(order) do
          Logger.error("unable to mark as not updatable #{inspect(errors)}")
        end
    end
  end

  defp map_async_grouped_by(map, callback) do
    map
    |> Enum.map(fn {_, items} ->
      map_async_grouped_by_async(items, callback)
    end)
    |> Enum.map(&Task.await/1)
  end

  defp map_async_grouped_by_async(items, callback) do
    Task.async(fn ->
      Enum.map(items, fn item ->
        callback.(item)
      end)
    end)
  end

  defp start_services do
    Logger.info("Loading application")
    # It is neceseary to load app else configuration will not
    # be available
    Application.load(:app)

    Logger.info("Starting dependencies..")
    Enum.each(@start_apps, &Application.ensure_all_started/1)

    # Start the Repo(s) for app
    Logger.info("Starting repos..")
    Enum.each(@repos, & &1.start_link(pool_size: 2))
  end

  defp handle_error(fun) do
    Logger.metadata(app: @log_app)
    fun.()
  end
end

Anybody had similar issue?

Thank you.

That’s likely related to logging level, have you tried inspecting it in both scenarios?

I tried it but it was same, but It get resolved when I added rescue to function called in parallel task, I noticed that all logs from functions get printed at once when async finishes, I suspect that issue was that some error happened in async part which crashed beam (eval ‘something’ is not run under supervisor) and it died before it managed to actually print those logs