Lager (as in the beer) is a logging framework for Erlang. Its purpose is to provide a more traditional way to perform logging in an erlang application that plays nicely with traditional UNIX logging tools like logrotate and syslog.
Travis-CI ::
- Finer grained log levels (debug, info, notice, warning, error, critical, alert, emergency)
- Logger calls are transformed using a parse transform to allow capturing Module/Function/Line/Pid information
- When no handler is consuming a log level (eg. debug) no event is sent to the log handler
- Supports multiple backends, including console and file.
- Supports multiple sinks
- Rewrites common OTP error messages into more readable messages
- Support for pretty printing records encountered at compile time
- Tolerant in the face of large or many log messages, won't out of memory the node
- Optional feature to bypass log size truncation ("unsafe")
- Supports internal time and date based rotation, as well as external rotation tools
- Syslog style log level comparison flags
- Colored terminal output (requires R16+)
- Map support (requires 17+)
To use lager in your application, you need to define it as a rebar dep or have some other way of including it in Erlang's path. You can then add the following option to the erlang compiler flags:
{parse_transform, lager_transform}
Alternately, you can add it to the module you wish to compile with logging enabled:
-compile([{parse_transform, lager_transform}]).
Before logging any messages, you'll need to start the lager application. The
lager module's start
function takes care of loading and starting any dependencies
lager requires.
lager:start().
You can also start lager on startup with a switch to erl
:
erl -pa path/to/lager/ebin -s lager
Once you have built your code with lager and started the lager application, you can then generate log messages by doing the following:
lager:error("Some message")
Or:
lager:warning("Some message with a term: ~p", [Term])
The general form is lager:Severity()
where Severity
is one of the log levels
mentioned above.
To configure lager's backends, you use an application variable (probably in your app.config):
{lager, [
{log_root, "/var/log/hello"},
{handlers, [
{lager_console_backend, info},
{lager_file_backend, [{file, "error.log"}, {level, error}]},
{lager_file_backend, [{file, "console.log"}, {level, info}]}
]}
]}.
log_root
variable is optional, by default file paths are relative to CWD.
The available configuration options for each backend are listed in their module's documentation.
Lager has traditionally supported a single sink (implemented as a
gen_event
manager) named lager_event
to which all backends were
connected.
Lager now supports extra sinks; each sink can have different sync/async message thresholds and different backends.
To use multiple sinks (beyond the built-in sink of lager and lager_event), you need to:
- Setup rebar.config
- Configure the backends in app.config
Each sink has two names: one atom to be used like a module name for
sending messages, and that atom with _lager_event
appended for backend
configuration.
This reflects the legacy behavior: lager:info
(or critical
, or
debug
, etc) is a way of sending a message to a sink named
lager_event
. Now developers can invoke audit:info
or
myCompanyName:debug
so long as the corresponding audit_lager_event
or
myCompanyName_lager_event
sinks are configured.
In rebar.config
for the project that requires lager, include a list
of sink names (without the _lager_event
suffix) in erl_opts
:
{lager_extra_sinks, [audit]}
To be useful, sinks must be configured at runtime with backends.
In app.config
for the project that requires lager, for example,
extend the lager configuration to include an extra_sinks
tuple with
backends (aka "handlers") and optionally async_threshold
and
async_threshold_window
values (see Overload Protection
below). If async values are not configured, no overload protection
will be applied on that sink.
[{lager, [
{log_root, "/tmp"},
%% Default handlers for lager/lager_event
{handlers, [
{lager_console_backend, info},
{lager_file_backend, [{file, "error.log"}, {level, error}]},
{lager_file_backend, [{file, "console.log"}, {level, info}]}
]},
%% Any other sinks
{extra_sinks,
[
{audit_lager_event,
[{handlers,
[{lager_file_backend,
[{file, "sink1.log"},
{level, info}
]
}]
},
{async_threshold, 500},
{async_threshold_window, 50}]
}]
}
]
}
].
All loggers have a default formatting that can be overriden. A formatter is any module that
exports format(#lager_log_message{},Config#any())
. It is specified as part of the configuration
for the backend:
{lager, [
{handlers, [
{lager_console_backend, [info, {lager_default_formatter, [time," [",severity,"] ", message, "\n"]}]},
{lager_file_backend, [{file, "error.log"}, {level, error}, {formatter, lager_default_formatter},
{formatter_config, [date, " ", time," [",severity,"] ",pid, " ", message, "\n"]}]},
{lager_file_backend, [{file, "console.log"}, {level, info}]}
]}
]}.
Included is lager_default_formatter
. This provides a generic, default formatting for log messages using a structure similar to Erlang's iolist which we call "semi-iolist":
- Any traditional iolist elements in the configuration are printed verbatim.
- Atoms in the configuration are treated as placeholders for lager metadata and extracted from the log message.
- The placeholders
date
,time
,message
,sev
andseverity
will always exist. sev
is an abbreviated severity which is interpreted as a capitalized single letter encoding of the severity level (e.g.'debug'
->$D
)- The placeholders
pid
,file
,line
,module
,function
, andnode
will always exist if the parse transform is used. - Applications can define their own metadata placeholder.
- A tuple of
{atom(), semi-iolist()}
allows for a fallback for the atom placeholder. If the value represented by the atom cannot be found, the semi-iolist will be interpreted instead. - A tuple of
{atom(), semi-iolist(), semi-iolist()}
represents a conditional operator: if a value for the atom placeholder can be found, the first semi-iolist will be output; otherwise, the second will be used.
- The placeholders
Examples:
["Foo"] -> "Foo", regardless of message content.
[message] -> The content of the logged message, alone.
[{pid,"Unknown Pid"}] -> "<?.?.?>" if pid is in the metadata, "Unknown Pid" if not.
[{pid, ["My pid is ", pid], ["Unknown Pid"]}] -> if pid is in the metadata print "My pid is <?.?.?>", otherwise print "Unknown Pid"
[{server,{pid, ["(", pid, ")"], ["(Unknown Server)"]}}] -> user provided server metadata, otherwise "(<?.?.?>)", otherwise "(Unknown Server)"
Lager is also supplied with a error_logger
handler module that translates
traditional erlang error messages into a friendlier format and sends them into
lager itself to be treated like a regular lager log call. To disable this, set
the lager application variable error_logger_redirect
to false
.
The error_logger
handler will also log more complete error messages (protected
with use of trunc_io
) to a "crash log" which can be referred to for further
information. The location of the crash log can be specified by the crash_log
application variable. If set to undefined
it is not written at all.
Messages in the crash log are subject to a maximum message size which can be
specified via the crash_log_msg_size
application variable.
Prior to lager 2.0, the gen_event
at the core of lager operated purely in
synchronous mode. Asynchronous mode is faster, but has no protection against
message queue overload. In lager 2.0, the gen_event
takes a hybrid approach. it
polls its own mailbox size and toggles the messaging between synchronous and
asynchronous depending on mailbox size.
{async_threshold, 20},
{async_threshold_window, 5}
This will use async messaging until the mailbox exceeds 20 messages, at which
point synchronous messaging will be used, and switch back to asynchronous, when
size reduces to 20 - 5 = 15
.
If you wish to disable this behaviour, simply set it to undefined
. It defaults
to a low number to prevent the mailbox growing rapidly beyond the limit and causing
problems. In general, lager should process messages as fast as they come in, so getting
20 behind should be relatively exceptional anyway.
If you want to limit the number of messages per second allowed from error_logger
,
which is a good idea if you want to weather a flood of messages when lots of
related processes crash, you can set a limit:
{error_logger_hwm, 50}
It is probably best to keep this number small.
The unsafe code pathway bypasses the normal lager formatting code and uses the same code as error_logger in OTP. This provides a marginal speedup to your logging code (we measured between 0.5-1.3% improvement during our benchmarking; others have reported better improvements.)
This is a dangerous feature. It will not protect you against large log messages - large messages can kill your application and even your Erlang VM dead due to memory exhaustion as large terms are copied over and over in a failure cascade. We strongly recommend that this code pathway only be used by log messages with a well bounded upper size of around 500 bytes.
If there's any possibility the log messages could exceed that limit, you should use the normal lager message formatting code which will provide the appropriate size limitations and protection against memory exhaustion.
If you want to format an unsafe log message, you may use the severity level (as
usual) followed by _unsafe
. Here's an example:
lager:info_unsafe("The quick brown ~s jumped over the lazy ~s", ["fox", "dog"]).
You can change the log level of any lager backend at runtime by doing the following:
lager:set_loglevel(lager_console_backend, debug).
Or, for the backend with multiple handles (files, mainly):
lager:set_loglevel(lager_file_backend, "console.log", debug).
Lager keeps track of the minimum log level being used by any backend and suppresses generation of messages lower than that level. This means that debug log messages, when no backend is consuming debug messages, are effectively free. A simple benchmark of doing 1 million debug log messages while the minimum threshold was above that takes less than half a second.
In addition to the regular log level names, you can also do finer grained masking of what you want to log:
info - info and higher (>= is implicit)
=debug - only the debug level
!=info - everything but the info level
<=notice - notice and below
<warning - anything less than warning
These can be used anywhere a loglevel is supplied, although they need to be either a quoted atom or a string.
Lager can rotate its own logs or have it done via an external process. To
use internal rotation, use the size
, date
and count
values in the file
backend's config:
[{file, "error.log"}, {level, error}, {size, 10485760}, {date, "$D0"}, {count, 5}]
This tells lager to log error and above messages to error.log
and to
rotate the file at midnight or when it reaches 10mb, whichever comes first,
and to keep 5 rotated logs in addition to the current one. Setting the
count to 0 does not disable rotation, it instead rotates the file and keeps
no previous versions around. To disable rotation set the size to 0 and the
date to "".
The $D0
syntax is taken from the syntax newsyslog uses in newsyslog.conf.
The relevant extract follows:
Day, week and month time format: The lead-in character
for day, week and month specification is a `$'-sign.
The particular format of day, week and month
specification is: [Dhh], [Ww[Dhh]] and [Mdd[Dhh]],
respectively. Optional time fields default to
midnight. The ranges for day and hour specifications
are:
hh hours, range 0 ... 23
w day of week, range 0 ... 6, 0 = Sunday
dd day of month, range 1 ... 31, or the
letter L or l to specify the last day of
the month.
Some examples:
$D0 rotate every night at midnight
$D23 rotate every day at 23:00 hr
$W0D23 rotate every week on Sunday at 23:00 hr
$W5D16 rotate every week on Friday at 16:00 hr
$M1D0 rotate on the first day of every month at
midnight (i.e., the start of the day)
$M5D6 rotate on every 5th day of the month at
6:00 hr
To configure the crash log rotation, the following application variables are used:
crash_log_size
crash_log_date
crash_log_count
See the .app.src
file for further details.
Lager syslog output is provided as a separate application:
lager_syslog. It is packaged as a
separate application so lager itself doesn't have an indirect dependency on a
port driver. Please see the lager_syslog
README for configuration information.
Lager 2.0 changed the backend API, there are various 3rd party backends for lager available, but they may not have been updated to the new API. As they are updated, links to them can be re-added here.
Lager's parse transform will keep track of any record definitions it encounters
and store them in the module's attributes. You can then, at runtime, print any
record a module compiled with the lager parse transform knows about by using the
lager:pr/2
function, which takes the record and the module that knows about the record:
lager:info("My state is ~p", [lager:pr(State, ?MODULE)])
Often, ?MODULE
is sufficent, but you can obviously substitute that for a literal module name.
lager:pr
also works from the shell.
If you have Erlang R16 or higher, you can tell lager's console backend to be colored. Simply add to lager's application environment config:
{colored, true}
If you don't like the default colors, they are also configurable; see
the .app.src
file for more details.
The output will be colored from the first occurrence of the atom color in the formatting configuration. For example:
{lager_console_backend, [info, {lager_default_formatter, [time, color, " [",severity,"] ", message, "\e[0m\r\n"]}]}
This will make the entire log message, except time, colored. The escape sequence before the line break is needed in order to reset the color after each log message.
Lager supports basic support for redirecting log messages based on log message attributes. Lager automatically captures the pid, module, function and line at the log message callsite. However, you can add any additional attributes you wish:
lager:warning([{request, RequestID},{vhost, Vhost}], "Permission denied to ~s", [User])
Then, in addition to the default trace attributes, you'll be able to trace based on request or vhost:
lager:trace_file("logs/example.com.error", [{vhost, "example.com"}], error)
To persist metadata for the life of a process, you can use lager:md/1
to store metadata
in the process dictionary:
lager:md([{zone, forbidden}])
Note that lager:md
will only accept a list of key/value pairs keyed by atoms.
You can also omit the final argument, and the loglevel will default to
debug
.
Tracing to the console is similar:
lager:trace_console([{request, 117}])
In the above example, the loglevel is omitted, but it can be specified as the second argument if desired.
You can also specify multiple expressions in a filter, or use the *
atom as
a wildcard to match any message that has that attribute, regardless of its
value.
Tracing to an existing logfile is also supported (but see Multiple sink support below):
lager:trace_file("log/error.log", [{module, mymodule}, {function, myfunction}], warning)
To view the active log backends and traces, you can use the lager:status()
function. To clear all active traces, you can use lager:clear_all_traces()
.
To delete a specific trace, store a handle for the trace when you create it,
that you later pass to lager:stop_trace/1
:
{ok, Trace} = lager:trace_file("log/error.log", [{module, mymodule}]),
...
lager:stop_trace(Trace)
Tracing to a pid is somewhat of a special case, since a pid is not a data-type that serializes well. To trace by pid, use the pid as a string:
lager:trace_console([{pid, "<0.410.0>"}])
As of lager 2.0, you can also use a 3 tuple while tracing, where the second element is a comparison operator. The currently supported comparison operators are:
<
- less than=
- equal to>
- greater than
lager:trace_console([{request, '>', 117}, {request, '<', 120}])
Using =
is equivalent to the 2-tuple form.
If using multiple sinks, there are limitations on tracing that you should be aware of.
Traces are specific to a sink, which can be specified via trace filters:
lager:trace_file("log/security.log", [{sink, audit}, {function, myfunction}], warning)
If no sink is thus specified, the default lager sink will be used.
This has two ramifications:
- Traces cannot intercept messages sent to a different sink.
- Tracing to a file already opened via
lager:trace_file
will only be successful if the same sink is specified.
The former can be ameliorated by opening multiple traces; the latter can be fixed by rearchitecting lager's file backend, but this has not been tackled.
Lager defaults to truncating messages at 4096 bytes, you can alter this by
using the {lager_truncation_size, X}
option. In rebar, you can add it to
erl_opts
:
{erl_opts, [{parse_transform, lager_transform}, {lager_truncation_size, 1024}]}.
You can also pass it to erlc
, if you prefer:
erlc -pa lager/ebin +'{parse_transform, lager_transform}' +'{lager_truncation_size, 1024}' file.erl