Implement console tracing, don't generate duplicate messages

src/lager.erl

@@ -109,20 +109,22 @@ trace_file(File, Filter, Level) ->
             end,
             %% install the trace.
             {MinLevel, Traces} = lager_mochiglobal:get(loglevel),
-            lager_mochiglobal:put(loglevel, {MinLevel, [Trace|Traces]});
+            lager_mochiglobal:put(loglevel, {MinLevel, [Trace|Traces]}),
+            ok;
         Error ->
             Error
     end.
 
 trace_console(Filter) ->
-    trace_file(Filter, debug).
+    trace_console(Filter, debug).
 
 trace_console(Filter, Level) ->
     Trace0 = {Filter, Level, lager_console_backend},
     case lager_util:validate_trace(Trace0) of
         {ok, Trace} ->
-            {Level, Traces} = lager_mochiglobal:get(loglevel),
-            lager_mochiglobal:put(loglevel, {Level, [Trace|Traces]});
+            {MinLevel, Traces} = lager_mochiglobal:get(loglevel),
+            lager_mochiglobal:put(loglevel, {MinLevel, [Trace|Traces]}),
+            ok;
         Error ->
             Error
     end.

src/lager_console_backend.erl

@@ -28,6 +28,7 @@
 
 -ifdef(TEST).
 -include_lib("eunit/include/eunit.hrl").
+-compile([{parse_transform, lager_transform}]).
 -endif.
 
 -include("lager.hrl").
@@ -63,6 +64,20 @@ handle_call(_Request, State) ->
     {ok, ok, State}.
 
 %% @private
+handle_event({log, Dest, Level, {Date, Time}, [LevelStr, Location, Message]},
+    #state{level=L, verbose=Verbose} = State) when Level > L ->
+    case lists:member(lager_console_backend, Dest) of
+        true ->
+            case Verbose of
+                true ->
+                    io:put_chars([Date, " ", Time, " ", LevelStr, Location, Message, "\n"]);
+                _ ->
+                    io:put_chars([Time, " ", LevelStr, Message, "\n"])
+            end,
+            {ok, State};
+        false ->
+            {ok, State}
+    end;
 handle_event({log, Level, {Date, Time}, [LevelStr, Location, Message]},
   #state{level=LogLevel, verbose=Verbose} = State) when Level =< LogLevel ->
     case Verbose of
@@ -152,7 +167,71 @@ console_log_test_() ->
                                 ?assert(false)
                         end
                 end
+            },
+            {"tracing should work",
+                fun() ->
+                        Pid = spawn(F(self())),
+                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        erlang:group_leader(Pid, whereis(lager_event)),
+                        lager_mochiglobal:put(loglevel, {?INFO, []}),
+                        lager:debug("Test message"),
+                        receive
+                            {io_request, From, ReplyAs, {put_chars, unicode, _Msg}} ->
+                                From ! {io_reply, ReplyAs, ok},
+                                ?assert(false)
+                        after
+                            500 ->
+                                ?assert(true)
+                        end,
+                        ok = lager:trace_console([{module, ?MODULE}]),
+                        lager:debug("Test message"),
+                        receive
+                            {io_request, From1, ReplyAs1, {put_chars, unicode, Msg1}} ->
+                                From1 ! {io_reply, ReplyAs1, ok},
+                                ?assertMatch([_, "[debug]", "Test message\n"], re:split(Msg1, " ", [{return, list}, {parts, 3}]))
+                        after
+                            500 ->
+                                ?assert(false)
+                        end
+                end
+            },
+            {"tracing doesn't duplicate messages",
+                fun() ->
+                        Pid = spawn(F(self())),
+                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        lager_mochiglobal:put(loglevel, {?INFO, []}),
+                        erlang:group_leader(Pid, whereis(lager_event)),
+                        lager:debug("Test message"),
+                        receive
+                            {io_request, From, ReplyAs, {put_chars, unicode, _Msg}} ->
+                                From ! {io_reply, ReplyAs, ok},
+                                ?assert(false)
+                        after
+                            500 ->
+                                ?assert(true)
+                        end,
+                        ok = lager:trace_console([{module, ?MODULE}]),
+                        lager:error("Test message"),
+                        receive
+                            {io_request, From1, ReplyAs1, {put_chars, unicode, Msg1}} ->
+                                From1 ! {io_reply, ReplyAs1, ok},
+                                ?assertMatch([_, "[error]", "Test message\n"], re:split(Msg1, " ", [{return, list}, {parts, 3}]))
+                        after
+                            1000 ->
+                                ?assert(false)
+                        end,
+                        %% make sure this event wasn't duplicated
+                        receive
+                            {io_request, From2, ReplyAs2, {put_chars, unicode, _Msg2}} ->
+                                From2 ! {io_reply, ReplyAs2, ok},
+                                ?assert(false)
+                        after
+                            500 ->
+                                ?assert(true)
+                        end
+                end
             }
+
         ]
     }.
 

src/lager_file_backend.erl

@@ -85,7 +85,8 @@ handle_call(_Request, State) ->
     {ok, ok, State}.
 
 %% @private
-handle_event({log, Dest, Level, {Date, Time}, Message}, #state{name=Name} = State) ->
+handle_event({log, Dest, Level, {Date, Time}, Message},
+    #state{name=Name, level=L} = State) when Level > L ->
     case lists:member({lager_file_backend, Name}, Dest) of
         true ->
             {ok, write(State, Level, [Date, " ", Time, " ", Message, "\n"])};
@@ -352,7 +353,29 @@ filesystem_test_() ->
                         {ok, Bin} = file:read_file("test.log"),
                         ?assertMatch([_, _, "[error]", _, "Test message\n"], re:split(Bin, " ", [{return, list}, {parts, 5}]))
                 end
+            },
+            {"tracing should not duplicate messages",
+                fun() ->
+                        gen_event:add_handler(lager_event, lager_file_backend,
+                            {"test.log", critical}),
+                        lager:critical("Test message"),
+                        {ok, Bin1} = file:read_file("test.log"),
+                        ?assertMatch([_, _, "[critical]", _, "Test message\n"], re:split(Bin1, " ", [{return, list}, {parts, 5}])),
+                        ok = file:delete("test.log"),
+                        {Level, _} = lager_mochiglobal:get(loglevel),
+                        lager_mochiglobal:put(loglevel, {Level, [{[{module,
+                                                ?MODULE}], ?DEBUG,
+                                        {lager_file_backend, "test.log"}}]}),
+                        lager:critical("Test message"),
+                        {ok, Bin2} = file:read_file("test.log"),
+                        ?assertMatch([_, _, "[critical]", _, "Test message\n"], re:split(Bin2, " ", [{return, list}, {parts, 5}])),
+                        ok = file:delete("test.log"),
+                        lager:error("Test message"),
+                        {ok, Bin3} = file:read_file("test.log"),
+                        ?assertMatch([_, _, "[error]", _, "Test message\n"], re:split(Bin3, " ", [{return, list}, {parts, 5}]))
+                end
             }
+
         ]
     }.