Elixir Human Readable reporter for erlang's :fprof output

fprof-report.exs

defmodule FPR do
  @moduledoc """

  # FProf Reporter

  Format results from `:fprof` into something human readable, with some basic
  filtering and sorting options.

  Start/Stop `:fprof` from IEx with the calls shown below (connect to your
  running application idealy).

  Note: this generates very large files on active systems (1gb ~ 15 seconds
  for example).

  Connect to iex of active beam and start profiling with:

     :fprof.start()
     :fprof.trace([:start, procs: :all])

  Then stop it with:

     :fprof.trace(:stop)
     :fprof.profile()
     :fprof.analyse(totals: false, dest: 'prof.analysis')

  Then run:

     elixir ../bin/analyze.exs ./prof.analysis {options}

  For help on options:

    elixir ../bin/analyze.exs -h

  Copyright 2022 Brandon Gillespie; License for use: GNU Affero GPL
  """

  @default_opts %{
    input: nil,
    sort_by: :acc,
    reverse: false,
    filter: ~r/^Elixir.*/
  }

  def run() do
    case Args.parse(System.argv(), @default_opts) do
      :help ->
        Args.print_usage()

      {:error, reason} ->
        Args.print_usage("\n#{reason}")

      {:ok, opts} ->
        with {:ok, terms} <- :file.consult(opts.input),
             {:ok, report} <- process_records(terms, opts, []) do
          format_report(report, opts)
        end
    end
  end

  ##############################################################################
  defp sort_keys(key, rev, [a | _], [b | _]) do
    va = Map.get(a, key)
    vb = Map.get(b, key)

    if rev do
      va > vb
    else
      va < vb
    end
  end

  defp format_report(report, %{sort_by: sortby, reverse: rev}) do
    Enum.sort(report, &sort_keys(sortby, rev, &1, &2))
    |> Enum.each(fn [top | rest] ->
      format_call("\n-->", top)
      Enum.each(rest, &format_call("   ", &1))
    end)
  end

  defp format_call(prefix, call) do
    IO.puts("#{prefix} #{call.acc} #{call.own} #{call.cnt} #{fmt_func(call.func)}")
  end

  ##############################################################################
  defp process_records([], _opts, report), do: {:ok, report}

  # ignore
  defp process_records([{:analysis_options, _opt} | rest], opts, report),
    do: process_records(rest, opts, report)

  defp process_records([[{:totals, _cnt, acc, _own}] | rest], opts, report) do
    IO.puts(:stderr, "Profile Period: #{Float.round(acc / 1000, 2)} seconds")
    process_records(rest, opts, report)
  end

  # list => it's a process report ~ PID, ignore for now
  defp process_records([list | rest], opts, report) when is_list(list),
    do: process_records(rest, opts, report)

  # otherwise it's a call report
  defp process_records([entry | rest], opts, report),
    do: process_records(rest, opts, process_record(entry, report, opts))

  ##############################################################################
  defp process_record({_callingList, {func, _, _, _} = actual, calledList}, report, %{
         filter: filter
       }) do
    with true <- filter_call(func, filter),
         [_ | _] = record <- process_call_stack([], [actual | calledList]) do
      [record | report]
    else
      _ -> report
    end
  end

  defp process_call_stack(out, [called | rest]),
    do: process_call(called, out) |> process_call_stack(rest)

  defp process_call_stack(out, []), do: Enum.reverse(out)

  ##############################################################################
  defp filter_call({mod, _, _}, filter), do: Regex.match?(filter, to_string(mod))
  defp filter_call(func, filter), do: Regex.match?(filter, to_string(func))

  ##############################################################################
  # drop system things
  defp process_call({{:fprof, _, _}, _, _, _}, out), do: out
  defp process_call({{:erlang, :trace, _}, _, _, _}, out), do: out
  defp process_call({{:erlang, :ensure_tracer_module_loaded, _}, _, _, _}, out), do: out
  defp process_call({{:elixir, :ensure_tracer_module_loaded, _}, _, _, _}, out), do: out
  defp process_call({{IEx.Evaluator, _, _}, _, _, _}, out), do: out
  defp process_call({:suspend, _, _, _}, out), do: out
  defp process_call({:undefined, _, _, _}, out), do: out
  defp process_call({:garbage_collect, _, _, _}, out), do: out

  defp process_call({func, cnt, acc, own}, out),
    do: [%{acc: acc, own: own, cnt: cnt, func: func} | out]

  ##############################################################################
  defp fmt_func({mod, func, arity}), do: "#{mod_name(mod)}.#{func}/#{arity}"
  defp fmt_func(other), do: inspect(other)

  defp mod_name(mod) do
    case "#{mod}" do
      "Elixir." <> mod -> mod
      mod -> mod
    end
  end
end

defmodule Args do
  ##############################################################################
  def parse(["-h" | _], _), do: :help

  def parse(["-r" | rest], opts), do: parse(rest, %{opts | reverse: true})

  def parse(["-s", sortby | rest], opts) do
    case String.downcase(sortby) do
      "acc" -> parse(rest, %{opts | sort_by: :acc})
      "own" -> parse(rest, %{opts | sort_by: :own})
      "cnt" -> parse(rest, %{opts | sort_by: :cnt})
      _ -> {:error, "Unrecognized sort key: #{sortby}, not one of: ACC, OWN, CNT"}
    end
  end

  def parse(["-f", filter | rest], opts) do
    case Regex.compile(filter) do
      {:ok, rx} -> parse(rest, %{opts | filter: rx})
      {:error, msg} -> {:error, "Cannot parse filter regex '#{filter}':\n#{inspect(msg)}"}
    end
  end

  def parse(["-" <> opt | _], _), do: {:error, "Invalid option '-#{opt}'"}

  def parse([arg | rest], %{input: nil} = opts),
    do: parse(rest, %{opts | input: arg})

  def parse([], opts), do: {:ok, opts}

  def parse(other, _), do: {:error, "Invalid argument '#{other}'"}

  ##############################################################################
  def print_usage(error \\ "") do
    IO.puts("""
    Usage: analyze {fproc.analysis file} [options]

    Options:

      -h This help message (see moduledoc for more details)
      -r (default: `false`)
         Reverse sort order
      -s KEY (default: `ACC`)
         sort by key (one of ACC, OWN, CNT below)
      -f REGEX (default: `^Elixir\.`)
         Filter results only to include the first/top call modules matching
         REGEX. Note: "^Elixir." must be included even though it is removed
         in the report, if referencing elixir modules (example: if your app
         is MyApp your regex is "^Elixir\.MyApp")

    Output format is:

      ACC OWN CNT MODULE.FUNCION/ARITY

      ACC (ms): the accumulated time spent in the function, including other function calls
      OWN (ms): the time the function spent to be executed
      CNT (x):  the number of times a function is called
    #{error}
    """)
  end
end

FPR.run()