Elixir Telemetry Logging
Tags: elixir, ecto, logging, sql
Published: 2022-10-01 09:32:50

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

![Preview, click here!](https://dev-to-uploads.s3.amazonaws.com/uploads/articles/f0dqxccd0b1dwfe5r5eb.gif)

⚠️ 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.

```elixir
{: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`:
```elixir
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:
```elixir
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:

```elixir
 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:

```elixir
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. 

```elixir
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`:

```elixir
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

```elixir
 :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: 
```elixir
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`

```elixir
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`
```elixir
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](https://github.com/vKxni/sqlt)