Merge pull request #100 from basho/adt-record-printing

Support pretty printing records found in a module at compile time

src/lager.erl

@@ -28,7 +28,7 @@
         clear_all_traces/0, stop_trace/1, status/0,
         get_loglevel/1, set_loglevel/2, set_loglevel/3, get_loglevels/0,
         minimum_loglevel/1, posix_error/1,
-        safe_format/3, safe_format_chop/3,dispatch_log/5]).
+        safe_format/3, safe_format_chop/3,dispatch_log/5, pr/2]).
 
 -type log_level() :: debug | info | notice | warning | error | critical | alert | emergency.
 -type log_level_number() :: 0..7.
@@ -265,3 +265,33 @@ safe_format(Fmt, Args, Limit, Options) ->
 %% @private
 safe_format_chop(Fmt, Args, Limit) ->
     safe_format(Fmt, Args, Limit, [{chomp, true}]).
+
+%% @doc Print a record lager found during parse transform
+pr(Record, Module) when is_tuple(Record), is_atom(element(1, Record)) ->
+    try Module:module_info(attributes) of
+        Attrs ->
+            case lists:keyfind(lager_records, 1, Attrs) of
+                false ->
+                    Record;
+                {lager_records, Records} ->
+                    RecordName = element(1, Record),
+                    RecordSize = tuple_size(Record) - 1,
+                    case lists:filter(fun({Name, Fields}) when Name == RecordName,
+                                length(Fields) == RecordSize ->
+                                    true;
+                                (_) ->
+                                    false
+                            end, Records) of
+                        [] ->
+                            Record;
+                        [{RecordName, RecordFields}|_] ->
+                            {'$lager_record', RecordName,
+                                lists:zip(RecordFields, tl(tuple_to_list(Record)))}
+                    end
+            end
+    catch
+        error:undef ->
+            Record
+    end;
+pr(Record, _) ->
+    Record.

src/lager_transform.erl

@@ -31,10 +31,11 @@
 parse_transform(AST, Options) ->
     TruncSize = proplists:get_value(lager_truncation_size, Options, ?DEFAULT_TRUNCATION),
     put(truncation_size, TruncSize),
+    erlang:put(records, []),
     walk_ast([], AST).
 
 walk_ast(Acc, []) ->
-    lists:reverse(Acc);
+    insert_record_attribute(Acc);
 walk_ast(Acc, [{attribute, _, module, {Module, _PmodArgs}}=H|T]) ->
     %% A wild parameterized module appears!
     put(module, Module),
@@ -46,6 +47,14 @@ walk_ast(Acc, [{function, Line, Name, Arity, Clauses}|T]) ->
     put(function, Name),
     walk_ast([{function, Line, Name, Arity,
                 walk_clauses([], Clauses)}|Acc], T);
+walk_ast(Acc, [{attribute, _, record, {Name, Fields}}=H|T]) ->
+    FieldNames = lists:map(fun({record_field, _, {atom, _, FieldName}}) ->
+                FieldName;
+            ({record_field, _, {atom, _, FieldName}, _Default}) ->
+                FieldName
+        end, Fields),
+    stash_record({Name, FieldNames}),
+    walk_ast([H|Acc], T);
 walk_ast(Acc, [H|T]) ->
     walk_ast([H|Acc], T).
 
@@ -129,3 +138,19 @@ concat_lists({nil, _Line}, B) ->
     B;
 concat_lists({cons, Line, Element, Tail}, B) ->
     {cons, Line, Element, concat_lists(Tail, B)}.
+
+stash_record(Record) ->
+    Records = case erlang:get(records) of
+        undefined ->
+            [];
+        R ->
+            R
+    end,
+    erlang:put(records, [Record|Records]).
+
+insert_record_attribute(AST) ->
+    lists:foldl(fun({attribute, Line, module, _}=E, Acc) ->
+                [E, {attribute, Line, lager_records, erlang:get(records)}|Acc];
+            (E, Acc) ->
+                [E|Acc]
+        end, [], AST).

src/lager_trunc_io.erl

@@ -262,6 +262,11 @@ print(Port, _Max, _Options) when is_port(Port) ->
     L = erlang:port_to_list(Port),
     {L, length(L)};
 
+print({'$lager_record', Name, Fields}, Max, Options) ->
+    Leader = "#" ++ atom_to_list(Name) ++ "{",
+    {RC, Len} = record_fields(Fields, Max - length(Leader) + 1, dec_depth(Options)),
+    {[Leader, RC, "}"], Len + length(Leader) + 1};
+
 print(Tuple, Max, Options) when is_tuple(Tuple) -> 
     {TC, Len} = tuple_contents(Tuple, Max-2, Options),
     {[${, TC, $}], Len + 2};
@@ -436,6 +441,23 @@ escape($\f) -> "\\f";
 escape($\b) -> "\\b";
 escape($\v) -> "\\v".
 
+record_fields([], _, _) ->
+    {"", 0};
+record_fields(_, Max, #print_options{depth=D}) when Max < 4; D == 0 ->
+    {"...", 3};
+record_fields([{Field, Value}|T], Max, Options) ->
+    {ExtraChars, Terminator} = case T of
+        [] ->
+            {1, []};
+        _ ->
+            {2, ","}
+    end,
+    {FieldStr, FieldLen} = print(Field, Max - ExtraChars, Options),
+    {ValueStr, ValueLen} = print(Value, Max - (FieldLen + ExtraChars), Options),
+    {Final, FLen} = record_fields(T, Max - (FieldLen + ValueLen + ExtraChars), dec_depth(Options)),
+    {[FieldStr++"="++ValueStr++Terminator|Final], FLen + FieldLen + ValueLen + ExtraChars}.
+
+
 -ifdef(TEST).
 %%--------------------
 %% The start of a test suite. So far, it only checks for not crashing.

test/lager_test_backend.erl

@@ -28,7 +28,7 @@
 
 -ifdef(TEST).
 -include_lib("eunit/include/eunit.hrl").
--export([pop/0, count/0, count_ignored/0, flush/0]).
+-export([pop/0, count/0, count_ignored/0, flush/0, print_state/0]).
 -endif.
 
 init(Level) ->
@@ -51,6 +51,14 @@ handle_call(get_loglevel, #state{level=Level} = State) ->
     {ok, Level, State};
 handle_call({set_loglevel, Level}, State) ->
     {ok, ok, State#state{level=lager_util:level_to_num(Level)}};
+handle_call(print_state, State) ->
+    spawn(fun() -> lager:info("State ~p", [lager:pr(State, ?MODULE)]) end),
+    timer:sleep(100),
+    {ok, ok, State};
+handle_call(print_bad_state, State) ->
+    spawn(fun() -> lager:info("State ~p", [lager:pr({state, 1}, ?MODULE)]) end),
+    timer:sleep(100),
+    {ok, ok, State};
 handle_call(_Request, State) ->
     {ok, ok, State}.
 
@@ -89,6 +97,12 @@ count_ignored() ->
 flush() ->
     gen_event:call(lager_event, ?MODULE, flush).
 
+print_state() ->
+    gen_event:call(lager_event, ?MODULE, print_state).
+
+print_bad_state() ->
+    gen_event:call(lager_event, ?MODULE, print_bad_state).
+
 has_line_numbers() ->
     %% are we R15 or greater
     Rel = erlang:system_info(otp_release),
@@ -220,6 +234,54 @@ lager_test_() ->
                         ?assertEqual(1, count()),
                         ok
                 end
+            },
+            {"record printing works",
+                fun() ->
+                        print_state(),
+                        {Level, _Time, Message, _Metadata}  = pop(),
+                        ?assertMatch(Level, lager_util:level_to_num(info)),
+                        ?assertEqual("State #state{level=6,buffer=[],ignored=[]}", lists:flatten(Message)),
+                        ok
+                end
+            },
+            {"record printing fails gracefully",
+                fun() ->
+                        print_bad_state(),
+                        {Level, _Time, Message, _Metadata}  = pop(),
+                        ?assertMatch(Level, lager_util:level_to_num(info)),
+                        ?assertEqual("State {state,1}", lists:flatten(Message)),
+                        ok
+                end
+            },
+            {"record printing fails gracefully when no lager_record attribute",
+                fun() ->
+                        spawn(fun() -> lager:info("State ~p", [lager:pr({state, 1}, lager)]) end),
+                        timer:sleep(100),
+                        {Level, _Time, Message, _Metadata}  = pop(),
+                        ?assertMatch(Level, lager_util:level_to_num(info)),
+                        ?assertEqual("State {state,1}", lists:flatten(Message)),
+                        ok
+                end
+            },
+            {"record printing fails gracefully when input is not a tuple",
+                fun() ->
+                        spawn(fun() -> lager:info("State ~p", [lager:pr(ok, lager)]) end),
+                        timer:sleep(100),
+                        {Level, _Time, Message, _Metadata}  = pop(),
+                        ?assertMatch(Level, lager_util:level_to_num(info)),
+                        ?assertEqual("State ok", lists:flatten(Message)),
+                        ok
+                end
+            },
+            {"record printing fails gracefully when module is invalid",
+                fun() ->
+                        spawn(fun() -> lager:info("State ~p", [lager:pr({state, 1}, not_a_module)]) end),
+                        timer:sleep(100),
+                        {Level, _Time, Message, _Metadata}  = pop(),
+                        ?assertMatch(Level, lager_util:level_to_num(info)),
+                        ?assertEqual("State {state,1}", lists:flatten(Message)),
+                        ok
+                end
             }
         ]
     }.