README.md 13.6 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
Overview
--------
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](http://travis-ci.org/basho/lager) :: ![Travis-CI](https://secure.travis-ci.org/basho/lager.png)

Features
--------
* 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 even sent
  to the log handler
* Supports multiple backends, including console and file.
* 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
* Supports internal time and date based rotation, as well as external rotation tools
* Syslog style log level comparison flags
* Colored terminal output (requires R16+)

Usage
-----
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

```erlang
{parse_transform, lager_transform}
```

Alternately, you can add it to the module you wish to compile with logging
enabled:

```erlang
-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.

```erlang
lager:start().
```

You can also start lager on startup with a switch to `erl`:

```erlang
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:

```erlang
lager:error("Some message")
```

  Or:

```erlang
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.

Configuration
-------------
To configure lager's backends, you use an application variable (probably in
your app.config):

```erlang
{lager, [
  {handlers, [
    {lager_console_backend, info},
    {lager_file_backend, [{file, "error.log"}, {level, error}]},
    {lager_file_backend, [{file, "console.log"}, {level, info}]}
  ]}
]}.
```

The available configuration options for each backend are listed in their
module's documentation.

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:

```erlang
{lager, [
  {handlers, [
100
101
    {lager_console_backend, [info, {lager_default_formatter, [time," [",severity,"] ", message, "\n"]}]},
    {lager_file_backend, [{file, "error.log"}, {level, error}, {formatter, lager_default_formatter},
102
      {formatter_config, [date, " ", time," [",severity,"] ",pid, " ", message, "\n"]}]},
103
    {lager_file_backend, [{file, "console.log"}, {level, info}]}
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
  ]}
]}.
```

Included is lager_default_formatter.  This provides a generic, default formatting for log messages using a "semi-iolist"
as configuration.  Any iolist allowed elements in the configuration are printed verbatim.  Atoms in the configuration
are treated as metadata properties and extracted from the log message.
The metadata properties date,time, message, and severity will always exist.
The properties pid, file, line, module, function, and node will always exist if the parser transform is used.

```
["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"
```

Optionally, a tuple of {atom(),semi-iolist()}
can be used.  The atom will look up the property, but if not found it will use the semi-iolist() instead.  These fallbacks
can be nested or refer to other properties.

```
[{pid,"Unknown Pid"}] -> "<?.?.?>" if pid is in the metadata, "Unknown Pid" if not.
[{server,[$(,{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
Benedikt Sauer's avatar
Benedikt Sauer committed
135
the lager application variable `error_logger_redirect` to `false`.
136
137
138
139

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
140
application variable. If set to `undefined` it is not written at all.
141
142
143
144
145
146
147
148
149
150
151
152
153
154

Messages in the crash log are subject to a maximum message size which can be
specified via the crash_log_msg_size application variable.

Overload Protection
-------------------

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.

```erlang
155
156
{async_threshold, 20},
{async_threshold_window, 5}
157
158
159
```

This will use async messaging until the mailbox exceeds 20 messages, at which
160
161
point synchronous messaging will be used, and switch back to asynchronous, when
size reduces to `20 - 5 = 15`.
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304

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:

```erlang
{error_logger_hwm, 50}
```

It is probably best to keep this number small.

Runtime loglevel changes
------------------------
You can change the log level of any lager backend at runtime by doing the
following:

```erlang
lager:set_loglevel(lager_console_backend, debug).
```

  Or, for the backend with multiple handles (files, mainly):

```erlang
lager:set_loglevel(lager_file_backend, "console.log", debug).
```

Lager keeps track of the minium log level being used by any backend and
supresses 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.

Syslog style loglevel comparison flags
--------------------------------------
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.

Internal log rotation
---------------------
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:

```erlang
[{name, "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.

Syslog Support
--------------
Lager syslog output is provided as a separate application;
[lager_syslog](https://github.com/basho/lager_syslog). It is packaged as a
separate application so Lager itself doesn't have an indirect dependancy on a
port driver. Please see the lager_syslog README for configuration information.

Older Backends
--------------
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.

Record Pretty Printing
----------------------
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:

```erlang
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.

Colored terminal output
-----------------------
If you have erlang R16 or higher, you can tell lager's console backend to be colored. Simply
add

```erlang
{colored, true}
```

Daniel Luna's avatar
Daniel Luna committed
305
To lager's application environment config. If you don't like the default colors, they are
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
also configurable, see the app.src file for more details.

Tracing
-------
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:

```erlang
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:

```erlang
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:

```erlang
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:

```erlang
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, if you wanted to log
warnings from a particular module to the default error.log:

```erlang
lager:trace_file("log/error.log", [{module, mymodule}], 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:

```erlang
{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:

```erlang
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

```erlang
egobrain's avatar
egobrain committed
385
lager:trace_console([{request, '>', 117}, {request, '<', 120}])
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
```

Using '=' is equivalent to the 2-tuple form.

Setting the truncation limit at compile-time
--------------------------------------------
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:

```erlang
{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
```