One of the most powerful parts of the BEAM1 ecosystem is that many of the libraries come with industrial tooling and ways to connect. Erlang and by proxy Elixir comes with powerful tools for visualizing processess, messages and mailboxes(queues)1.
In this case I am using Heroku, so I cannot connect directly to a running instance, and I cannot connect multiple instances to each other1. There is an add-on available for Heroku called Librato and they have many libraries available to help get the data into Librato so they can graph/analyze it.
In this case though, Erlang and Elixir does not have a library. Librato has got an excellent solution for us, Custom Log Based Metrics, basically if we use the builtin Elixir Logger correctly we can pipe all the metrics we like into Librato.
So lets begin with an easy example, Ecto. Ecto has a built in function called Repo.log/11. This function is overridable and you probably see the default implemenetation when it logs queries it executes.
In this example I am overriding the built in log function to also log some info. In this case I am building an iolist of
measure# database.query=10ms measure# database.queue=0.1ms which Librato will pick up and treat as a measurement.
Some important things to note.
- Use the function style of logging. Using this style it makes sure the Logger.info call does not block the process. You will find this behaviour in most of the elixir libraries where performance is key, like the original Ecto repo.log
- I am using an
iolist. Basically whenever you have some data, usually a binary or string that is going to go directly to IO you want to generate an
iolist. It is an array of characters, binaries, or anything that can be flattened and joined. It saves allocating extra memory and is good for performance
- The log time function is from the Ecto library and mostly formats floats.
- I am calling super so I can also still have the dev debug level logging.
How can you use this data?
This will generate several metrics you can graph and display in Librato, such as min, max, mean, stdev, 95th percentile and so on. If, for example, you see a spike in the
database.queue you can check many things:
- Is my database down or hanging?
- Do I have long running queries holding up my connection pooling? (Check
- Do I have enough connections pooled for Ecto?
Lets look at a larger example, hackney. Hackney is a HTTP client library which offers a multitude of metrics. All you need to do is implement a single module and your data is made available to you. This is particularly useful because many time we rely on third party HTTP API’s. And knowing when we are slow vs when the third party is slow, is handy.
Here is the module:
This module follows the spec defined in the folsom/exometer module in hackney.
In our case, we don’t need to explicitly delete or create any metrics. We only need counts, measures and samples, hackney doesn’t use the rest. It is pretty straight forward so I am not going to discuss at length. But I hope it is handy do you.
To configure simply add a line to your existing config.exs:
And this is just scratching the surface of what’s possible. If you needed to keep an eye on certain processes you could simply have them log metrics. Or have a process that only watches the VM and logs specific information. Sky is the limit kemosabe!