Merge pull request #409 from erlang-lager/console_stderror

Enable sending console output to standard error

README.md

@@ -28,6 +28,29 @@ Features
 * Optional load shedding by setting a high water mark to kill (and reinstall)
   a sink after a configurable cool down timer
 
+Contributing
+------------
+We welcome contributions from the community. We are always excited to get ideas
+for improving lager.
+
+If you are looking for an idea to help out, please take a look at our open
+issues - a number of them are tagged with [Help Wanted](https://github.com/erlang-lager/lager/issues?q=is%3Aopen+is%3Aissue+label%3A%22Help+Wanted%22)
+and [Easy](https://github.com/erlang-lager/lager/issues?q=is%3Aopen+is%3Aissue+label%3AEasy) - some
+of them are tagged as both! We are happy to mentor people get started with any
+of these issues, and they don't need prior discussion.
+
+That being said, before you send large changes please open an issue first to
+discuss the change you'd like to make along with an idea of your proposal to
+implement that change.
+
+### PR guidelines ###
+
+* Large changes without prior discussion are likely to be rejected.
+* Changes without test cases are likely to be rejected.
+* Please use the style of the existing codebase when submitting PRs.
+
+We review PRs and issues at least once a month as described below.
+
 OTP Support Policy
 ------------------
 The lager maintainers intend to support the past three OTP releases from
@@ -42,9 +65,9 @@ or the 2.x branch.
 
 Monthly triage cadence
 ----------------------
-We have (at least) monthly issue and PR triage for lager in the #lager room on the 
+We have (at least) monthly issue and PR triage for lager in the #lager room on the
 [freenode](https://freenode.net) IRC network every third Thursday at 2 pm US/Pacific,
-9 pm UTC. You are welcome to join us there to ask questions about lager or 
+10 pm UTC. You are welcome to join us there to ask questions about lager or
 participate in the triage.
 
 Usage
@@ -103,7 +126,7 @@ your app.config):
 {lager, [
   {log_root, "/var/log/hello"},
   {handlers, [
-    {lager_console_backend, info},
+    {lager_console_backend, [{level, info}],
     {lager_file_backend, [{file, "error.log"}, {level, error}]},
     {lager_file_backend, [{file, "console.log"}, {level, info}]}
   ]}
@@ -168,7 +191,7 @@ will be applied on that sink.
 
           %% Default handlers for lager/lager_event
           {handlers, [
-                      {lager_console_backend, info},
+                      {lager_console_backend, [{level, info}]},
                       {lager_file_backend, [{file, "error.log"}, {level, error}]},
                       {lager_file_backend, [{file, "console.log"}, {level, info}]}
                      ]},
@@ -202,7 +225,8 @@ for the backend:
 ```erlang
 {lager, [
   {handlers, [
-    {lager_console_backend, [info, {lager_default_formatter, [time," [",severity,"] ", message, "\n"]}]},
+    {lager_console_backend, [{level, info}, {formatter, lager_default_formatter},
+      {formatter_config, [time," [",severity,"] ", message, "\n"]}]},
     {lager_file_backend, [{file, "error.log"}, {level, error}, {formatter, lager_default_formatter},
       {formatter_config, [date, " ", time," [",severity,"] ",pid, " ", message, "\n"]}]},
     {lager_file_backend, [{file, "console.log"}, {level, info}]}
@@ -528,7 +552,8 @@ The output will be colored from the first occurrence of the atom color
 in the formatting configuration. For example:
 
 ```erlang
-{lager_console_backend, [info, {lager_default_formatter, [time, color, " [",severity,"] ", message, "\e[0m\r\n"]}]}
+{lager_console_backend, [{level, info}, {formatter, lager_default_formatter},
+  {formatter_config, [time, color, " [",severity,"] ", message, "\e[0m\r\n"]}]]}
 ```
 
 This will make the entire log message, except time, colored. The
@@ -815,6 +840,14 @@ Example Usage:
 
 3.x Changelog
 -------------
+3.4.2 - 26 April 2017
+
+    * Docs: Document how to make lager use UTC timestamps (#405)
+    * Docs: Add a note about our triage cadence.
+    * Docs: Update lager_syslog URL
+    * Docs: Document placeholders for error_logger integration (#404)
+    * Feature: Add hex.pm metadata and full rebar3 support.
+
 3.4.1 - 28 March 2017
 
     * Docs: Added documentation around using lager in the context of elixir applications (#398)

src/lager_app.erl

@@ -40,7 +40,7 @@
 -define(FILENAMES, '__lager_file_backend_filenames').
 -define(THROTTLE, lager_backend_throttle).
 -define(DEFAULT_HANDLER_CONF,
-        [{lager_console_backend, info},
+        [{lager_console_backend, [{level, info}]},
          {lager_file_backend,
           [{file, "log/error.log"}, {level, error},
            {size, 10485760}, {date, "$D0"}, {count, 5}]

src/lager_console_backend.erl

@@ -14,8 +14,17 @@
 %% specific language governing permissions and limitations
 %% under the License.
 
-%% @doc Console backend for lager. Configured with a single option, the loglevel
-%% desired.
+%% @doc Console backend for lager.
+%% Configuration is a proplist with the following keys:
+%% <ul>
+%%    <li>`level' - log level to use</li>
+%%    <li>`use_stderr' - either `true' or `false', defaults to false. If set to true,
+%%                       use standard error to output console log messages</li>
+%%    <li>`formatter' - the module to use when formatting log messages. Defaults to
+%%                      `lager_default_formatter'</li>
+%%    <li>`formatter_config' - the format configuration string. Defaults to
+%%                             `time [ severity ] message'</li>
+%% </ul>
 
 -module(lager_console_backend).
 
@@ -25,6 +34,7 @@
         code_change/3]).
 
 -record(state, {level :: {'mask', integer()},
+                out = user :: user | standard_error,
                 formatter :: atom(),
                 format_config :: any(),
                 colors=[] :: list()}).
@@ -34,17 +44,33 @@
 -compile([{parse_transform, lager_transform}]).
 -endif.
 
+
 -include("lager.hrl").
+
 -define(TERSE_FORMAT,[time, " ", color, "[", severity,"] ", message]).
+-define(DEFAULT_FORMAT_CONFIG, ?TERSE_FORMAT ++ [eol()]).
+-define(FORMAT_CONFIG_OFF, [{eol, eol()}]).
+
+-ifdef(TEST).
+-define(DEPRECATED(_Msg), ok).
+-else.
+-define(DEPRECATED(Msg),
+        io:format(user, "WARNING: This is a deprecated console configuration. Please use \"~w\" instead.~n", [Msg])).
+-endif.
 
 %% @private
 init([Level]) when is_atom(Level) ->
-    init(Level);
-init([Level, true]) -> % for backwards compatibility
-    init([Level,{lager_default_formatter,[{eol, eol()}]}]);
-init([Level,false]) -> % for backwards compatibility
-    init([Level,{lager_default_formatter,?TERSE_FORMAT ++ [eol()]}]);
-init([Level,{Formatter,FormatterConfig}]) when is_atom(Formatter) ->
+    ?DEPRECATED([{level, Level}]),
+    init([{level, Level}]);
+init([Level, true]) when is_atom(Level) -> % for backwards compatibility
+    ?DEPRECATED([{level, Level}, {formatter_config, [{eol, "\\r\\n\\"}]}]),
+    init([{level, Level}, {formatter_config, ?FORMAT_CONFIG_OFF}]);
+init([Level, false]) when is_atom(Level) -> % for backwards compatibility
+    ?DEPRECATED([{level, Level}]),
+    init([{level, Level}]);
+
+init(Options) when is_list(Options) ->
+    true = validate_options(Options),
     Colors = case application:get_env(lager, colored) of
         {ok, true} ->
             {ok, LagerColors} = application:get_env(lager, colors),
@@ -52,6 +78,7 @@ init([Level,{Formatter,FormatterConfig}]) when is_atom(Formatter) ->
         _ -> []
     end,
 
+    Level = get_option(level, Options, undefined),
     try {is_new_style_console_available(), lager_util:config_to_mask(Level)} of
         {false, _} ->
             Msg = "Lager's console backend is incompatible with the 'old' shell, not enabling it",
@@ -65,23 +92,62 @@ init([Level,{Formatter,FormatterConfig}]) when is_atom(Formatter) ->
             io:format("WARNING: " ++ Msg ++ "~n"),
             ?INT_LOG(warning, Msg, []),
             {error, {fatal, old_shell}};
-        {true, Levels} ->
-            {ok, #state{level=Levels,
+        {true, L} ->
+            [UseErr, Formatter, Config] = [ get_option(K, Options, Default) || {K, Default} <- [
+                                                                                   {use_stderr, false},
+                                                                                   {formatter, lager_default_formatter},
+                                                                                   {formatter_config, ?DEFAULT_FORMAT_CONFIG}
+                                                                                               ]
+                                          ],
+            Out = case UseErr of
+                     false -> user;
+                     true -> standard_error
+                  end,
+            {ok, #state{level=L,
+                    out=Out,
                     formatter=Formatter,
-                    format_config=FormatterConfig,
+                    format_config=Config,
                     colors=Colors}}
     catch
         _:_ ->
             {error, {fatal, bad_log_level}}
     end;
-init(Level) ->
-    init([Level,{lager_default_formatter,?TERSE_FORMAT ++ [eol()]}]).
+init(Level) when is_atom(Level) ->
+    ?DEPRECATED([{level, Level}]),
+    init([{level, Level}]);
+init(Other) ->
+    {error, {fatal, {bad_console_config, Other}}}.
+
+validate_options([]) -> true;
+validate_options([{level, L}|T]) when is_atom(L) ->
+    case lists:member(L, ?LEVELS) of
+        false ->
+            throw({error, {fatal, {bad_level, L}}});
+        true ->
+            validate_options(T)
+    end;
+validate_options([{use_stderr, true}|T]) ->
+    validate_options(T);
+validate_options([{use_stderr, false}|T]) ->
+    validate_options(T);
+validate_options([{formatter, M}|T]) when is_atom(M) ->
+    validate_options(T);
+validate_options([{formatter_config, C}|T]) when is_list(C) ->
+    validate_options(T);
+validate_options([H|_]) ->
+    throw({error, {fatal, {bad_console_config, H}}}).
+
+get_option(K, Options, Default) ->
+   case lists:keyfind(K, 1, Options) of
+       {K, V} -> V;
+       false -> Default
+   end.
 
 %% @private
 handle_call(get_loglevel, #state{level=Level} = State) ->
     {ok, Level, State};
 handle_call({set_loglevel, Level}, State) ->
-   try lager_util:config_to_mask(Level) of
+    try lager_util:config_to_mask(Level) of
         Levels ->
             {ok, ok, State#state{level=Levels}}
     catch
@@ -93,10 +159,10 @@ handle_call(_Request, State) ->
 
 %% @private
 handle_event({log, Message},
-    #state{level=L,formatter=Formatter,format_config=FormatConfig,colors=Colors} = State) ->
+    #state{level=L,out=Out,formatter=Formatter,format_config=FormatConfig,colors=Colors} = State) ->
     case lager_util:is_loggable(Message, L, ?MODULE) of
         true ->
-            io:put_chars(user, Formatter:format(Message,FormatConfig,Colors)),
+            io:put_chars(Out, Formatter:format(Message,FormatConfig,Colors)),
             {ok, State};
         false ->
             {ok, State}
@@ -145,6 +211,20 @@ is_new_style_console_available() ->
 -endif.
 
 -ifdef(TEST).
+console_config_validation_test_() ->
+    Good = [{level, info}, {use_stderr, true}],
+    Bad1 = [{level, foo}, {use_stderr, flase}],
+    Bad2 = [{level, info}, {use_stderr, flase}],
+    AllGood = [{level, info}, {formatter, my_formatter},
+               {formatter_config, ["blort", "garbage"]},
+               {use_stderr, false}],
+    [
+     ?_assertEqual(true, validate_options(Good)),
+     ?_assertThrow({error, {fatal, {bad_level, foo}}}, validate_options(Bad1)),
+     ?_assertThrow({error, {fatal, {bad_console_config, {use_stderr, flase}}}}, validate_options(Bad2)),
+     ?_assertEqual(true, validate_options(AllGood))
+    ].
+
 console_log_test_() ->
     %% tiny recursive fun that pretends to be a group leader
     F = fun(Self) ->
@@ -186,7 +266,7 @@ console_log_test_() ->
                         unregister(user),
                         register(user, Pid),
                         erlang:group_leader(Pid, whereis(lager_event)),
-                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        gen_event:add_handler(lager_event, lager_console_backend, [{level, info}]),
                         lager_config:set({lager_event, loglevel}, {element(2, lager_util:config_to_mask(info)), []}),
                         lager:log(info, self(), "Test message"),
                         receive
@@ -227,7 +307,7 @@ console_log_test_() ->
                         register(user, Pid),
                         erlang:group_leader(Pid, whereis(lager_event)),
                         gen_event:add_handler(lager_event, lager_console_backend,
-                          [info, {lager_default_formatter, [date,"#",time,"#",severity,"#",node,"#",pid,"#",
+                          [{level, info}, {formatter, lager_default_formatter}, {formatter_config, [date,"#",time,"#",severity,"#",node,"#",pid,"#",
                                                             module,"#",function,"#",file,"#",line,"#",message,"\r\n"]}]),
                         lager_config:set({lager_event, loglevel}, {?INFO, []}),
                         lager:info("Test message"),
@@ -250,7 +330,7 @@ console_log_test_() ->
                         Pid = spawn(F(self())),
                         unregister(user),
                         register(user, Pid),
-                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        gen_event:add_handler(lager_event, lager_console_backend, [{level, info}]),
                         erlang:group_leader(Pid, whereis(lager_event)),
                         lager_config:set({lager_event, loglevel}, {element(2, lager_util:config_to_mask(info)), []}),
                         lager:debug("Test message"),
@@ -280,7 +360,7 @@ console_log_test_() ->
                         Pid = spawn(F(self())),
                         unregister(user),
                         register(user, Pid),
-                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        gen_event:add_handler(lager_event, lager_console_backend, [{level, info}]),
                         lager_config:set({lager_event, loglevel}, {element(2, lager_util:config_to_mask(info)), []}),
                         erlang:group_leader(Pid, whereis(lager_event)),
                         lager:debug("Test message"),
@@ -319,7 +399,7 @@ console_log_test_() ->
                         Pid = spawn(F(self())),
                         unregister(user),
                         register(user, Pid),
-                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        gen_event:add_handler(lager_event, lager_console_backend, [{level, info}]),
                         lager_config:set({lager_event, loglevel}, {element(2, lager_util:config_to_mask(info)), []}),
                         lager:set_loglevel(lager_console_backend, '!=info'),
                         erlang:group_leader(Pid, whereis(lager_event)),
@@ -350,7 +430,7 @@ console_log_test_() ->
                         Pid = spawn(F(self())),
                         unregister(user),
                         register(user, Pid),
-                        gen_event:add_handler(lager_event, lager_console_backend, info),
+                        gen_event:add_handler(lager_event, lager_console_backend, [{level, info}]),
                         lager_config:set({lager_event, loglevel}, {element(2, lager_util:config_to_mask(info)), []}),
                         lager:set_loglevel(lager_console_backend, '=debug'),
                         erlang:group_leader(Pid, whereis(lager_event)),
@@ -384,7 +464,7 @@ set_loglevel_test_() ->
         fun() ->
                 error_logger:tty(false),
                 application:load(lager),
-                application:set_env(lager, handlers, [{lager_console_backend, info}]),
+                application:set_env(lager, handlers, [{lager_console_backend, [{level, info}]}]),
                 application:set_env(lager, error_logger_redirect, false),
                 lager:start()
         end,