Changed the messages sent to the backends to include metadata and sep…

…arated formatting from the backend. Added documentation, fixed tests, and removed some unused code.

.gitignore

@@ -4,3 +4,4 @@ ebin
 doc
 *.swp
 erl_crash.dump
+.project

README.org

@@ -64,6 +64,45 @@
   The available configuration options for each backend are listed in their
   module's documentation.
 
+* Custom Formatting
+  All loggers have a default formatting that can be overriden.  A formatter is any module that
+  exports format(#lager_log_message{},Config#any()).  It is specified as part of the configuration
+  for the backend:
+
+#+BEGIN_EXAMPLE
+  {lager, [
+    {handlers, [
+      {lager_console_backend, [info, {lager_default_formatter, [time," [",severity,"] ", message, "\n"]}},
+      {lager_file_backend, [
+        [{"error.log", error, 10485760, "$D0", 5,{lager_default_formatter,[date, " ", time," [",severity,"] ",pid, " ", message, "\n"]}],
+        {"console.log", info, 10485760, "$D0", 5}
+      ]}
+    ]}
+  ]}.
+#+END_EXAMPLE  
+
+  Included is lager_default_formatter.  This 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.  
+  The metadata properties date,time, message, and severity will always exist.  
+  The properties pid, file, line, module, and function will always exist if the parser transform is used.
+
+#+BEGIN_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.
+    [date, " ", time," [",severity,"] ",pid, " ", message, "\n"] -> default formatting if none is provided
+#+END_EXAMPLE  
+
+  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 nested or refer to other properties.
+
+#+BEGIN_EXAMPLE
+    [{pid,"Unknown Pid"}] -> "<?.?.?>" if pid is in the metadata, "Unknown Pid" if not.
+    [{server,[$(,{pid,"Unknown Server"},$)]}}] -> user provided server metadata, otherwise "(<?.?.?>)", otherwise "(Unknown Server)"
+#+END_EXAMPLE  
+
 * Error logger integration
   Lager is also supplied with a error_logger handler module that translates
   traditional erlang error messages into a friendlier format and sends them into

include/lager.hrl

@@ -14,6 +14,15 @@
 %% specific language governing permissions and limitations
 %% under the License.
 
+-record(lager_log_message,{
+						   destinations,
+						   metadata,
+						   severity_as_int,
+						   timestamp,
+						   message
+						   }).
+
+
 -define(LEVELS,
     [debug, info, notice, warning, error, critical, alert, emergency, none]).
 
@@ -55,10 +64,13 @@
     lager_util:level_to_num(Level) =< element(1, lager_mochiglobal:get(loglevel, {?LOG_NONE, []}))).
 
 -define(NOTIFY(Level, Pid, Format, Args),
-    gen_event:notify(lager_event, {log, lager_util:level_to_num(Level),
-            lager_util:format_time(), [io_lib:format("[~p] ", [Level]),
-                io_lib:format("~p ", [Pid]), io_lib:format(Format, Args)]})).
-
+    gen_event:notify(lager_event,#lager_log_message{destinations=[],
+													message=io_lib:format(Format,Args),
+													metadata=[{pid,Pid},{line,?LINE},{file,?FILE},{module,?MODULE}],
+													timestamp=lager_util:format_time(),
+													severity_as_int=lager_util:level_to_num(Level)
+													})). 
+
 %% FOR INTERNAL USE ONLY
 %% internal non-blocking logging call
 %% there's some special handing for when we try to log (usually errors) while
@@ -93,3 +105,4 @@
             end
     end)).
 -endif.
+

src/lager.erl

@@ -19,15 +19,16 @@
 -module(lager).
 
 -include("lager.hrl").
+-include_lib("eunit/include/eunit.hrl").
 
 %% API
 -export([start/0,
-        log/8, log_dest/9, log/3, log/4,
+        log/3, log/4,
         trace_file/2, trace_file/3, trace_console/1, trace_console/2,
         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/8]).
+        safe_format/3, safe_format_chop/3,dispatch_log/4]).
 
 -type log_level() :: debug | info | notice | warning | error | critical | alert | emergency.
 -type log_level_number() :: 0..7.
@@ -52,69 +53,48 @@ start_ok(App, {error, Reason}) ->
     erlang:error({app_start_failed, App, Reason}).
 
 
--spec dispatch_log(log_level(), atom(), atom(), pos_integer(), pid(), list(), string(), list()) ->
-    ok | {error, lager_not_running}.
-
-dispatch_log(Severity, Module, Function, Line, Pid, Traces, Format, Args) ->
-    {LevelThreshold,TraceFilters} = lager_mochiglobal:get(loglevel,{?LOG_NONE,[]}),
-    Result=
-    case LevelThreshold >= lager_util:level_to_num(Severity) of
-        true -> lager:log(Severity,Module,Function,Line,Pid,
-                lager_util:maybe_utc(lager_util:localtime_ms()),
-                Format,Args);
-        _ -> ok
-    end,
-    case TraceFilters of
-        [] -> Result;
-        Match when is_list(Match) ->
-            lager:log_dest(Severity,Module,Function,Line,Pid,
-                lager_util:maybe_utc(lager_util:localtime_ms()),
-                lager_util:check_traces(Traces,
-                    lager_util:level_to_num(Severity),
-                    TraceFilters,
-                    []),
-                Format,Args);
-        _ -> ok
-    end.
-
-%% @private
--spec log(log_level(), atom(), atom(), pos_integer(), pid(), tuple(), string(), list()) ->
-    ok | {error, lager_not_running}.
-log(Level, Module, Function, Line, Pid, Time, Format, Args) ->
-    Timestamp = lager_util:format_time(Time),
-    Msg = [["[", atom_to_list(Level), "] "],
-           io_lib:format("~p@~p:~p:~p ", [Pid, Module, Function, Line]),
-           safe_format_chop(Format, Args, 4096)],
-    safe_notify({log, lager_util:level_to_num(Level), Timestamp, Msg}).
-
-%% @private
--spec log_dest(log_level(), atom(), atom(), pos_integer(), pid(), tuple(), list(), string(), list()) ->
-    ok | {error, lager_not_running}.
-log_dest(_Level, _Module, _Function, _Line, _Pid, _Time, [], _Format, _Args) ->
-    ok;
-log_dest(Level, Module, Function, Line, Pid, Time, Dest, Format, Args) ->
-    Timestamp = lager_util:format_time(Time),
-    Msg = [["[", atom_to_list(Level), "] "],
-           io_lib:format("~p@~p:~p:~p ", [Pid, Module, Function, Line]),
-           safe_format_chop(Format, Args, 4096)],
-    safe_notify({log, Dest, lager_util:level_to_num(Level), Timestamp, Msg}).
-
+-spec dispatch_log(log_level(), list(), string(), list() | none) ->  ok | {error, lager_not_running}.
+dispatch_log(Severity, Metadata, Format, Args) when is_atom(Severity)->
+	case whereis(lager_event) of
+		undefined ->
+			%% lager isn't running
+			{error, lager_not_running};
+		Pid ->
+
+			{LevelThreshold,TraceFilters} = lager_mochiglobal:get(loglevel,{?LOG_NONE,[]}),
+			SeverityAsInt=lager_util:level_to_num(Severity),
+			Destinations = case TraceFilters of 
+							   [] -> [];
+							   _ -> 
+								   lager_util:check_traces(Metadata,SeverityAsInt,TraceFilters,[])
+						   end,
+			case (LevelThreshold >= SeverityAsInt orelse Destinations =/= []) of
+				true -> 
+					Timestamp = lager_util:format_time(),
+					Msg=case Args of 
+							A when is_list(A) ->safe_format_chop(Format,Args,4096);
+							_ -> Format
+						end,
+					gen_event:sync_notify(Pid, #lager_log_message{destinations=Destinations, 
+																  metadata=Metadata, 
+																  severity_as_int=SeverityAsInt, 
+																  timestamp=Timestamp, 
+																  message=Msg});
+				_ -> 
+					ok
+			end
+	end.
+
 
 %% @doc Manually log a message into lager without using the parse transform.
 -spec log(log_level(), pid(), list()) -> ok | {error, lager_not_running}.
 log(Level, Pid, Message) ->
-    Timestamp = lager_util:format_time(),
-    Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]),
-           safe_format_chop("~s", [Message], 4096)],
-    safe_notify({log, lager_util:level_to_num(Level), Timestamp, Msg}).
+	dispatch_log(Level, [{pid,Pid}], Message,none).
 
 %% @doc Manually log a message into lager without using the parse transform.
 -spec log(log_level(), pid(), string(), list()) -> ok | {error, lager_not_running}.
 log(Level, Pid, Format, Args) ->
-    Timestamp = lager_util:format_time(),
-    Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]),
-           safe_format_chop(Format, Args, 4096)],
-    safe_notify({log, lager_util:level_to_num(Level), Timestamp, Msg}).
+	dispatch_log(Level, [{pid,Pid}], Format, Args).
 
 trace_file(File, Filter) ->
     trace_file(File, Filter, debug).
@@ -265,15 +245,6 @@ minimum_loglevel([]) ->
 minimum_loglevel(Levels) ->
     erlang:hd(lists:reverse(lists:sort(Levels))).
 
-safe_notify(Event) ->
-    case whereis(lager_event) of
-        undefined ->
-            %% lager isn't running
-            {error, lager_not_running};
-        Pid ->
-            gen_event:sync_notify(Pid, Event)
-    end.
-
 %% @doc Print the format string `Fmt' with `Args' safely with a size
 %% limit of `Limit'. If the format string is invalid, or not enough
 %% arguments are supplied 'FORMAT ERROR' is printed with the offending

src/lager_app.erl

@@ -22,7 +22,9 @@
 
 -behaviour(application).
 -include("lager.hrl").
-
+-ifdef(TEST).
+-include_lib("eunit/include/eunit.hrl").
+-endif.
 -export([start/0,
          start/2,
          stop/1]).
@@ -42,7 +44,7 @@ start(_StartType, _StartArgs) ->
         {ok, Val} ->
             Val
     end,
-
+	
     [supervisor:start_child(lager_handler_watcher_sup, [lager_event, Module, Config]) ||
         {Module, Config} <- expand_handlers(Handlers)],
 
@@ -71,7 +73,43 @@ stop(Handlers) ->
 expand_handlers([]) ->
     [];
 expand_handlers([{lager_file_backend, Configs}|T]) ->
-    [{{lager_file_backend, element(1, Config)}, Config} || Config <- Configs] ++
+    [ to_config(Config) || Config <- Configs] ++
       expand_handlers(T);
 expand_handlers([H|T]) ->
     [H | expand_handlers(T)].
+
+to_config({Name,Severity}) ->
+	{{lager_file_backend, Name}, {Name, Severity}};
+to_config({Name,_Severity,_Size,_Rotation,_Count}=Config) ->
+	{{lager_file_backend, Name}, Config};
+to_config({Name,Severity,Size,Rotation,Count,Format}) ->
+	{{lager_file_backend, Name}, {Name,Severity,Size,Rotation,Count},Format}.
+
+
+
+-ifdef(TEST).
+application_config_mangling_test_() ->
+	[{"Explode the file backend handlers",
+	  ?_assertMatch( 
+	   [{lager_console_backend, info},
+		{{lager_file_backend,"error.log"},{"error.log",error,10485760, "$D0",5}},
+		{{lager_file_backend,"console.log"},{"console.log",info,10485760, "$D0",5}}
+	   ]	  
+	  ,expand_handlers([{lager_console_backend, info},
+		{lager_file_backend, [
+							  {"error.log", error, 10485760, "$D0", 5},
+							  {"console.log", info, 10485760, "$D0", 5}
+							 ]}]
+					  ))}
+	 ,{"Explode with formatter info",
+	   ?_assertMatch(
+	   [{{lager_file_backend,"test.log"},  {"test.log", debug, 10485760, "$D0", 5},{lager_default_formatter,["[",severity,"] ", message, "\n"]}},
+		{{lager_file_backend,"test2.log"}, {"test2.log",debug, 10485760, "$D0", 5},{lager_default_formatter,["2>[",severity,"] ", message, "\n"]}}]
+	   ,expand_handlers([{lager_file_backend, [
+										   {"test.log", debug, 10485760, "$D0", 5,{lager_default_formatter,["[",severity,"] ", message, "\n"]}},
+										   {"test2.log",debug, 10485760, "$D0", 5,{lager_default_formatter,["2>[",severity,"] ",message, "\n"]}}
+											  ]
+					   }])
+	   )
+	  }].
+-endif.

src/lager_backend_utils.erl

@@ -0,0 +1,41 @@
+%% Author: jason
+%% Created: Jan 16, 2012
+%% Description: TODO: Add description to lager_backend_utils
+-module(lager_backend_utils).
+
+%%
+%% Include files
+%%
+-include_lib("lager/include/lager.hrl").
+-ifdef(TEST).
+-include_lib("eunit/include/eunit.hrl").
+-endif.
+
+%%
+%% Exported Functions
+%%
+-export([is_loggable/3]).
+
+%%
+%% API Functions
+%%
+
+
+-spec is_loggable(#lager_log_message{},integer(),term()) -> boolean().
+is_loggable(#lager_log_message{severity_as_int=Severity,destinations=Destinations},SeverityThreshold,MyName)->
+%%  	?debugFmt("is_loggable: Severity=~p, Threshold=~p, Destinations=~p, MyName=~p", [Severity,SeverityThreshold,Destinations,MyName]),
+	Severity =< SeverityThreshold orelse lists:member(MyName, Destinations).
+
+
+-ifdef(TEST).
+
+is_loggable_test_() ->
+	[
+	 {"Loggable by severity only", ?_assert(is_loggable(#lager_log_message{severity_as_int=1,destinations=[]},2,me))},
+	 {"Not loggable by severity only", ?_assertNot(is_loggable(#lager_log_message{severity_as_int=2,destinations=[]},1,me))},
+	 {"Loggable by severity with destination", ?_assert(is_loggable(#lager_log_message{severity_as_int=1,destinations=[you]},2,me))},
+	 {"Not loggable by severity with destination", ?_assertNot(is_loggable(#lager_log_message{severity_as_int=2,destinations=[you]},1,me))},
+	 {"Loggable by destination overriding severity", ?_assert(is_loggable(#lager_log_message{severity_as_int=2,destinations=[me]},1,me))}
+	].
+
+-endif.