Merge pull request #336 from basho/mra/gh315

Ensure traces pointed to files work in config file

Reviewed-by: macintux

README.md

@@ -568,6 +568,38 @@ The former can be ameliorated by opening multiple traces; the latter
 can be fixed by rearchitecting lager's file backend, but this has not
 been tackled.
 
+### Traces from configuration
+
+Lager supports starting traces from its configuration file. The keyword
+to define them is `traces`, followed by a proplist of tuples that define
+a backend handler and zero or more filters in a required list,
+followed by an optional message severity level.
+
+An example looks like this:
+
+```erlang
+{lager, [
+  {handlers, [...]},
+  {traces, [
+    %% handler,                         filter,                message level (defaults to debug if not given)
+    {lager_console_backend,             [{module, foo}],       info },
+    {{lager_file_backend, "trace.log"}, [{request, '>', 120}], error},
+    {{lager_file_backend, "event.log"}, [{module, bar}]             } %% implied debug level here
+  ]}
+]}.
+```
+
+In this example, we have three traces. One using the console backend, and two
+using the file backend. If the message severity level is left out, it defaults
+to `debug` as in the last file backend example.
+
+The `traces` keyword works on alternative sinks too but the same limitations
+and caveats noted above apply.
+
+**IMPORTANT**: You **must** define a severity level in all lager releases
+up to and including 3.1.0 or previous. The 2-tuple form wasn't added until
+3.2.0.
+
 Setting the truncation limit at compile-time
 --------------------------------------------
 Lager defaults to truncating messages at 4096 bytes, you can alter this by

src/lager_app.erl

@@ -261,12 +261,14 @@ add_configured_traces() ->
             TraceVal
     end,
 
-    lists:foreach(fun({Handler, Filter, Level}) ->
-                {ok, _} = lager:trace(Handler, Filter, Level)
-        end,
-        Traces),
+    lists:foreach(fun start_configured_trace/1, Traces),
     ok.
 
+start_configured_trace({Handler, Filter}) ->
+    {ok, _} = lager:trace(Handler, Filter);
+start_configured_trace({Handler, Filter, Level}) when is_atom(Level) ->
+    {ok, _} = lager:trace(Handler, Filter, Level).
+
 maybe_make_handler_id(Mod, Config) ->
     %% Allow the backend to generate a gen_event handler id, if it wants to.
     %% We don't use erlang:function_exported here because that requires the module

src/lager_file_backend.erl

@@ -799,6 +799,64 @@ filesystem_test_() ->
         ]
     }.
 
+trace_files_test_() ->
+    {foreach,
+        fun() ->
+                file:delete("events.log"),
+                file:delete("test.log"),
+                file:delete("debug.log"),
+                error_logger:tty(false),
+                application:load(lager),
+                application:set_env(lager, handlers, [{lager_file_backend, [{file, "test.log"},
+                                                                            {level, error},
+                                                                            {formatter, lager_default_formatter},
+                                                                            {formatter_config, [message, "\n"]}]}]),
+                application:set_env(lager, traces, [
+                                                    { % get default level of debug
+                                                     {lager_file_backend, "debug.log"}, [{module, ?MODULE}]
+                                                    },
+                                                    { % Handler                          Filters              Level
+                                                     {lager_file_backend, "events.log"}, [{module, ?MODULE}], notice
+                                                    }
+                                                   ]
+                                   ),
+                application:set_env(lager, async_threshold, undefined),
+                lager:start()
+        end,
+        fun(_) ->
+                catch ets:delete(lager_config),
+                application:unset_env(lager, traces),
+                application:stop(lager),
+                  
+                file:delete("events.log"),
+                file:delete("test.log"),
+                file:delete("debug.log"),
+                error_logger:tty(true)
+        end,
+        [
+            {"a trace using file backend set up in configuration should work",
+                fun() ->
+                        lager:error("trace test error message"),
+                        lager:info("info message"),
+                        %% not eligible for trace
+                        lager:log(error, self(), "Not trace test message"),
+                        {ok, BinInfo} = file:read_file("events.log"),
+                        ?assertMatch([_, _, "[error]", _, "trace test error message\n"],
+                                     re:split(BinInfo, " ", [{return, list}, {parts, 5}])),
+                        ?assert(filelib:is_regular("test.log")),
+                        {ok, BinInfo2} = file:read_file("test.log"),
+                        ?assertMatch(["trace test error message", "Not trace test message\n"],
+                                     re:split(BinInfo2, "\n", [{return, list}, {parts, 2}])),
+                        ?assert(filelib:is_regular("debug.log")),
+                        %% XXX Aughhhh, wish I could force this to flush somehow...
+                        timer:sleep(1000),
+                        {ok, BinInfo3} = file:read_file("debug.log"),
+                        ?assertEqual(2, length(re:split(BinInfo3, "\n", [{return, list}, trim])))
+                end
+            }
+        ]
+    }.
+
 formatting_test_() ->
     {foreach,
         fun() ->

test/lager_test_backend.erl

@@ -794,10 +794,12 @@ setup() ->
     application:load(lager),
     application:set_env(lager, handlers, [{?MODULE, info}]),
     application:set_env(lager, error_logger_redirect, false),
+    application:unset_env(lager, traces),
     lager:start(),
     gen_event:call(lager_event, ?MODULE, flush).
 
 cleanup(_) ->
+    catch ets:delete(lager_config), %% kill the ets config table with fire
     application:stop(lager),
     application:stop(goldrush),
     error_logger:tty(true).