lib/credo/execution/execution_timing.ex

defmodule Credo.Execution.ExecutionTiming do
  @moduledoc """
  The `ExecutionTiming` module can help in timing the execution of code parts and
  storing those timing inside the `Credo.Execution` struct.
  """

  use GenServer

  alias Credo.Execution

  @doc """
  Runs the given `fun` and prints the time it took with the given `label`.

      iex> Credo.Execution.ExecutionTiming.inspect("foo", fn -> some_complicated_stuff() end)
      foo: 51284

  """
  def inspect(label, fun) do
    {duration, result} = :timer.tc(fun)

    # credo:disable-for-lines:3 Credo.Check.Warning.IoInspect
    duration
    |> format_time()
    |> IO.inspect(label: label)

    result
  end

  @doc """
  Returns the current timestamp in the same format (microseconds) as the returned starting times of `run/1`.
  """
  def now, do: :os.system_time(:microsecond)

  @doc """
  Runs the given `fun` and returns a tuple of `{started_at, duration, result}`.

      iex> Credo.Execution.ExecutionTiming.run(fn -> some_complicated_stuff() end)
      {1540540119448181, 51284, [:whatever, :fun, :returned]}

  """
  def run(fun) do
    started_at = now()
    {duration, result} = :timer.tc(fun)

    {started_at, duration, result}
  end

  @doc "Same as `run/1` but takes `fun` and `args` separately."
  def run(fun, args) do
    started_at = now()
    {duration, result} = :timer.tc(fun, args)

    {started_at, duration, result}
  end

  @doc """
  Adds a timing to the given `exec` using the given values of `tags`, `started_at` and `duration`.
  """
  def append(%Execution{timing_pid: pid}, tags, started_at, duration) do
    spawn(fn ->
      GenServer.call(pid, {:append, tags, started_at, duration})
    end)
  end

  @doc """
  Adds a timing piped from `run/2` to the given `exec` (using the given values of `tags`, `started_at` and `duration`).
  """
  def append({started_at, duration, _result}, %Execution{timing_pid: pid}, tags) do
    spawn(fn ->
      GenServer.call(pid, {:append, tags, started_at, duration})
    end)
  end

  @doc """
  Returns all timings for the given `exec`.
  """
  def all(%Execution{timing_pid: pid}) do
    GenServer.call(pid, :all)
  end

  @doc """
  Groups all timings for the given `exec` and `tag_name`.
  """
  def grouped_by_tag(exec, tag_name) do
    map =
      exec
      |> all()
      |> Enum.filter(fn {tags, _started_at, _time} -> tags[tag_name] end)
      |> Enum.group_by(fn {tags, _started_at, _time} -> tags[tag_name] end)

    map
    |> Map.keys()
    |> Enum.map(fn map_key ->
      sum = Enum.reduce(map[map_key], 0, fn {_tags, _, time}, acc -> time + acc end)

      {[{tag_name, map_key}, {:accumulated, true}], nil, sum}
    end)
  end

  @doc """
  Returns all timings for the given `exec` and `tag_name`.
  """
  def by_tag(exec, tag_name) do
    exec
    |> all()
    |> Enum.filter(fn {tags, _started_at, _time} -> tags[tag_name] end)
  end

  @doc """
  Returns all timings for the given `exec` and `tag_name` where the tag's value also matches the given `regex`.
  """
  def by_tag(exec, tag_name, regex) do
    exec
    |> all()
    |> Enum.filter(fn {tags, _started_at, _time} ->
      tags[tag_name] && to_string(tags[tag_name]) =~ regex
    end)
  end

  @doc """
  Returns the earliest timestamp for the given `exec`.
  """
  def started_at(exec) do
    {_, started_at, _} =
      exec
      |> all()
      |> List.first()

    started_at
  end

  @doc """
  Returns the latest timestamp plus its duration for the given `exec`.
  """
  def ended_at(exec) do
    {_, started_at, duration} =
      exec
      |> all()
      |> List.last()

    started_at + duration
  end

  defp format_time(time) do
    cond do
      time > 1_000_000 ->
        "#{div(time, 1_000_000)}s"

      time > 1_000 ->
        "#{div(time, 1_000)}ms"

      true ->
        "#{time}μs"
    end
  end

  # callbacks

  @doc false
  def start_server(exec) do
    {:ok, pid} = GenServer.start_link(__MODULE__, [])

    %Execution{exec | timing_pid: pid}
  end

  @doc false
  def init(_) do
    {:ok, []}
  end

  @doc false
  def handle_call({:append, tags, started_at, time}, _from, current_state) do
    new_current_state = [{tags, started_at, time} | current_state]

    {:reply, :ok, new_current_state}
  end

  @doc false
  def handle_call(:all, _from, current_state) do
    list = Enum.sort_by(current_state, fn {_, started_at, _} -> started_at end)

    {:reply, list, current_state}
  end
end