No stack trace in production log

Does this help? Error logging and stack traces in release vs IEx

I looked over those replies already. There in no solution offered in any of those.

One person suggest to “add Logger.error(error) to render() in ErrorView” but that seams like a hack and still doesn’t show stack trace.

I’m trying to understand what is the fundamental reason of that happening in production build and why this is default behavior?

Phoenix’s default logger is very basic, which is implemented as telemetry event handler at here.

At first, you can disable the default logger by:

config :phoenix, :logger, false

Then, implement you own telemetry event handler for logging.

Recently, I added a JSON logger for my app, so I can give you a basic example:

1. I implemented a module for handling related telemetry event:

defmodule JSONLog.Logger do
  @moduledoc """
  Instrumenter to handle logging of various Phoenix instrumentation events.
  """

  require Logger

  @doc false
  def install do
    handlers = %{
      [:phoenix, :endpoint, :stop] => &__MODULE__.phoenix_endpoint_stop/4
    }

    for {key, fun} <- handlers do
      :telemetry.attach({__MODULE__, key}, key, fun, :ok)
    end
  end

  @doc false
  def duration(duration) do
    duration = System.convert_time_unit(duration, :native, :microsecond)

    if duration > 1000 do
      [duration |> div(1000) |> Integer.to_string(), "ms"]
    else
      [Integer.to_string(duration), "µs"]
    end
  end

  defp log_level(nil, _conn), do: :info
  defp log_level(level, _conn) when is_atom(level), do: level

  defp log_level({mod, fun, args}, conn) when is_atom(mod) and is_atom(fun) and is_list(args) do
    apply(mod, fun, [conn | args])
  end

  @doc false
  def phoenix_endpoint_stop(_, %{duration: duration}, %{conn: conn} = metadata, _) do
    case log_level(metadata[:options][:log], conn) do
      false ->
        :ok

      level ->
        Logger.log(
          level,
          fn ->
            %{method: method, request_path: request_path, status: status} = conn
            status = Integer.to_string(status)

            [method, ?\s, request_path, ?\s, status, " in ", duration(duration)]
          end,
          metadata(conn)
        )
    end
  end

  defp metadata(conn) do
    %{method: method, request_path: request_path, status: status} = conn
    status = Integer.to_string(status)

    %{
      method: method,
      request_path: request_path,
      user_agent: extract_user_agent(conn),
      connection_type: connection_type(conn),
      status: status,
      exception: extract_exception(conn)
    }
  end

  defp connection_type(%Plug.Conn{state: :set_chunked}), do: "Chunked"
  defp connection_type(_), do: "Sent"

  defp extract_user_agent(%Plug.Conn{} = conn), do: Plug.Conn.get_req_header(conn, "user-agent")

  defp extract_exception(%Plug.Conn{assigns: %{kind: kind, reason: reason, stack: stack}}),
    do: Exception.format(kind, reason, stack)

  defp extract_exception(_), do: nil
end

In above code, the metadata of log contains a field called exception which is the stacktrace you wanted.

2. Output the log to a place, such as STDIO, logstash, etc. You can use a custom logger backend for implementing it. In my case, I use ink - print JSON to STDIO. And, related configurations are:

# Configures Elixir's Logger
config :logger,
  backends: [Ink],
  utc_log: true,
  # do not print debug messages in production
  level: :info

config :logger, Ink,
  name: "demo",
  exclude_hostname: true

# Disable default logger of phoenix
config :phoenix, :logger, false

Wow this is cool but sounds like overkill! How come stack trace shows up on dev and not production? That means that default logger is capable of outputting it?

Did you turn off debug symbols in prod?

I don’t know how. Can you point me to the docs on how to do that?

UPDATE1: I did more testing on that and discover that I mix release and start app locally I do get stack trace as expected however on my production Ubuntu server I just get application=phoenix request_id=FwQp3A4z_ymkm3sAAAHh [debug] Converted error ArgumentError to 500 response.

I’m using Docker to cross compile the app when I copy it to Ubuntu server where I run it as systemd process.

Re the ErrorView hack: Yes, it is a hack, but I do get a stack trace. Not necessarily a nicely formatted one, but enough to point me to the problem. (Actually now that I’m trying to reproduce it, it’s also giving me a formatted stack trace, which is weird. Maybe something in my build chain got updated without me noticing, or it depends on exactly from where the error was raised)

Your last update is very curious, since that’s the exact experiment I did to determine that it was the release environment that was failing to log my stack traces. Run in release locally, no traces. (IIRC I had also run it in iex with MIX_ENV=prod and seen stack traces like I wanted)

Re: debug symbols, the best I was able to find was setting strip_beams: false in the release config, documented here, but it didn’t make a difference for me.

I noticed that I do get some stack traces. I intentionally made an exception by passing nil to Ecto query and that logs fine on local and production machine. However, Converted error :undef to 500 response which I assume happening due to email validation controller failure doesn’t log anything in production and doesn’t fail on my local system (which is pretty annoying).

So somehow not all exception age getting caught by default which is weird since I use mix gen.auth without pretty much any changes.

Seam like a pretty big flow of Phoenix if it is true.

I didn’t change any debug symbol settings as well.

I will continue to investigate and post some updates.

Are you using releases at all?