261 lines
7.1 KiB
Markdown
261 lines
7.1 KiB
Markdown
# Telemetry
|
||
|
||
[![Codecov](https://codecov.io/gh/beam-telemetry/telemetry/branch/master/graphs/badge.svg)](https://codecov.io/gh/beam-telemetry/telemetry/branch/master/graphs/badge.svg)
|
||
|
||
[Documentation](https://hexdocs.pm/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.
|
||
|
||
> Note: this library is agnostic to tooling and therefore is not directly related to
|
||
> OpenTelemetry. For OpenTelemetry in the Erlang VM, see
|
||
> [opentelemetry-erlang](https://github.com/open-telemetry/opentelemetry-erlang), and check
|
||
> [opentelemetry_telemetry](https://github.com/open-telemetry/opentelemetry-erlang-contrib/tree/main/utilities/opentelemetry_telemetry)
|
||
> to connect both libraries.
|
||
|
||
## Usage
|
||
|
||
In a nutshell, you register a custom module and function to be invoked for certain events,
|
||
which are executed whenever there is such an event. The event name is a list of atoms. Each event is
|
||
composed of a numeric value and can have metadata attached to it. Let's look at an example.
|
||
|
||
Imagine that you have a web application and you'd like to log latency and response status for each
|
||
incoming request. With Telemetry, you can build a module which does exactly that whenever a response
|
||
is sent. The first step is to execute a measurement.
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
:telemetry.execute(
|
||
[:web, :request, :done],
|
||
%{latency: latency},
|
||
%{request_path: path, status_code: status}
|
||
)
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
telemetry:execute(
|
||
[web, request, done],
|
||
#{latency => Latency},
|
||
#{request_path => Path, status_code => Status}
|
||
)
|
||
```
|
||
|
||
Then you can create a module to be invoked whenever the event happens.
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
defmodule LogResponseHandler do
|
||
require Logger
|
||
|
||
def handle_event([:web, :request, :done], measurements, metadata, _config) do
|
||
Logger.info(
|
||
"[#{metadata.request_path}] #{metadata.status_code} sent in #{measurements.latency}"
|
||
)
|
||
end
|
||
end
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
-module(log_response_handler).
|
||
|
||
-include_lib("kernel/include/logger.hrl").
|
||
|
||
handle_event([web, request, done], #{latency := Latency}, #{request_path := Path,
|
||
status_code := Status}, _Config) ->
|
||
?LOG_INFO("[~s] ~p sent in ~p", [Path, Status, Latency]).
|
||
|
||
```
|
||
|
||
**Important note:**
|
||
|
||
The `handle_event` callback of each handler is invoked synchronously on each `telemetry:execute` call.
|
||
Therefore, it is extremely important to avoid blocking operations. If you need to perform any action
|
||
that is not immediate, consider offloading the work to a separate process (or a pool of processes)
|
||
by sending a message.
|
||
|
||
Finally, all you need to do is to attach the module to the executed event.
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
:ok =
|
||
:telemetry.attach(
|
||
# unique handler id
|
||
"log-response-handler",
|
||
[:web, :request, :done],
|
||
&LogResponseHandler.handle_event/4,
|
||
nil
|
||
)
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
ok = telemetry:attach(
|
||
%% unique handler id
|
||
<<"log-response-handler">>,
|
||
[web, request, done],
|
||
fun log_response_handler:handle_event/4,
|
||
[]
|
||
)
|
||
```
|
||
|
||
You might think that it isn't very useful, because you could just as well write a log statement
|
||
instead of calling `telemetry:execute/3` – and you would be right! But now imagine that each Elixir library
|
||
would publish its own set of events with information useful for introspection. Currently each library
|
||
rolls their own instrumentation layer – Telemetry aims to provide a single interface for these use
|
||
cases across the whole ecosystem.
|
||
|
||
### Spans
|
||
|
||
In order to provide uniform events that capture the start and end of discrete events, it is recommended
|
||
that you use the `telemetry:span/3` call. This function will generate a start event and a stop or exception
|
||
event depending on whether the provided function executed successfully or raised an error. Under the hood,
|
||
the `telemetry:span/3` function leverages the `telemetry:execute/3` function, so all the same usage patterns
|
||
apply. If an exception does occur, an `EventPrefix ++ [exception]` event will be emitted and the caught error
|
||
will be re-raised.
|
||
|
||
The measurements for the `EventPrefix ++ [start]` event will contain a key called `system_time` which is
|
||
derived by calling `erlang:system_time()`. For `EventPrefix ++ [stop]` and `EventPrefix ++ [exception]`
|
||
events, the measurements will contain a key called `duration` and its value is derived by calling
|
||
`erlang:monotonic_time() - StartMonotonicTime`. All events include a `monotonic_time` measurement too.
|
||
All of them represent time as native units.
|
||
|
||
To convert the duration from native units you can use:
|
||
|
||
```elixir
|
||
milliseconds = System.convert_time_unit(duration, :native, :millisecond)
|
||
```
|
||
|
||
To create span events you would do something like this:
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
def process_message(message) do
|
||
start_metadata = %{message: message}
|
||
|
||
result =
|
||
:telemetry.span(
|
||
[:worker, :processing],
|
||
start_metadata,
|
||
fn ->
|
||
result = ... # Process the message
|
||
{result, %{metadata: "Information related to the processing of the message"}}
|
||
end
|
||
)
|
||
end
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
process_message(Message) ->
|
||
StartMetadata = #{message => Message},
|
||
Result = telemetry:span(
|
||
[worker, processing],
|
||
StartMetadata,
|
||
fun() ->
|
||
Result = % Process the message
|
||
{Result, #{metadata => "Information related to the processing of the message"}}
|
||
end
|
||
).
|
||
```
|
||
|
||
To then attach to the events that `telemetry:span/3` emits you would do the following:
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
:ok =
|
||
:telemetry.attach_many(
|
||
"log-response-handler",
|
||
[
|
||
[:worker, :processing, :start],
|
||
[:worker, :processing, :stop],
|
||
[:worker, :processing, :exception]
|
||
],
|
||
&LogResponseHandler.handle_event/4,
|
||
nil
|
||
)
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
ok = telemetry:attach_many(
|
||
<<"log-response-handler">>,
|
||
[
|
||
[worker, processing, start],
|
||
[worker, processing, stop],
|
||
[worker, processing, exception]
|
||
],
|
||
fun log_response_handler:handle_event/4,
|
||
[]
|
||
)
|
||
```
|
||
|
||
With the following event handler module defined:
|
||
|
||
In Elixir:
|
||
|
||
```elixir
|
||
defmodule LogResponseHandler do
|
||
require Logger
|
||
|
||
def handle_event(event, measurements, metadata, _config) do
|
||
Logger.info("Event: #{inspect(event)}")
|
||
Logger.info("Measurements: #{inspect(measurements)}")
|
||
Logger.info("Metadata: #{inspect(metadata)}")
|
||
end
|
||
end
|
||
```
|
||
|
||
In Erlang:
|
||
|
||
```erlang
|
||
-module(log_response_handler).
|
||
|
||
-include_lib("kernel/include/logger.hrl").
|
||
|
||
handle_event(Event, Measurements, Metadata, _Config) ->
|
||
?LOG_INFO("Event: ~p", [Event]),
|
||
?LOG_INFO("Measurements: ~p", [Measurements]),
|
||
?LOG_INFO("Metadata: ~p", [Metadata]).
|
||
```
|
||
|
||
## Installation
|
||
|
||
Telemetry is available on [Hex](https://hex.pm/packages/telemetry). To install, just add it to
|
||
your dependencies in `mix.exs`:
|
||
|
||
```elixir
|
||
defp deps() do
|
||
[
|
||
{:telemetry, "~> 1.0"}
|
||
]
|
||
end
|
||
```
|
||
|
||
or `rebar.config`:
|
||
|
||
```erlang
|
||
{deps, [{telemetry, "~> 1.0"}]}.
|
||
```
|
||
|
||
## Copyright and License
|
||
|
||
Copyright (c) 2018 Chris McCord and Erlang Solutions.
|
||
|
||
Telemetry's source code is released under the Apache License, Version 2.0.
|
||
|
||
See the [LICENSE](LICENSE) and [NOTICE](NOTICE) files for more information.
|