Logs are an important part of your application and logging shouldn't be one of the last things you think of. You should configure your log system, formatter, and style as soon as you start the development of your app. Also, do your best to document the process and share how it works with the rest of your team.
In this article, we're going to demonstrate how logs work in Elixir. We'll jump into Elixir's Logger module, which brings a lot of power to logging features. It also smoothly integrates with Erlang’s :logger to convert code to Elixir syntax.
You’ll learn how to customize your formatter, set up and change the log defaults of a Phoenix web API, as well as understand Logger levels a bit better.
Logs are useful but having a complete overview of your app is even better. Check out our 5-in-1 application monitoring for Elixir. We're free for OSS.
Our Project Environment Setup
To follow along, you should have a working Elixir environment set up. You can find instructions for that on Elixir’s Installation Page.
After installation, the following command will be available:
1iexWhen you run that command, an Elixir Interactive Shell will be opened. This is a REPL command-line environment in which you can test Elixir commands.
This is the perfect stage for some initial tests with Elixir’s IO module. As the name suggests, this module handles operations over IO, like data input and output.
To check that out, run the following commands within the iex shell:
1IO.puts("Hello world from Elixir")
2
3IO.puts(:stdio, "Logging from the stdio...")
4IO.puts(:stderr, "This is an error...")
5
6IO.inspect(self())This is the simplest form of logging in Elixir. The puts function takes two arguments, the first being the target destination of the log message (as an atom) and the second, the message itself.
When called with only the message argument, IO.puts will print to :stdout by default.
The third line exemplifies how you could change the destination to something else, like the :stderr. Although this setting changes the internal structure of the log, it doesn’t change anything in the output because there’s no color highlight being made.
Finally, there’s an inspect function on the last line. This function inspects the more complex structures of your Elixir application and allows you to log, for example, information about the process id in which that code is running.
You can see the logs of this execution below:
Phoenix Project
For the purposes of the article, you'll also need to have a Phoenix application created from scratch.
So make sure to follow the official instructions for that.
Since our focus is on logging, we only need the homepage and a single GET endpoint.
What About the Elixir Logger?
Among other things, Elixir’s Logger module provides:
- All the major levels of logging common to most languages
- Pre-formatting of log messages before they reach their destination
- Integration with Erlang’s Logger for even more power
Logger Levels
Logger currently embraces the following log levels:
- :debug: must be used for debug-only purposes. Be careful not to set this mode for production environments.
- :info: the most used one. It should be triggered whenever you need to print information of any nature.
- :warn and :error: even though
:infocan be used for everything, it’s better to finetune your warning and error messages. This way, automation tools will understand your categorized logs better.
They are stacked in the exact order of precedence which Elixir considers when having to choose between one or another.
Usage Example
Its usage is pretty simple. See the following example with a string interpolation:
1Logger.info("Hey, it's me: #{user_name}")You can also use it within the iex shell. Just run the following:
1require Logger
2user_name = "Julio"
3Logger.info("Hey, it's me: #{user_name}")Here's the output:
111:29:55.379 [info] Hey, it's me: JulioFormatter
Note that, by default, Logger comes with a preset format. In the above log, you can see a timestamp of when the event happened, the level of the log, and its message.
When you work with real-world applications, like a web API, you need to define which levels are accepted for each environment.
Get back to the Phoenix application you created previously and open the config folder. You may see a bunch of Elixir files with names that match development, testing, and production environments. Open the config.exs file, which is the boss of your app configuration and locate the config :logger line.
Take a brief look at these lines. This is Elixir’s Logger configuration. Whatever you change here, is going to be applied to all your app’s logs.
Start by changing the default log level of the entire app. If you specify that it should be error (the highest in the stack), then the others won't be logged anymore. So change the first line of the config to this:
1config :logger, :console,
2 level: :errorTo test, you’ll need to add some logs to your controller function. So, open the file simple_controller.ex that’s located in the web/controllers folder and switch its code to this:
1require Logger
2
3defmodule SimpleElixirApi.PageController do
4 use SimpleElixirApi.Web, :controller
5
6 def index(conn, _params) do
7 IO.puts("I'm a log")
8 Logger.debug("I'm a debug log")
9 Logger.info("I'm an info log")
10 Logger.warn("I'm a warn log")
11 Logger.error("I'm an error log")
12
13 Logger.metadata(request_id: "123")
14 render(conn, "index.html")
15 end
16endRestart your server and hit the http://localhost:4000/ address again. You should see the following in your console:
Change the level to the others and check out the results. Remember that you may configure each of the environment files separately to avoid log setting confusion.
Message Formatter
Alternatively, you can format your log messages by providing a regex. Change your Logger config (at configs.ex) to the following:
1config :logger, :console,
2 level: :info,
3 format: "$time $message $metadata[$level] \n"Note that the level was changed to allow more log lines for comparison.
Here, the format is receiving only the log’s variables to be injected into the output. However, you can customize with any of Elixir’s regex that may please you.
This should be the output:
In the end, it hasn’t changed that much. However, this was on purpose. For more advanced logs, you’ll need to write your own formatter.
Creating Your Formatter
Elixir’s config allows you to create and set your own formatter. With it, you have the option of creating whatever routines you want before, during, and after each log reaches its destination.
To make this happen, you’ll need to create a new logger module. So, within the lib folder, create another one called logger and create a file named my_logger.ex inside it with the following code:
1defmodule Logger.MyLogger do
2 def format(level, message, timestamp, metadata) do
3 "time=#{timestamp} level=[#{level}] metadata=#{inspect(metadata)} message=#{message}\n"
4 rescue
5 _ -> "Ooops, there was an error here!\n"
6 end
7endYou can name the function whatever you want but it’s common practice to give it the format name. It basically receives all common log attributes and formats them into a predefined pattern.
The message obeys the usual pattern for maps (key=value), very common among log processing tools.
In case anything goes wrong, an error message will be thrown at the rescue block.
For it to run, the Elixir config file has to be aware of it, so change the logger config to the following:
1config :logger, :console,
2 level: :info,
3 format: {Logger.MyLogger, :format}Restart the server and check out how your logs look now.
Logging Metadata
Another useful feature that comes built-in with Elixir’s Logger is metadata logging.
If you're using AppSignal to monitor your app, instead of adding metadata to your logs, you can add sample data to your AppSignal samples by using tagging. This way you can supply extra context on errors and performance issues.
There are times when you need to group a bunch of information in categorized logs. Since you’re under Phoenix's wing, your web APIs may need to automatically show some data related to HTTP requests and responses, like the request’s id.
Logger metadata works as a list of keywords (similar to maps and dictionaries) that’s exclusive to the running process (which means that, in the HTTP fandom, one request won’t get affected by others).
Every time a request arrives in the house, Logger will catch it, check your log configs and ask what metadata keywords are allowed to be logged.
You can define them one by one or tell Logger to consider them all:
1config :logger, :console,
2 level: :info,
3 format: {Logger.MyLogger, :format},
4 metadata: [:request_id]To set them all, just change the metadata config to:
1metadata: :allDo you remember the code line you added to the controller a few moments ago:
1Logger.metadata(request_id: "123")Now you can check out the request’s id appearing in your logs:
112:08:13.040 metadata=[request_id=123] [info] My request logLogging to Files
Perhaps one of the easiest features within Logger is changing the log’s destination to a file rather than the default console.
First, you need to set up a new backend for the logger_file_backend package:
1config :logger,
2 backends: [{LoggerFileBackend, :debug_log}]Then, you specify the destination file that Logger will send the logs to:
1config :logger, :debug_log,
2 path: 'myLog.log',
3 level: :debugWhen you tail -f your myLog.log file, you should see the logs.
Conclusion
It’s unbelievable how such a simple subject like logging can lead to a lot of unseen extra information.
Earlier this year, Elixir v1.10 was released providing tighter integration with Erlang’s new logger. Now, all your Logger levels, metadata, and messages are shared between Erlang and Elixir applications. This is great for interoperability between both languages, which leads to more ease when mixing them in a single project.
I strongly recommend that you go through the Logger documentation to discover more on this amazing part of the language.
P.S. If you'd like to read Elixir Alchemy posts as soon as they get off the press, subscribe to our Elixir Alchemy newsletter and never miss a single post!
