Logging Memory Usage in LiveView

Building and maintaining Elixir apps is a great experience, but if you're not careful you can introduce functionality that can accidentally use way more memory than you intended it to.

There are a number of ways you can instrument your app in development or production in order to avoid this, but I've found there's a simple way to add it to the logger in order to allow you to eyeball in dev if something looks like it's out of hand, and find specific problematic cases in prod of an otherwise fine action.

The first thing you need to do is update your logger config:

config :logger, :console,
  format: "$time $metadata[$level] $message\n",
  metadata: [:request_id, :user_id, :memory]

Yours doesn't have to match exactly, but the key addition is the :memory atom to the logger metadata.

From there, the first thing that will come to mind is a more traditional approach to monitoring, by adding a Plug that instruments your Endpoint module.

# lib/my_app_web/endpoint.ex

defmodule MyAppWeb.Endpoint do
  use Phoenix.Endpoint, otp_app: :my_app

  ...
  
  plug(MyAppWeb.Plugs.MemoryToMetadata) # <--- this is the one
  plug(MyAppWeb.Router)
end

And from there, you then create the Plug that you've added in the Endpoint.

# lib/my_app_web/plugs/memory_to_metadata.ex

defmodule MyAppWeb.Plugs.MemoryToMetadata do
  @behaviour Plug

  import Plug.Conn

  require Logger

  @spec init(Keyword.t()) :: Keyword.t()
  def init(_opts), do: []

  @spec call(Plug.Conn.t(), Keyword.t()) :: Plug.Conn.t()
  def call(conn, _opts) do
    register_before_send(conn, fn conn ->
      # The addition of Sizeable is optional - makes human readable from bytes
      Logger.metadata(mem: self() |> Process.info(:memory) |> elem(1) |> Sizeable.filesize())
      conn
    end)
  end
end

This one introduces a callback you may not be familiar with, register_before_send that allows you to hook into just before the response is sent, which is when I'm interested in checking the memory of each request.

However, LiveView users will be sad to note here that this only instruments your normal controller actions, and the initial mount of your LiveView. Not super useful.

Luckily, LiveView gives us the tools to instrument here as well, without too much redundancy, and without having to write crazy macros that involved before_compile and defoverridable.

Phoenix.LiveView.attach_hook gives us the ability to attach to various lifecycle events. Normally this would allow you to perform different actions, but this also gives us an easy place to hook into like so:

socket
|> Phoenix.LiveView.attach_hook(
  :some_handle_params_hook,
  :handle_params,
  &MyApp.Hooks.SomeHandleParamsHook.the_function/3
)

But it sucks to have to add that on mount to every LiveView.

Luckily you can just add it :on_mount , and you're not limited to just a single hook attachment on mount. You could just do something like this:

# lib/my_app_web/live/hooks/log_memory.ex
defmodule MyAppWeb.Hooks.LogMemory do
  @spec on_mount(:default, any(), any(), any()) :: any()
  def on_mount(:default, _params, _session, socket) do
    {:cont, attach_all(socket)}
  end

    @spec attach_all(any()) :: any()
  def attach_all(socket) do
    socket
    |> Phoenix.LiveView.attach_hook(
      :handle_params_add_memory_to_meta,
      :handle_params,
      &memory_to_meta/3
    )
    |> Phoenix.LiveView.attach_hook(
      :handle_event_add_memory_to_meta,
      :handle_event,
      &memory_to_meta/3
    )
    |> Phoenix.LiveView.attach_hook(
      :handle_info_add_memory_to_meta,
      :handle_info,
      &memory_to_meta/2
    )
    |> Phoenix.LiveView.attach_hook(
      :handle_async_add_memory_to_meta,
      :handle_async,
      &memory_to_meta/3
    )
    |> Phoenix.LiveView.attach_hook(
      :after_render_add_memory_to_meta,
      :after_render,
      &memory_to_meta/1
    )
  end

  def memory_to_meta(socket) do
    add_memory()
    socket
  end

  def memory_to_meta(_event, socket) do
    add_memory()
    {:cont, socket}
  end

  def memory_to_meta(_params_or_event, _uri, socket) do
    add_memory()
    {:cont, socket}
  end

  defp add_memory do
    Logger.metadata(memory: self() |> Process.info(:memory) |> elem(1) |> Sizeable.filesize())
  end
end

Now, you may be worried that you have to add this to each of your LiveView's individually, but you don't.

# lib/my_app_web/router.ex

defmodule MyAppWeb.Router do
  use MyAppWeb, :router
  
  ...
  
  live_session :some_session_name, on_mount: [MyAppWeb.Hooks.LogMemory] do
    ...
  end
end

And this will take care of ensuring that you get logs that look something like this:

06:16:01.609 request_id=GCmy1aDrnqPYitEABF_C user_id=1c06a439-a23c-4f1e-be01-6e60cc00344d mem=1.72 MB [info] /
06:16:01.656 request_id=GCmy1aDrnqPYitEABF_C user_id=1c06a439-a23c-4f1e-be01-6e60cc00344d mem=1.72 MB [info] Sent 200 in 102ms

for every Controller action, and LiveView action too.

Hopefully this will save you some trouble, or keep you and your team out of trouble as you build amazing Phoenix apps.