XUtils

lager

A logging framework for Erlang/OTP by basho.com.

Elixir
https://github.com/basho/lager

Names

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.

rebar.config

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]}

Runtime requirements

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}]
            }]
          }
         ]
 }
].

Custom Formatting

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 and severity 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, and node 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.

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)"

Error logger integration

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. You can also disable reformatting for OTP and Cowboy messages by setting variable error_logger_format_raw to true.

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 false 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.

Messages from error_logger will be redirected to error_logger_lager_event sink if it is defined so it can be redirected to another log file.

For example:

[{lager, [
         {extra_sinks,
          [
           {error_logger_lager_event, 
            [{handlers, [
              {lager_file_backend, [{file, "error_logger.log"}, {level, info}]}]
              }]
           }]
           }]
}].

will send all error_logger messages to error_logger.log file.

Overload Protection

Asynchronous mode

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. As of 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.

Articles

  • coming soon...