Auditing function calls of unit of work implementations

Hello all. I’m thinking about implementing a library which audits function calls and their return values and sends them to somewhere else, possibly to something like file logger or directly to a database (i.e. Elasticsearch). There are unit-of-work implementations in my Phoenix application currently, and those should be logged without adding extra lines of code to the business logic (seperation of concerns).

This pretty looks like a decent use case for aspect-oriented-programming. With a little amount of effort for the research on it, in StackOverflow, I found something like this:

defmodule Tracer do
  use GenServer

  def start(modules), do: GenServer.start(__MODULE__, modules)

  def init(modules) do
    :erlang.trace(:all, true, [:call])

    for module <- modules do
      :erlang.trace_pattern({module, :_, :_}, [{:_, [], [{:return_trace}]}])
    end

    {:ok, nil}
  end

  def handle_info({:trace, _, :call, {mod, fun, args}}, state) do
    IO.puts "called #{mod}.#{fun}(#{Enum.join(Enum.map(args, &inspect/1), ",")})"
    {:noreply, state}
  end

  def handle_info({:trace, _, :return_from, {mod, fun, arity}, res}, state) do
    IO.puts "#{mod}.#{fun}/#{arity} returned #{res}"
    {:noreply, state}
  end

  def handle_info(_, state), do: {:noreply, state}
end

This GenServer hooks to the Erlang’s tracer thing, gets notified by the tracer upon function calls on given modules/functions etc. It works like fswatch, register some callback for some pattern, boom.

This implementation is pretty naive, and I would like to use (or create) a more pluggable and configurable implementation, with a backend system (similar to Logger), and be Elixir-ready for my use cases. This is pretty dirty.

Hence, I started to think about an API and a way to use a library (unknown) like this. The ultimate goal for me is inspecting public functions of service modules, which contains unit-of-work implementations. I’m gonna give you an example containing unit-of-work functions.

defmodule App.Telephony do
  @moduledoc """
  Provides functionality to use telephony services.
  """
  use App.Stereotype, :service

  def add_phone_number(phone_number) do
    ...
  end

  def list_phone_numbers() do
    ...
  end

  def call_phone_number(phone_number_id, audio_blob) do
    ...
  end
end

We wanted to audit service calls, so the use directive at the top of the module calls a macro on the stereotype module. It is actually implemented by the Phoenix boilerplate, with slight modifications.

defmodule App.Stereotype do
  @moduledoc """
  Defines stereotypes for the modules of the application.
  """

  @doc false
  def service do
    quote do
      import Ecto
      import Ecto.Changeset
      import Ecto.Query

      alias App.Repo

      # we're starting the tracer to monitor the calls made to the service
      Tracer.start([__MODULE__])
    end
  end

  @doc """
  When used, dispatch to the appropriate stereotype.
  """
  defmacro __using__(which) when is_atom(which),
    do: apply(__MODULE__, which, [])
end

I do not actually know if that works or not (probably not), this is just a demonstration for the use case. Let’s ignore about this implementation, look more conceptually. I have some questions mingling my head.

  1. Is there any library doing such kind of thing? Or, at least, a starting point?
  2. Does it create an overhead in the virtual machine to trace function calls, is it negligible to do it in production? (assume there is no writing pressure)
  3. I’m expecting an aspect-oriented programming like approach, but more generic and low-cost in terms of code.

Thank you for your suggestions and feedbacks. I’m also okay to scaffold a new library for this.

1 Like