Errors not logging in Phoenix

My user got an 'Internal Server Error' at a specific URL. I check the server logs - nothing. This is not the first time this has happened. So I spend a whole day looking for a solution and chatting about it. I try out my usual tricks like turning on level: :debug for logging. Sometimes Ecto errors are hidden because of that.

Curiously sometimes the error shows up. But after a hard refresh on the browser - again nothing. Just

[info] GET /learn
[info] Sent 500 in 2ms

Where's the error?

Solution

I was advised to use Sentry, so I dug in and tried to figure out what they do differently. Their elixir integration is open-source so I found the plug that's responsible for capturing errors and implemented that into my own app.

Amazingly it actually logs the hidden error. So this time the problem was actually Phoenix Endpoint not handling its error properly.

Here's my module.

defmodule PlatformWeb.EndpointErrorCatcher do
  @moduledoc """
  Since Phoenix doesn't capture all errors we've got to try-catch them ourselves. I have no idea how Phoenix is meant to be working in this regard, but I just had an invisible error in prod.
  Module is ripped from https://github.com/getsentry/sentry-elixir/blob/02a2cc31c7444af88d079f7c32a789b9b1b4e6f1/lib/sentry/plug_capture.ex
  #### Usage
  In a Phoenix application, it is important to use this module before
  the Phoenix endpoint itself. It should be added to your endpoint.ex:
      defmodule MyApp.Endpoint
        use EndpointErrorCatcher
        use Phoenix.Endpoint, otp_app: :my_app
        # ...
      end
  In a Plug application, it can be added below your router:
      defmodule MyApp.PlugRouter do
        use Plug.Router
        use EndpointErrorCatcher
        # ...
      end
  """
  defmacro __using__(_opts) do
    quote do
      @before_compile PlatformWeb.EndpointErrorCatcher
    end
  end

  defmacro __before_compile__(_) do
    quote do
      defoverridable call: 2

      def call(conn, opts) do
        try do
          super(conn, opts)
        rescue
          e in Plug.Conn.WrapperError ->
            stack =
              e.stack
              |> List.first()
              |> elem(3)
              |> then(fn [file: file, line: line] -> "#{file}:#{line}" end)

            Logger.error("EndpointWrapperError at #{stack}: #{e.reason.message}")
            Plug.Conn.WrapperError.reraise(e)

          e ->
            stack =
              __STACKTRACE__
              |> List.first()
              |> elem(3)
              |> then(fn [file: file, line: line] -> "#{file}:#{line}" end)

            Logger.error("EndpointUnknownError at #{stack}: #{e.reason.message}")

            :erlang.raise(:error, e, __STACKTRACE__)
        catch
          kind, reason ->
            message = "Uncaught #{kind} - #{inspect(reason)}"
            stack = __STACKTRACE__
            Logger.error(message, stacktrace: stack)
            :erlang.raise(kind, reason, stack)
        end
      end
    end
  end
end

It logs the file:line and reason for error.

Use it as per instructed in @moduledoc.