You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

501 lines
17 KiB

11 years ago
  1. Overview
  2. --------
  3. Lager (as in the beer) is a logging framework for Erlang. Its purpose is
  4. to provide a more traditional way to perform logging in an erlang application
  5. that plays nicely with traditional UNIX logging tools like logrotate and
  6. syslog.
  7. [Travis-CI](http://travis-ci.org/basho/lager) :: ![Travis-CI](https://secure.travis-ci.org/basho/lager.png)
  8. Features
  9. --------
  10. * Finer grained log levels (debug, info, notice, warning, error, critical,
  11. alert, emergency)
  12. * Logger calls are transformed using a parse transform to allow capturing
  13. Module/Function/Line/Pid information
  14. * When no handler is consuming a log level (eg. debug) no event is sent
  15. to the log handler
  16. * Supports multiple backends, including console and file.
  17. * Supports multiple sinks
  18. * Rewrites common OTP error messages into more readable messages
  19. * Support for pretty printing records encountered at compile time
  20. * Tolerant in the face of large or many log messages, won't out of memory the node
  21. * Supports internal time and date based rotation, as well as external rotation tools
  22. * Syslog style log level comparison flags
  23. * Colored terminal output (requires R16+)
  24. * Map support (requires 17+)
  25. Usage
  26. -----
  27. To use lager in your application, you need to define it as a rebar dep or have
  28. some other way of including it in Erlang's path. You can then add the
  29. following option to the erlang compiler flags:
  30. ```erlang
  31. {parse_transform, lager_transform}
  32. ```
  33. Alternately, you can add it to the module you wish to compile with logging
  34. enabled:
  35. ```erlang
  36. -compile([{parse_transform, lager_transform}]).
  37. ```
  38. Before logging any messages, you'll need to start the lager application. The
  39. lager module's `start` function takes care of loading and starting any dependencies
  40. lager requires.
  41. ```erlang
  42. lager:start().
  43. ```
  44. You can also start lager on startup with a switch to `erl`:
  45. ```erlang
  46. erl -pa path/to/lager/ebin -s lager
  47. ```
  48. Once you have built your code with lager and started the lager application,
  49. you can then generate log messages by doing the following:
  50. ```erlang
  51. lager:error("Some message")
  52. ```
  53. Or:
  54. ```erlang
  55. lager:warning("Some message with a term: ~p", [Term])
  56. ```
  57. The general form is `lager:Severity()` where `Severity` is one of the log levels
  58. mentioned above.
  59. Configuration
  60. -------------
  61. To configure lager's backends, you use an application variable (probably in
  62. your app.config):
  63. ```erlang
  64. {lager, [
  65. {log_root, "/var/log/hello"},
  66. {handlers, [
  67. {lager_console_backend, info},
  68. {lager_file_backend, [{file, "error.log"}, {level, error}]},
  69. {lager_file_backend, [{file, "console.log"}, {level, info}]}
  70. ]}
  71. ]}.
  72. ```
  73. ```log_root``` variable is optional, by default file paths are relative to CWD.
  74. The available configuration options for each backend are listed in their
  75. module's documentation.
  76. Sinks
  77. -----
  78. Lager has traditionally supported a single sink (implemented as a
  79. `gen_event` manager) named `lager_event` to which all backends were
  80. connected.
  81. Lager now supports extra sinks; each sink can have different
  82. sync/async message thresholds and different backends.
  83. ### Sink configuration
  84. To use multiple sinks (beyond the built-in sink of lager and lager_event), you
  85. need to:
  86. 1. Setup rebar.config
  87. 2. Configure the backends in app.config
  88. #### Names
  89. Each sink has two names: one atom to be used like a module name for
  90. sending messages, and that atom with `_event` appended for backend
  91. configuration.
  92. This reflects the legacy behavior: `lager:info` (or `critical`, or
  93. `debug`, etc) is a way of sending a message to a sink named
  94. `lager_event`. Now developers can invoke `audit:info` or
  95. `myCompanyName:debug` so long as the corresponding `audit_event` or
  96. `myCompanyName_event` sinks are configured.
  97. #### rebar.config
  98. In `rebar.config` for the project that requires lager, include a list
  99. of sink names (without the `_event` suffix) in `erl_opts`:
  100. `{lager_extra_sinks, [audit]}`
  101. #### Runtime requirements
  102. To be useful, sinks must be configured at runtime with backends.
  103. In `app.config` for the project that requires lager, for example,
  104. extend the lager configuration to include an `extra_sinks` tuple with
  105. backends (aka "handlers") and optionally `async_threshold` and
  106. `async_threshold_window` values (see **Overload Protection**
  107. below). If async values are not configured, no overload protection
  108. will be applied on that sink.
  109. ```erlang
  110. [{lager, [
  111. {log_root, "/tmp"},
  112. %% Default handlers for lager/lager_event
  113. {handlers, [
  114. {lager_console_backend, info},
  115. {lager_file_backend, [{file, "error.log"}, {level, error}]},
  116. {lager_file_backend, [{file, "console.log"}, {level, info}]}
  117. ]},
  118. %% Any other sinks
  119. {extra_sinks,
  120. [
  121. {audit_event,
  122. [{handlers,
  123. [{lager_file_backend,
  124. [{file, "sink1.log"},
  125. {level, info}
  126. ]
  127. }]
  128. },
  129. {async_threshold, 500},
  130. {async_threshold_window, 50}]
  131. }]
  132. }
  133. ]
  134. }
  135. ].
  136. ```
  137. Custom Formatting
  138. -----------------
  139. All loggers have a default formatting that can be overriden. A formatter is any module that
  140. exports `format(#lager_log_message{},Config#any())`. It is specified as part of the configuration
  141. for the backend:
  142. ```erlang
  143. {lager, [
  144. {handlers, [
  145. {lager_console_backend, [info, {lager_default_formatter, [time," [",severity,"] ", message, "\n"]}]},
  146. {lager_file_backend, [{file, "error.log"}, {level, error}, {formatter, lager_default_formatter},
  147. {formatter_config, [date, " ", time," [",severity,"] ",pid, " ", message, "\n"]}]},
  148. {lager_file_backend, [{file, "console.log"}, {level, info}]}
  149. ]}
  150. ]}.
  151. ```
  152. Included is `lager_default_formatter`. This provides a generic, default formatting for log messages using a structure similar to Erlang's [iolist](http://learnyousomeerlang.com/buckets-of-sockets#io-lists) which we call "semi-iolist":
  153. * Any traditional iolist elements in the configuration are printed verbatim.
  154. * Atoms in the configuration are treated as placeholders for lager metadata and extracted from the log message.
  155. * The placeholders `date`, `time`, `message`, and `severity` will always exist.
  156. * The placeholders `pid`, `file`, `line`, `module`, `function`, and `node` will always exist if the parse transform is used.
  157. * Applications can define their own metadata placeholder.
  158. * A tuple of `{atom(), semi-iolist()}` allows for a fallback for
  159. the atom placeholder. If the value represented by the atom
  160. cannot be found, the semi-iolist will be interpreted instead.
  161. * A tuple of `{atom(), semi-iolist(), semi-iolist()}` represents a
  162. conditional operator: if a value for the atom placeholder can be
  163. found, the first semi-iolist will be output; otherwise, the
  164. second will be used.
  165. Examples:
  166. ```
  167. ["Foo"] -> "Foo", regardless of message content.
  168. [message] -> The content of the logged message, alone.
  169. [{pid,"Unknown Pid"}] -> "<?.?.?>" if pid is in the metadata, "Unknown Pid" if not.
  170. [{pid, ["My pid is ", pid], ["Unknown Pid"]}] -> if pid is in the metadata print "My pid is <?.?.?>", otherwise print "Unknown Pid"
  171. [{server,{pid, ["(", pid, ")"], ["(Unknown Server)"]}}] -> user provided server metadata, otherwise "(<?.?.?>)", otherwise "(Unknown Server)"
  172. ```
  173. Error logger integration
  174. ------------------------
  175. Lager is also supplied with a `error_logger` handler module that translates
  176. traditional erlang error messages into a friendlier format and sends them into
  177. lager itself to be treated like a regular lager log call. To disable this, set
  178. the lager application variable `error_logger_redirect` to `false`.
  179. The `error_logger` handler will also log more complete error messages (protected
  180. with use of `trunc_io`) to a "crash log" which can be referred to for further
  181. information. The location of the crash log can be specified by the crash_log
  182. application variable. If set to `undefined` it is not written at all.
  183. Messages in the crash log are subject to a maximum message size which can be
  184. specified via the `crash_log_msg_size` application variable.
  185. Overload Protection
  186. -------------------
  187. Prior to lager 2.0, the `gen_event` at the core of lager operated purely in
  188. synchronous mode. Asynchronous mode is faster, but has no protection against
  189. message queue overload. In lager 2.0, the `gen_event` takes a hybrid approach. it
  190. polls its own mailbox size and toggles the messaging between synchronous and
  191. asynchronous depending on mailbox size.
  192. ```erlang
  193. {async_threshold, 20},
  194. {async_threshold_window, 5}
  195. ```
  196. This will use async messaging until the mailbox exceeds 20 messages, at which
  197. point synchronous messaging will be used, and switch back to asynchronous, when
  198. size reduces to `20 - 5 = 15`.
  199. If you wish to disable this behaviour, simply set it to `undefined`. It defaults
  200. to a low number to prevent the mailbox growing rapidly beyond the limit and causing
  201. problems. In general, lager should process messages as fast as they come in, so getting
  202. 20 behind should be relatively exceptional anyway.
  203. If you want to limit the number of messages per second allowed from `error_logger`,
  204. which is a good idea if you want to weather a flood of messages when lots of
  205. related processes crash, you can set a limit:
  206. ```erlang
  207. {error_logger_hwm, 50}
  208. ```
  209. It is probably best to keep this number small.
  210. Runtime loglevel changes
  211. ------------------------
  212. You can change the log level of any lager backend at runtime by doing the
  213. following:
  214. ```erlang
  215. lager:set_loglevel(lager_console_backend, debug).
  216. ```
  217. Or, for the backend with multiple handles (files, mainly):
  218. ```erlang
  219. lager:set_loglevel(lager_file_backend, "console.log", debug).
  220. ```
  221. Lager keeps track of the minimum log level being used by any backend and
  222. suppresses generation of messages lower than that level. This means that debug
  223. log messages, when no backend is consuming debug messages, are effectively
  224. free. A simple benchmark of doing 1 million debug log messages while the
  225. minimum threshold was above that takes less than half a second.
  226. Syslog style loglevel comparison flags
  227. --------------------------------------
  228. In addition to the regular log level names, you can also do finer grained masking
  229. of what you want to log:
  230. ```
  231. info - info and higher (>= is implicit)
  232. =debug - only the debug level
  233. !=info - everything but the info level
  234. <=notice - notice and below
  235. <warning - anything less than warning
  236. ```
  237. These can be used anywhere a loglevel is supplied, although they need to be either
  238. a quoted atom or a string.
  239. Internal log rotation
  240. ---------------------
  241. Lager can rotate its own logs or have it done via an external process. To
  242. use internal rotation, use the `size`, `date` and `count` values in the file
  243. backend's config:
  244. ```erlang
  245. [{file, "error.log"}, {level, error}, {size, 10485760}, {date, "$D0"}, {count, 5}]
  246. ```
  247. This tells lager to log error and above messages to `error.log` and to
  248. rotate the file at midnight or when it reaches 10mb, whichever comes first,
  249. and to keep 5 rotated logs in addition to the current one. Setting the
  250. count to 0 does not disable rotation, it instead rotates the file and keeps
  251. no previous versions around. To disable rotation set the size to 0 and the
  252. date to "".
  253. The `$D0` syntax is taken from the syntax newsyslog uses in newsyslog.conf.
  254. The relevant extract follows:
  255. ```
  256. Day, week and month time format: The lead-in character
  257. for day, week and month specification is a `$'-sign.
  258. The particular format of day, week and month
  259. specification is: [Dhh], [Ww[Dhh]] and [Mdd[Dhh]],
  260. respectively. Optional time fields default to
  261. midnight. The ranges for day and hour specifications
  262. are:
  263. hh hours, range 0 ... 23
  264. w day of week, range 0 ... 6, 0 = Sunday
  265. dd day of month, range 1 ... 31, or the
  266. letter L or l to specify the last day of
  267. the month.
  268. Some examples:
  269. $D0 rotate every night at midnight
  270. $D23 rotate every day at 23:00 hr
  271. $W0D23 rotate every week on Sunday at 23:00 hr
  272. $W5D16 rotate every week on Friday at 16:00 hr
  273. $M1D0 rotate on the first day of every month at
  274. midnight (i.e., the start of the day)
  275. $M5D6 rotate on every 5th day of the month at
  276. 6:00 hr
  277. ```
  278. To configure the crash log rotation, the following application variables are
  279. used:
  280. * `crash_log_size`
  281. * `crash_log_date`
  282. * `crash_log_count`
  283. See the `.app.src` file for further details.
  284. Syslog Support
  285. --------------
  286. Lager syslog output is provided as a separate application:
  287. [lager_syslog](https://github.com/basho/lager_syslog). It is packaged as a
  288. separate application so lager itself doesn't have an indirect dependency on a
  289. port driver. Please see the `lager_syslog` README for configuration information.
  290. Older Backends
  291. --------------
  292. Lager 2.0 changed the backend API, there are various 3rd party backends for
  293. lager available, but they may not have been updated to the new API. As they
  294. are updated, links to them can be re-added here.
  295. Record Pretty Printing
  296. ----------------------
  297. Lager's parse transform will keep track of any record definitions it encounters
  298. and store them in the module's attributes. You can then, at runtime, print any
  299. record a module compiled with the lager parse transform knows about by using the
  300. `lager:pr/2` function, which takes the record and the module that knows about the record:
  301. ```erlang
  302. lager:info("My state is ~p", [lager:pr(State, ?MODULE)])
  303. ```
  304. Often, `?MODULE` is sufficent, but you can obviously substitute that for a literal module name.
  305. `lager:pr` also works from the shell.
  306. Colored terminal output
  307. -----------------------
  308. If you have Erlang R16 or higher, you can tell lager's console backend to be colored. Simply
  309. add to lager's application environment config:
  310. ```erlang
  311. {colored, true}
  312. ```
  313. If you don't like the default colors, they are also configurable; see
  314. the `.app.src` file for more details.
  315. The output will be colored from the first occurrence of the atom color
  316. in the formatting configuration. For example:
  317. ```erlang
  318. {lager_console_backend, [info, {lager_default_formatter, [time, color, " [",severity,"] ", message, "\e[0m\r\n"]}]}
  319. ```
  320. This will make the entire log message, except time, colored. The
  321. escape sequence before the line break is needed in order to reset the
  322. color after each log message.
  323. Tracing
  324. -------
  325. Lager supports basic support for redirecting log messages based on log message
  326. attributes. Lager automatically captures the pid, module, function and line at the
  327. log message callsite. However, you can add any additional attributes you wish:
  328. ```erlang
  329. lager:warning([{request, RequestID},{vhost, Vhost}], "Permission denied to ~s", [User])
  330. ```
  331. Then, in addition to the default trace attributes, you'll be able to trace
  332. based on request or vhost:
  333. ```erlang
  334. lager:trace_file("logs/example.com.error", [{vhost, "example.com"}], error)
  335. ```
  336. To persist metadata for the life of a process, you can use `lager:md/1` to store metadata
  337. in the process dictionary:
  338. ```erlang
  339. lager:md([{zone, forbidden}])
  340. ```
  341. Note that `lager:md` will *only* accept a list of key/value pairs keyed by atoms.
  342. You can also omit the final argument, and the loglevel will default to
  343. `debug`.
  344. Tracing to the console is similar:
  345. ```erlang
  346. lager:trace_console([{request, 117}])
  347. ```
  348. In the above example, the loglevel is omitted, but it can be specified as the
  349. second argument if desired.
  350. You can also specify multiple expressions in a filter, or use the `*` atom as
  351. a wildcard to match any message that has that attribute, regardless of its
  352. value.
  353. Tracing to an existing logfile is also supported, if you wanted to log
  354. warnings from a particular function in a particular module to the default `error.log`:
  355. ```erlang
  356. lager:trace_file("log/error.log", [{module, mymodule}, {function, myfunction}], warning)
  357. ```
  358. To view the active log backends and traces, you can use the `lager:status()`
  359. function. To clear all active traces, you can use `lager:clear_all_traces()`.
  360. To delete a specific trace, store a handle for the trace when you create it,
  361. that you later pass to `lager:stop_trace/1`:
  362. ```erlang
  363. {ok, Trace} = lager:trace_file("log/error.log", [{module, mymodule}]),
  364. ...
  365. lager:stop_trace(Trace)
  366. ```
  367. Tracing to a pid is somewhat of a special case, since a pid is not a
  368. data-type that serializes well. To trace by pid, use the pid as a string:
  369. ```erlang
  370. lager:trace_console([{pid, "<0.410.0>"}])
  371. ```
  372. As of lager 2.0, you can also use a 3 tuple while tracing, where the second
  373. element is a comparison operator. The currently supported comparison operators
  374. are:
  375. * `<` - less than
  376. * `=` - equal to
  377. * `>` - greater than
  378. ```erlang
  379. lager:trace_console([{request, '>', 117}, {request, '<', 120}])
  380. ```
  381. Using `=` is equivalent to the 2-tuple form.
  382. Setting the truncation limit at compile-time
  383. --------------------------------------------
  384. Lager defaults to truncating messages at 4096 bytes, you can alter this by
  385. using the `{lager_truncation_size, X}` option. In rebar, you can add it to
  386. `erl_opts`:
  387. ```erlang
  388. {erl_opts, [{parse_transform, lager_transform}, {lager_truncation_size, 1024}]}.
  389. ```
  390. You can also pass it to `erlc`, if you prefer:
  391. ```
  392. erlc -pa lager/ebin +'{parse_transform, lager_transform}' +'{lager_truncation_size, 1024}' file.erl
  393. ```