Elixir Telemetry Logging

Ever wondered how you can log your Ecto/Mix Events to a file or even to the console? Well, here is how!

A small showcase

⚠️ Warning:
This isn't valid SQL code, this is just logging the Code being executed by Ecto that is able to save/edit/delete/purge data.

Requirements:

• Elixir v13.3.2 +
• A working Database
• Basic Knowledge of Elixir

$ elixir -v
Elixir 1.13.2 (compiled with Erlang/OTP 24)

Getting started

Here, as an example, I am using Ecto - however, you can use basically everything else (that might be similar) and directly skip to the Telemetry part.

Docs: https://hexdocs.pm/ecto/getting-started.html

Creating our project

$ mix new sqlt --sup

Adding packages

If you use another DB, like MySQL, then add that instead.

{:ecto_sql, "~> 3.0"},
{:postgrex, ">= 0.0.0"}

make sure to run mix deps.get to install them.

Generating our Repo

$ mix ecto.gen.repo -r SQLT.Repo

This command will generate the configuration required to connect to a database. The first bit of configuration is in config/config.exs:

config :sqlt, SQLT.Repo,
  database: "localhost",
  username: "root",
  password: "admin",
  hostname: "localhost"

Make sure to fill out the correct informations here.

NOTE: Your PostgreSQL database may be setup to

• not require a username and password. If the above configuration doesn't work, try removing the username and password fields, or setting them both to "postgres".
• be running on a non-standard port. The default port is 5432. You can specify your specific port by adding it to the config: e.g. port: 15432.

Configurating our Repo

The SQLT.Repo module is defined in lib/sqlt/repo.ex by our mix ecto.gen.repo command:

defmodule SQLT.Repo do
  use Ecto.Repo,
    otp_app: :sqlt,
    adapter: Ecto.Adapters.Postgres
end

We now have to add our Repo to our Application. For that being said, open your application.ex file.

Possible path: lib/sqlt/application.ex.
Within the children, add the following:

 children = [
  # add this
  {SQLT.Repo, []},
]

This piece of configuration will start the Ecto process which receives and executes our application's queries. Without it, we wouldn't be able to query the database at all!

There's one final bit of configuration that we'll need to add ourselves, since the generator does not add it. Underneath the configuration in config/config.exs, add this line:
config :sqlt, ecto_repos: [SQLT.Repo]

This tells our application about the repo, which will allow us to run commands such as mix ecto.create very soon.

Database Setup

Run the following command:

$ mix ecto.create

You should now see
The database for SQLT.Repo has been created.

NOTE: If you get an error, you should try changing your configuration in config/config.exs, as it may be an authentication error.

This command will generate a brand new migration file in priv/repo/migrations, which is empty by default:

defmodule SQLT.Repo.Migrations.People do
  use Ecto.Migration

  def change do

end

We will now create a table called people and also add some values to it.

defmodule SQLT.Repo.Migrations.People do
  use Ecto.Migration

  def change do
    create table(:people) do 
      add :first_name, :string
      add :last_name, :string
      add :age, :integer
    end
  end
end

To run this migration and create the people table in our database, we will run this command:

$ mix ecto.migrate

Creating a schema

Let's create the schema within our application at lib/sqlt/people.ex:

defmodule SQLT.People do
  use Ecto.Schema

  @moduledoc """
  Changesets allow filtering, casting, validation and definition of constraints when manipulating structs.
  There is an example of working with changesets in the introductory documentation in the Ecto module. 
  The functions cast/4 and change/2 are the usual entry points for creating changesets. 
  The first one is used to cast and validate external parameters, such as parameters sent through a 
  form, API, command line, etc. 
  The second one is used to change data directly from your application.
    - https://hexdocs.pm/ecto/Ecto.Changeset.html
  The remaining functions in this module, such as validations, constraints, 
  association handling, are about manipulating changesets. 
  """

  def changeset(person, params \\ %{}) do
    person
    # tell what parameters are allowed to be passted through 
    |> Ecto.Changeset.cast(params, [:first_name, :last_name, :age])
    # we expect values for fn + ln
    |> Ecto.Changeset.validate_required([:first_name, :last_name])
  end

  schema "people" do
    field(:first_name, :string)
    field(:last_name, :string)
    field(:age, :integer)
  end
end

Awesome! Our database is now fully working.

Adding telemetry

Telemetry is a lightweight library for dynamic dispatching of events, with a focus on metrics and instrumentation. Any Erlang or Elixir library can use telemetry to emit events. Application code and other libraries can then hook into those events and run custom handlers.

Docs: https://hexdocs.pm/telemetry/readme.html

Configurating our Application

Open your application.ex file (lib/sqlt/application)
and add the following line

 :ok = :telemetry.attach("sqlt-repo-handler", [:sqlt, :repo, :query], &SQLT.Telemetry.handle_event/4, %{})

above the children.

Your application.ex should now look like this:

defmodule Sqlt.Application do
  # See https://hexdocs.pm/elixir/Application.html
  # for more information on OTP Applications
  @moduledoc false

  use Application

  @impl true
  def start(_type, _args) do
   # here!! :)
    :ok = :telemetry.attach("sqlt-repo-handler", [:sqlt, :repo, :query], &SQLT.Telemetry.handle_event/4, %{})

    children = [
      {SQLT.Repo, []},
    ]

    # See https://hexdocs.pm/elixir/Supervisor.html
    # for other strategies and supported options
    opts = [strategy: :one_for_one, name: Sqlt.Supervisor]
    Supervisor.start_link(children, opts)
  end
end

Configurating Telemetry

Start by creating a telemetry.ex file at the following path: lib/sqlt/telemetry.ex

defmodule SQLT.Telemetry do
  require Logger

def emit(value) do 
    :telemetry.execute([:sqlt, :emit], %{value: value})
end

# *
def handle_event([:sqlt, :repo, :query], measurements, metadata, _config) do
    data = "#{metadata.query} #{metadata.params}"

    Logger.info(data)
    File.write("raw.sql", data)
  end
end

*
Here we handle "main event" for the telemetry handler defined in the application.ex file

:ok = :telemetry.attach("sqlt-repo-handler", [:sqlt, :repo, :query], &SQLT.Telemetry.handle_event/4, %{})

Once some event is executed, we log it to the console and also write the content into a separate file in our root directory.

We use the metadata variable with the query and params parameter, tho there are some more

:type - the type of the Ecto query. For example, for Ecto.SQL databases, it would be :ecto_sql_query

:repo - the Ecto repository

:result - the query result

:params - the query parameters

:query - the query sent to the database as a string

:source - the source the query was made on (may be nil)

:options - extra options given to the repo operation under :telemetry_options

Also, if you go through the code, you notice the handle_event function, this is where all the magic happens. Obviously you can remove the Logger (nothing will be logged to the console) and also change the behaviour (in my case writing the result to a .sql file).

Creating Events

In my case I am using Ecto Events, of course you can use something else.

I will now create some functions that is inserts, edits and also deletes data from the Database.

lib/sqlt/queries.ex

defmodule Query do
  require Ecto.Query

# here we create / insert data
def insert do
    firstname = IO.gets("Enter the firstname: ") |> String.trim()
    lastname = IO.gets("Enter the lastname: ") |> String.trim()
    person = %SQLT.People{first_name: firstname, last_name: lastname, age: 25}
    SQLT.Repo.insert(person)
  end

# here we edit our data
def edit do
    name = IO.gets("Enter the first_name that you want to find: ") |> String.trim()
    newname = IO.gets("Now enter the new first_name: ") |> String.trim()
    person = SQLT.People |> Ecto.Query.where(first_name: ^name) |> SQLT.Repo.one()
    changeset = SQLT.People.changeset(person, %{first_name: newname})

    case SQLT.Repo.update(changeset) do
      {:ok, person} ->
        IO.puts("Updated #{person}")

      {:error, error} ->
        IO.puts("Error #{error}")
    end
  end
end

🎉🎉🎉 YOU ARE AWESOME! 🎉🎉🎉
You have successfully created a custom event logger with Telemetry.

If you run one of the functions above, you will see the raw.sql being created. By running more functions, telemetry will be write them into that file.

I have uploaded the whole code to GitHub, just in case if you want to take a look at the whole code/repo.

https://github.com/vKxni/sqlt