eLog/src/formatter/rumFormatter.erl

-module(rumFormatter).

-include("eRum.hrl").

-ifdef(TEST).
-include_lib("eunit/include/eunit.hrl").
-endif.

%%
%% Exported Functions
%%
-export([format/2, format/3]).

%%
%% API Functions
%%

%% @doc 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.  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 similarly nested
%% or refer to other properties, if desired. You can also use a {atom, semi-iolist(), semi-iolist()} formatter, which
%% acts like a ternary operator's true/false branches.
%%
%% The metadata properties date,time, message, severity, and sev will always exist.  
%% The properties pid, file, line, module, and function will always exist if the parser transform is used.
%%
%% Example:
%%
%%    `["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 metada print "My pid is ?.?.?", otherwise print "Unknown Pid"
%% @end
-spec format(rumMsg:rumMsg(), list(), list()) -> any().
format(Msg, [], Colors) ->
   format(Msg, [{eol, "\n"}], Colors);
format(Msg, [{eol, EOL}], Colors) ->
   Config = case application:get_env(lager, metadata_whitelist) of
               undefined -> config(EOL, []);
               {ok, Whitelist} -> config(EOL, Whitelist)
            end,
   format(Msg, Config, Colors);
format(Message, Config, Colors) ->
   [case V of
       color -> output_color(Message, Colors);
       _ -> output(V, Message)
    end || V <- Config].

-spec format(rumMsg:rumMsg(), list()) -> any().
format(Msg, Config) ->
   format(Msg, Config, []).

-spec output(term(), rumMsg:rumMsg()) -> iolist().
output(message, Msg) -> rumMsg:message(Msg);
output(date, Msg) ->
   {D, _T} = rumMsg:datetime(Msg),
   D;
output(time, Msg) ->
   {_D, T} = rumMsg:datetime(Msg),
   T;
output(severity, Msg) ->
   atom_to_list(rumMsg:severity(Msg));
output(severity_upper, Msg) ->
   uppercase_severity(rumMsg:severity(Msg));
output(blank, _Msg) ->
   output({blank, " "}, _Msg);
output(node, _Msg) ->
   output({node, atom_to_list(node())}, _Msg);
output({blank, Fill}, _Msg) ->
   Fill;
output(sev, Msg) ->
   %% Write brief acronym for the severity level (e.g. debug -> $D)
   [rumUtil:levelToChr(rumMsg:severity(Msg))];
output(metadata, Msg) ->
   output({metadata, "=", " "}, Msg);
output({metadata, IntSep, FieldSep}, Msg) ->
   MD = lists:keysort(1, rumMsg:metadata(Msg)),
   string:join([io_lib:format("~s~s~p", [K, IntSep, V]) || {K, V} <- MD], FieldSep);
output({pterm, Key}, Msg) ->
   output({pterm, Key, ""}, Msg);
output({pterm, Key, Default}, _Msg) ->
   make_printable(maybe_get_persistent_term(Key, Default));
output(Prop, Msg) when is_atom(Prop) ->
   Metadata = rumMsg:metadata(Msg),
   make_printable(get_metadata(Prop, Metadata, <<"Undefined">>));
output({Prop, Default}, Msg) when is_atom(Prop) ->
   Metadata = rumMsg:metadata(Msg),
   make_printable(get_metadata(Prop, Metadata, output(Default, Msg)));
output({Prop, Present, Absent}, Msg) when is_atom(Prop) ->
   %% sort of like a poor man's ternary operator
   Metadata = rumMsg:metadata(Msg),
   case get_metadata(Prop, Metadata) of
      undefined ->
         [output(V, Msg) || V <- Absent];
      _ ->
         [output(V, Msg) || V <- Present]
   end;
output({Prop, Present, Absent, Width}, Msg) when is_atom(Prop) ->
   %% sort of like a poor man's ternary operator
   Metadata = rumMsg:metadata(Msg),
   case get_metadata(Prop, Metadata) of
      undefined ->
         [output(V, Msg, Width) || V <- Absent];
      _ ->
         [output(V, Msg, Width) || V <- Present]
   end;
output(Other, _) -> make_printable(Other).

output(message, Msg, _Width) -> rumMsg:message(Msg);
output(date, Msg, _Width) ->
   {D, _T} = rumMsg:datetime(Msg),
   D;
output(time, Msg, _Width) ->
   {_D, T} = rumMsg:datetime(Msg),
   T;
output(severity, Msg, Width) ->
   make_printable(atom_to_list(rumMsg:severity(Msg)), Width);
output(sev, Msg, _Width) ->
   %% Write brief acronym for the severity level (e.g. debug -> $D)
   [rumUtil:levelToChr(rumMsg:severity(Msg))];
output(node, Msg, _Width) ->
   output({node, atom_to_list(node())}, Msg, _Width);
output(blank, _Msg, _Width) ->
   output({blank, " "}, _Msg, _Width);
output({blank, Fill}, _Msg, _Width) ->
   Fill;
output(metadata, Msg, _Width) ->
   output({metadata, "=", " "}, Msg, _Width);
output({metadata, IntSep, FieldSep}, Msg, _Width) ->
   MD = lists:keysort(1, rumMsg:metadata(Msg)),
   [string:join([io_lib:format("~s~s~p", [K, IntSep, V]) || {K, V} <- MD], FieldSep)];
output({pterm, Key}, Msg, Width) ->
   output({pterm, Key, ""}, Msg, Width);
output({pterm, Key, Default}, _Msg, _Width) ->
   make_printable(maybe_get_persistent_term(Key, Default));

output(Prop, Msg, Width) when is_atom(Prop) ->
   Metadata = rumMsg:metadata(Msg),
   make_printable(get_metadata(Prop, Metadata, <<"Undefined">>), Width);
output({Prop, Default}, Msg, Width) when is_atom(Prop) ->
   Metadata = rumMsg:metadata(Msg),
   make_printable(get_metadata(Prop, Metadata, output(Default, Msg)), Width);
output(Other, _, Width) -> make_printable(Other, Width).

output_color(_Msg, []) -> [];
output_color(Msg, Colors) ->
   Level = rumMsg:severity(Msg),
   case lists:keyfind(Level, 1, Colors) of
      {_, Color} -> Color;
      _ -> []
   end.

-spec make_printable(any()) -> iolist().
make_printable(A) when is_atom(A) -> atom_to_list(A);
make_printable(P) when is_pid(P) -> pid_to_list(P);
make_printable(L) when is_list(L) orelse is_binary(L) -> L;
make_printable(Other) -> io_lib:format("~p", [Other]).

make_printable(A, W) when is_integer(W) -> string:left(make_printable(A), W);
make_printable(A, {Align, W}) when is_integer(W) ->
   case Align of
      left ->
         string:left(make_printable(A), W);
      centre ->
         string:centre(make_printable(A), W);
      right ->
         string:right(make_printable(A), W);
      _ ->
         string:left(make_printable(A), W)
   end;

make_printable(A, _W) -> make_printable(A).

%% persistent term was introduced in OTP 21.2, so
%% if we're running on an older OTP, just return the
%% default value.
-ifdef(OTP_RELEASE).
maybe_get_persistent_term(Key, Default) ->
   try
      persistent_term:get(Key, Default)
   catch
      _:undef -> Default
   end.
-else.
maybe_get_persistent_term(_Key, Default) -> Default.
-endif.

run_function(Function, Default) ->
   try Function() of
      Result ->
         Result
   catch
      _:_ ->
         Default
   end.

get_metadata(Key, Metadata) ->
   get_metadata(Key, Metadata, undefined).

get_metadata(Key, Metadata, Default) ->
   case lists:keyfind(Key, 1, Metadata) of
      false ->
         Default;
      {Key, Value} when is_function(Value) ->
         run_function(Value, Default);
      {Key, Value} ->
         Value
   end.

config(EOL, []) ->
   [
      date, " ", time, " ", color, "[", severity, "] ",
      {pid, ""},
      {module, [
         {pid, ["@"], ""},
         module,
         {function, [":", function], ""},
         {line, [":", line], ""}], ""},
      " ", message, EOL
   ];
config(EOL, MetaWhitelist) ->
   [
      date, " ", time, " ", color, "[", severity, "] ",
      {pid, ""},
      {module, [
         {pid, ["@"], ""},
         module,
         {function, [":", function], ""},
         {line, [":", line], ""}], ""},
      " "
   ] ++
      [{M, [atom_to_list(M), "=", M, " "], ""} || M <- MetaWhitelist] ++
      [message, EOL].



uppercase_severity(debug) -> "DEBUG";
uppercase_severity(info) -> "INFO";
uppercase_severity(notice) -> "NOTICE";
uppercase_severity(warning) -> "WARNING";
uppercase_severity(error) -> "ERROR";
uppercase_severity(critical) -> "CRITICAL";
uppercase_severity(alert) -> "ALERT";
uppercase_severity(emergency) -> "EMERGENCY".

-ifdef(TEST).
date_time_now() ->
   Now = os:timestamp(),
   {Date, Time} = rumUtil:format_time(rumUtil:maybe_utc(rumUtil:localtime_ms(Now))),
   {Date, Time, Now}.

basic_test_() ->
   {Date, Time, Now} = date_time_now(),
   [{"Default formatting test",
      ?_assertEqual(iolist_to_binary([Date, " ", Time, " [error] ", pid_to_list(self()), " Message\n"]),
         iolist_to_binary(format(rumMsg:new("Message",
            Now,
            error,
            [{pid, self()}],
            []),
            [])))
   },
      {"Basic Formatting",
         ?_assertEqual(<<"Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, self()}],
               []),
               ["Simplist Format"])))
      },
      {"Default equivalent formatting test",
         ?_assertEqual(iolist_to_binary([Date, " ", Time, " [error] ", pid_to_list(self()), " Message\n"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, self()}],
               []),
               [date, " ", time, " [", severity, "] ", pid, " ", message, "\n"]
            )))
      },
      {"Non existent metadata can default to string",
         ?_assertEqual(iolist_to_binary([Date, " ", Time, " [error] Fallback Message\n"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, self()}],
               []),
               [date, " ", time, " [", severity, "] ", {does_not_exist, "Fallback"}, " ", message, "\n"]
            )))
      },
      {"Non existent metadata can default to other metadata",
         ?_assertEqual(iolist_to_binary([Date, " ", Time, " [error] Fallback Message\n"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, "Fallback"}],
               []),
               [date, " ", time, " [", severity, "] ", {does_not_exist, pid}, " ", message, "\n"]
            )))
      },
      {"Non existent metadata can default to a string2",
         ?_assertEqual(iolist_to_binary(["Unknown Pid"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [],
               []),
               [{pid, ["My pid is ", pid], ["Unknown Pid"]}]
            )))
      },
      {"Metadata can have extra formatting",
         ?_assertEqual(iolist_to_binary(["My pid is hello"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               [{pid, ["My pid is ", pid], ["Unknown Pid"]}]
            )))
      },
      {"Metadata can have extra formatting1",
         ?_assertEqual(iolist_to_binary(["servername"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}, {server, servername}],
               []),
               [{server, {pid, ["(", pid, ")"], ["(Unknown Server)"]}}]
            )))
      },
      {"Metadata can have extra formatting2",
         ?_assertEqual(iolist_to_binary(["(hello)"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               [{server, {pid, ["(", pid, ")"], ["(Unknown Server)"]}}]
            )))
      },
      {"Metadata can have extra formatting3",
         ?_assertEqual(iolist_to_binary(["(Unknown Server)"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [],
               []),
               [{server, {pid, ["(", pid, ")"], ["(Unknown Server)"]}}]
            )))
      },
      {"Metadata can be printed in its enterity",
         ?_assertEqual(iolist_to_binary(["bar=2 baz=3 foo=1"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{foo, 1}, {bar, 2}, {baz, 3}],
               []),
               [metadata]
            )))
      },
      {"Metadata can be printed in its enterity with custom seperators",
         ?_assertEqual(iolist_to_binary(["bar->2, baz->3, foo->1"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{foo, 1}, {bar, 2}, {baz, 3}],
               []),
               [{metadata, "->", ", "}]
            )))
      },
      {"Metadata can have extra formatting with width 1",
         ?_assertEqual(iolist_to_binary(["(hello     )(hello     )(hello)(hello)(hello)"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               ["(", {pid, [pid], "", 10}, ")",
                  "(", {pid, [pid], "", {bad_align, 10}}, ")",
                  "(", {pid, [pid], "", bad10}, ")",
                  "(", {pid, [pid], "", {right, bad20}}, ")",
                  "(", {pid, [pid], "", {bad_align, bad20}}, ")"]
            )))
      },
      {"Metadata can have extra formatting with width 2",
         ?_assertEqual(iolist_to_binary(["(hello     )"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               ["(", {pid, [pid], "", {left, 10}}, ")"]
            )))
      },
      {"Metadata can have extra formatting with width 3",
         ?_assertEqual(iolist_to_binary(["(     hello)"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               ["(", {pid, [pid], "", {right, 10}}, ")"]
            )))
      },
      {"Metadata can have extra formatting with width 4",
         ?_assertEqual(iolist_to_binary(["(  hello   )"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               ["(", {pid, [pid], "", {centre, 10}}, ")"]
            )))
      },
      {"Metadata can have extra formatting with width 5",
         ?_assertEqual(iolist_to_binary(["error     |hello     ! (  hello   )"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}],
               []),
               [{x, "", [severity, {blank, "|"}, pid], 10}, "!", blank, "(", {pid, [pid], "", {centre, 10}}, ")"]
            )))
      },
      {"Metadata can have extra formatting with width 6",
         ?_assertEqual(iolist_to_binary([Time, Date, " bar=2 baz=3 foo=1 pid=hello EMessage"]),
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, hello}, {foo, 1}, {bar, 2}, {baz, 3}],
               []),
               [{x, "", [time]}, {x, "", [date], 20}, blank, {x, "", [metadata], 30}, blank, {x, "", [sev], 10}, message, {message, message, "", {right, 20}}]
            )))
      },
      {"Uppercase Severity Formatting - DEBUG",
         ?_assertEqual(<<"DEBUG Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               debug,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - INFO",
         ?_assertEqual(<<"INFO Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               info,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - NOTICE",
         ?_assertEqual(<<"NOTICE Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               notice,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - WARNING",
         ?_assertEqual(<<"WARNING Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               warning,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - ERROR",
         ?_assertEqual(<<"ERROR Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               error,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - CRITICAL",
         ?_assertEqual(<<"CRITICAL Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               critical,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - ALERT",
         ?_assertEqual(<<"ALERT Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               alert,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"Uppercase Severity Formatting - EMERGENCY",
         ?_assertEqual(<<"EMERGENCY Simplist Format">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               emergency,
               [{pid, self()}],
               []),
               [severity_upper, " Simplist Format"])))
      },
      {"pterm presence test",
         %% skip test on OTP < 21
         case list_to_integer(erlang:system_info(otp_release)) >= 21 of
            true ->
               ?_assertEqual(<<"Pterm is: something">>,
                  begin
                     persistent_term:put(thing, something),
                     Ret = iolist_to_binary(format(rumMsg:new("Message",
                        Now,
                        emergency,
                        [{pid, self()}],
                        []),
                        ["Pterm is: ", {pterm, thing}])),
                     persistent_term:erase(thing),
                     Ret
                  end);
            false -> ?_assert(true)
         end
      },
      {"pterm absence test",
         ?_assertEqual(<<"Pterm is: nothing">>,
            iolist_to_binary(format(rumMsg:new("Message",
               Now,
               emergency,
               [{pid, self()}],
               []),
               ["Pterm is: ", {pterm, thing, "nothing"}])))
      },
      {"node formatting basic",
         begin
            [N, "foo"] = format(rumMsg:new("Message",
               Now,
               info,
               [{pid, self()}],
               []),
               [node, "foo"]),
            ?_assertNotMatch(nomatch, re:run(N, <<"@">>))
         end
      }
   ].

-endif.