Logging

To use logger in your module, include

-include("mongoose_logger.hrl").

or

-include("mongoose.hrl").

Logging macros

There are several macroses:

DEBUG("event=debug_event info=~1000p", [Arg]),
INFO_MSG("event=info_event info=~1000p", [Arg]),
ERROR_MSG("event=error_event reason=~1000p", [Arg]),
WARNING_MSG("event=warning_event reason=~1000p", [Arg]),

Use them to log on corresponding log level.

Don't use ERROR_MSG for cases that are not errors.

Logging levels

A system operator can choose log level by setting loglevel in mongooseim.cfg.

  • level 5 - debug
  • level 4 - info
  • level 3 - warning
  • level 2 - error
  • level 1 - critical
  • level 0 - none

While there is a macro to log on level 1, we rarely use it.

If an user sets log level 5, than he would see all messages in logs.

Levels 3 or 2 are usually used for production systems.

Logging format

We use modified logfmt format.

This format is Splunk and ELK friendly.

event=something_interesting field is required.

reason=~1000p field is commonly used.

    ?ERROR_MSG("event=check_password_failed "
               "reason=~p user=~ts", [Error, LUser]),

    try ...
    catch
        Class:Reason:StackTrace ->
            ?ERROR_MSG("event=check_password_failed "
                       "reason=~p:~p user=~ts stacktrace=~1000p",
                       [Class, Reason, LUser, StackTrace]),
            erlang:raise(Class, Reason, StackTrace)
    end

user=~ts is often used too.

A common way to name an error event is event=function_name_failed. For example, event=remove_user_failed. Use the advice critically, it would not work well for any function. Counter example:

handle_info(Info, State) ->
    ?ERROR_MSG("issue=unexpected_info_received info=~1000p", [Info]),
    {noreply, State}.

Log messages should not contain new lines.

We usually use ~1000p to log long datastructures.

Use whitespace as a field separator:

%% Use
?ERROR_MSG("event=check_password_failed reason=~p", [Reason])

%% Don't use
?ERROR_MSG("event=check_password_failed, reason=~p", [Reason])

Filtering logs by module

Setting loglevel to debug leads to a flood of messages in logs. To set different loglevel for just one module, call:

ejabberd_loglevel:set(3).
ejabberd_loglevel:set_custom(mod_mam, 5).

This code sets loglevel error for all messages, except generated by mod_mam. All messages from mod_mam would be logged.