Browse Source

Merge branch 'adt-syslog-comparison-flags'

pull/104/head
Andrew Thompson 12 years ago
parent
commit
0ed603bd58
7 changed files with 365 additions and 138 deletions
  1. +10
    -10
      include/lager.hrl
  2. +45
    -23
      src/lager.erl
  3. +1
    -1
      src/lager_config.erl
  4. +81
    -15
      src/lager_console_backend.erl
  5. +33
    -18
      src/lager_file_backend.erl
  6. +165
    -48
      src/lager_util.erl
  7. +30
    -23
      test/lager_test_backend.erl

+ 10
- 10
include/lager.hrl View File

@ -20,15 +20,15 @@
-define(LEVELS, -define(LEVELS,
[debug, info, notice, warning, error, critical, alert, emergency, none]). [debug, info, notice, warning, error, critical, alert, emergency, none]).
-define(DEBUG, 7).
-define(INFO, 6).
-define(NOTICE, 5).
-define(WARNING, 4).
-define(ERROR, 3).
-define(CRITICAL, 2).
-define(ALERT, 1).
-define(EMERGENCY, 0).
-define(LOG_NONE, -1).
-define(DEBUG, 128).
-define(INFO, 64).
-define(NOTICE, 32).
-define(WARNING, 16).
-define(ERROR, 8).
-define(CRITICAL, 4).
-define(ALERT, 2).
-define(EMERGENCY, 1).
-define(LOG_NONE, 0).
-define(LEVEL2NUM(Level), -define(LEVEL2NUM(Level),
case Level of case Level of
@ -55,7 +55,7 @@
end). end).
-define(SHOULD_LOG(Level), -define(SHOULD_LOG(Level),
lager_util:level_to_num(Level) =< element(1, lager_config:get(loglevel, {?LOG_NONE, []}))).
(lager_util:level_to_num(Level) band element(1, lager_config:get(loglevel, {?LOG_NONE, []}))) /= 0).
-define(NOTIFY(Level, Pid, Format, Args), -define(NOTIFY(Level, Pid, Format, Args),
gen_event:notify(lager_event, {log, lager_msg:new(io_lib:format(Format, Args), gen_event:notify(lager_event, {log, lager_msg:new(io_lib:format(Format, Args),

+ 45
- 23
src/lager.erl View File

@ -23,7 +23,7 @@
%% API %% API
-export([start/0, -export([start/0,
log/3, log/4, log/3, log/4,
trace_file/2, trace_file/3, trace_console/1, trace_console/2,
trace/2, trace/3, trace_file/2, trace_file/3, trace_console/1, trace_console/2,
clear_all_traces/0, stop_trace/1, status/0, clear_all_traces/0, stop_trace/1, status/0,
get_loglevel/1, set_loglevel/2, set_loglevel/3, get_loglevels/0, get_loglevel/1, set_loglevel/2, set_loglevel/3, get_loglevels/0,
minimum_loglevel/1, posix_error/1, minimum_loglevel/1, posix_error/1,
@ -61,21 +61,24 @@ dispatch_log(Severity, Metadata, Format, Args, Size) when is_atom(Severity)->
Pid -> Pid ->
{LevelThreshold,TraceFilters} = lager_config:get(loglevel,{?LOG_NONE,[]}), {LevelThreshold,TraceFilters} = lager_config:get(loglevel,{?LOG_NONE,[]}),
SeverityAsInt=lager_util:level_to_num(Severity), 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 ->
case (LevelThreshold band SeverityAsInt) /= 0 of
true ->
Destinations = case TraceFilters of
[] ->
[];
_ ->
lager_util:check_traces(Metadata,SeverityAsInt,TraceFilters,[])
end,
Timestamp = lager_util:format_time(), Timestamp = lager_util:format_time(),
Msg=case Args of
A when is_list(A) ->safe_format_chop(Format,Args,Size);
_ -> Format
Msg = case Args of
A when is_list(A) ->
safe_format_chop(Format,Args,Size);
_ ->
Format
end, end,
gen_event:sync_notify(Pid, {log, lager_msg:new(Msg, Timestamp, gen_event:sync_notify(Pid, {log, lager_msg:new(Msg, Timestamp,
Severity, Metadata, Destinations)}); Severity, Metadata, Destinations)});
_ ->
_ ->
ok ok
end end
end. end.
@ -107,7 +110,7 @@ trace_file(File, Filter, Level) ->
false -> false ->
%% install the handler %% install the handler
supervisor:start_child(lager_handler_watcher_sup, supervisor:start_child(lager_handler_watcher_sup,
[lager_event, {lager_file_backend, File}, {File, none}]);
[lager_event, {lager_file_backend, File}, {File, Level}]);
_ -> _ ->
{ok, exists} {ok, exists}
end, end,
@ -117,7 +120,8 @@ trace_file(File, Filter, Level) ->
{MinLevel, Traces} = lager_config:get(loglevel), {MinLevel, Traces} = lager_config:get(loglevel),
case lists:member(Trace, Traces) of case lists:member(Trace, Traces) of
false -> false ->
lager_config:set(loglevel, {MinLevel, [Trace|Traces]});
{_, {mask, TraceMask}, _} = Trace,
lager_config:set(loglevel, {MinLevel bor TraceMask, [Trace|Traces]});
_ -> _ ->
ok ok
end, end,
@ -133,13 +137,20 @@ trace_console(Filter) ->
trace_console(Filter, debug). trace_console(Filter, debug).
trace_console(Filter, Level) -> trace_console(Filter, Level) ->
Trace0 = {Filter, Level, lager_console_backend},
trace(lager_console_backend, Filter, Level).
trace(Backend, Filter) ->
trace(Backend, Filter, debug).
trace(Backend, Filter, Level) ->
Trace0 = {Filter, Level, Backend},
case lager_util:validate_trace(Trace0) of case lager_util:validate_trace(Trace0) of
{ok, Trace} -> {ok, Trace} ->
{MinLevel, Traces} = lager_config:get(loglevel), {MinLevel, Traces} = lager_config:get(loglevel),
case lists:member(Trace, Traces) of case lists:member(Trace, Traces) of
false -> false ->
lager_config:set(loglevel, {MinLevel, [Trace|Traces]});
{_, {mask, TraceMask}, _} = Trace,
lager_config:set(loglevel, {MinLevel bor TraceMask, [Trace|Traces]});
_ -> ok _ -> ok
end, end,
{ok, Trace}; {ok, Trace};
@ -148,8 +159,9 @@ trace_console(Filter, Level) ->
end. end.
stop_trace({_Filter, _Level, Target} = Trace) -> stop_trace({_Filter, _Level, Target} = Trace) ->
{MinLevel, Traces} = lager_config:get(loglevel),
{_, Traces} = lager_config:get(loglevel),
NewTraces = lists:delete(Trace, Traces), NewTraces = lists:delete(Trace, Traces),
MinLevel = minimum_loglevel(get_loglevels() ++ get_trace_levels(NewTraces)),
lager_config:set(loglevel, {MinLevel, NewTraces}), lager_config:set(loglevel, {MinLevel, NewTraces}),
case get_loglevel(Target) of case get_loglevel(Target) of
none -> none ->
@ -166,7 +178,7 @@ stop_trace({_Filter, _Level, Target} = Trace) ->
ok. ok.
clear_all_traces() -> clear_all_traces() ->
{MinLevel, _Traces} = lager_config:get(loglevel),
MinLevel = minimum_loglevel(get_loglevels()),
lager_config:set(loglevel, {MinLevel, []}), lager_config:set(loglevel, {MinLevel, []}),
lists:foreach(fun(Handler) -> lists:foreach(fun(Handler) ->
case get_loglevel(Handler) of case get_loglevel(Handler) of
@ -202,8 +214,8 @@ status() ->
set_loglevel(Handler, Level) when is_atom(Level) -> set_loglevel(Handler, Level) when is_atom(Level) ->
Reply = gen_event:call(lager_event, Handler, {set_loglevel, Level}, infinity), Reply = gen_event:call(lager_event, Handler, {set_loglevel, Level}, infinity),
%% recalculate min log level %% recalculate min log level
MinLog = minimum_loglevel(get_loglevels()),
{_, Traces} = lager_config:get(loglevel), {_, Traces} = lager_config:get(loglevel),
MinLog = minimum_loglevel(get_loglevels() ++ get_trace_levels(Traces)),
lager_config:set(loglevel, {MinLog, Traces}), lager_config:set(loglevel, {MinLog, Traces}),
Reply. Reply.
@ -212,8 +224,8 @@ set_loglevel(Handler, Level) when is_atom(Level) ->
set_loglevel(Handler, Ident, Level) when is_atom(Level) -> set_loglevel(Handler, Ident, Level) when is_atom(Level) ->
Reply = gen_event:call(lager_event, {Handler, Ident}, {set_loglevel, Level}, infinity), Reply = gen_event:call(lager_event, {Handler, Ident}, {set_loglevel, Level}, infinity),
%% recalculate min log level %% recalculate min log level
MinLog = minimum_loglevel(get_loglevels()),
{_, Traces} = lager_config:get(loglevel), {_, Traces} = lager_config:get(loglevel),
MinLog = minimum_loglevel(get_loglevels() ++ get_trace_levels(Traces)),
lager_config:set(loglevel, {MinLog, Traces}), lager_config:set(loglevel, {MinLog, Traces}),
Reply. Reply.
@ -221,6 +233,8 @@ set_loglevel(Handler, Ident, Level) when is_atom(Level) ->
%% has multiple identifiers, the lowest is returned %% has multiple identifiers, the lowest is returned
get_loglevel(Handler) -> get_loglevel(Handler) ->
case gen_event:call(lager_event, Handler, get_loglevel, infinity) of case gen_event:call(lager_event, Handler, get_loglevel, infinity) of
{mask, Mask} ->
erlang:hd(lager_util:mask_to_levels(Mask));
X when is_integer(X) -> X when is_integer(X) ->
lager_util:num_to_level(X); lager_util:num_to_level(X);
Y -> Y Y -> Y
@ -242,10 +256,18 @@ get_loglevels() ->
Handler <- gen_event:which_handlers(lager_event)]. Handler <- gen_event:which_handlers(lager_event)].
%% @private %% @private
minimum_loglevel([]) ->
-1; %% lower than any log level, logging off
minimum_loglevel(Levels) -> minimum_loglevel(Levels) ->
erlang:hd(lists:reverse(lists:sort(Levels))).
lists:foldl(fun({mask, Mask}, Acc) ->
Mask bor Acc;
(Level, Acc) when is_integer(Level) ->
{mask, Mask} = lager_util:config_to_mask(lager_util:num_to_level(Level)),
Mask bor Acc;
(_, Acc) ->
Acc
end, 0, Levels).
get_trace_levels(Traces) ->
lists:map(fun({_, Level, _}) -> Level end, Traces).
%% @doc Print the format string `Fmt' with `Args' safely with a size %% @doc Print the format string `Fmt' with `Args' safely with a size
%% limit of `Limit'. If the format string is invalid, or not enough %% limit of `Limit'. If the format string is invalid, or not enough

+ 1
- 1
src/lager_config.erl View File

@ -36,7 +36,7 @@ new() ->
%% use insert_new here so that if we're in an appup we don't mess anything up %% use insert_new here so that if we're in an appup we don't mess anything up
%% %%
%% until lager is completely started, allow all messages to go through %% until lager is completely started, allow all messages to go through
ets:insert_new(?TBL, {loglevel, {?DEBUG, []}}),
ets:insert_new(?TBL, {loglevel, {element(2, lager_util:config_to_mask(debug)), []}}),
ok. ok.

+ 81
- 15
src/lager_console_backend.erl View File

@ -43,12 +43,13 @@ init([Level, true]) -> % for backwards compatibility
init([Level,false]) -> % for backwards compatibility init([Level,false]) -> % for backwards compatibility
init([Level,{lager_default_formatter,?TERSE_FORMAT}]); init([Level,{lager_default_formatter,?TERSE_FORMAT}]);
init([Level,{Formatter,FormatterConfig}]) when is_atom(Level), is_atom(Formatter)-> init([Level,{Formatter,FormatterConfig}]) when is_atom(Level), is_atom(Formatter)->
case lists:member(Level, ?LEVELS) of
true ->
{ok, #state{level=lager_util:level_to_num(Levelspan>),
try lager_util:config_to_mask(Level) of
Levels ->
{ok, #state{level=Levels,
formatter=Formatter, formatter=Formatter,
format_config=FormatterConfig}};
_ ->
format_config=FormatterConfig}}
catch
_:_ ->
{error, bad_log_level} {error, bad_log_level}
end. end.
@ -57,10 +58,11 @@ init([Level,{Formatter,FormatterConfig}]) when is_atom(Level), is_atom(Formatte
handle_call(get_loglevel, #state{level=Level} = State) -> handle_call(get_loglevel, #state{level=Level} = State) ->
{ok, Level, State}; {ok, Level, State};
handle_call({set_loglevel, Level}, State) -> handle_call({set_loglevel, Level}, State) ->
case lists:member(Level, ?LEVELS) of
true ->
{ok, ok, State#state{level=lager_util:level_to_num(Level)}};
_ ->
try lager_util:config_to_mask(Level) of
Levels ->
{ok, ok, State#state{level=Levels}}
catch
_:_ ->
{ok, {error, bad_log_level}, State} {ok, {error, bad_log_level}, State}
end; end;
handle_call(_Request, State) -> handle_call(_Request, State) ->
@ -133,7 +135,7 @@ console_log_test_() ->
unregister(user), unregister(user),
register(user, Pid), register(user, Pid),
erlang:group_leader(Pid, whereis(lager_event)), erlang:group_leader(Pid, whereis(lager_event)),
lager_config:set(loglevel, {?INFO, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
lager:log(info, self(), "Test message"), lager:log(info, self(), "Test message"),
receive receive
{io_request, From, ReplyAs, {put_chars, unicode, Msg}} -> {io_request, From, ReplyAs, {put_chars, unicode, Msg}} ->
@ -152,7 +154,7 @@ console_log_test_() ->
register(user, Pid), register(user, Pid),
erlang:group_leader(Pid, whereis(lager_event)), erlang:group_leader(Pid, whereis(lager_event)),
gen_event:add_handler(lager_event, lager_console_backend, [info, true]), gen_event:add_handler(lager_event, lager_console_backend, [info, true]),
lager_config:set(loglevel, {?INFO, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
lager:info("Test message"), lager:info("Test message"),
lager:info("Test message"), lager:info("Test message"),
PidStr = pid_to_list(self()), PidStr = pid_to_list(self()),
@ -196,7 +198,7 @@ console_log_test_() ->
register(user, Pid), register(user, Pid),
gen_event:add_handler(lager_event, lager_console_backend, info), gen_event:add_handler(lager_event, lager_console_backend, info),
erlang:group_leader(Pid, whereis(lager_event)), erlang:group_leader(Pid, whereis(lager_event)),
lager_config:set(loglevel, {?INFO, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
lager:debug("Test message"), lager:debug("Test message"),
receive receive
{io_request, From, ReplyAs, {put_chars, unicode, _Msg}} -> {io_request, From, ReplyAs, {put_chars, unicode, _Msg}} ->
@ -224,7 +226,7 @@ console_log_test_() ->
unregister(user), unregister(user),
register(user, Pid), register(user, Pid),
gen_event:add_handler(lager_event, lager_console_backend, info), gen_event:add_handler(lager_event, lager_console_backend, info),
lager_config:set(loglevel, {?INFO, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
erlang:group_leader(Pid, whereis(lager_event)), erlang:group_leader(Pid, whereis(lager_event)),
lager:debug("Test message"), lager:debug("Test message"),
receive receive
@ -255,8 +257,67 @@ console_log_test_() ->
?assert(true) ?assert(true)
end end
end end
},
{"blacklisting a loglevel works",
fun() ->
Pid = spawn(F(self())),
unregister(user),
register(user, Pid),
gen_event:add_handler(lager_event, lager_console_backend, info),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
lager:set_loglevel(lager_console_backend, '!=info'),
erlang:group_leader(Pid, whereis(lager_event)),
lager:debug("Test message"),
receive
{io_request, From1, ReplyAs1, {put_chars, unicode, Msg1}} ->
From1 ! {io_reply, ReplyAs1, ok},
?assertMatch([_, "[debug]", "Test message\r\n"], re:split(Msg1, " ", [{return, list}, {parts, 3}]))
after
1000 ->
?assert(false)
end,
%% info is blacklisted
lager:info("Test message"),
receive
{io_request, From2, ReplyAs2, {put_chars, unicode, _Msg2}} ->
From2 ! {io_reply, ReplyAs2, ok},
?assert(false)
after
500 ->
?assert(true)
end
end
},
{"whitelisting a loglevel works",
fun() ->
Pid = spawn(F(self())),
unregister(user),
register(user, Pid),
gen_event:add_handler(lager_event, lager_console_backend, info),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(info)), []}),
lager:set_loglevel(lager_console_backend, '=debug'),
erlang:group_leader(Pid, whereis(lager_event)),
lager:debug("Test message"),
receive
{io_request, From1, ReplyAs1, {put_chars, unicode, Msg1}} ->
From1 ! {io_reply, ReplyAs1, ok},
?assertMatch([_, "[debug]", "Test message\r\n"], re:split(Msg1, " ", [{return, list}, {parts, 3}]))
after
1000 ->
?assert(false)
end,
%% info is blacklisted
lager:error("Test message"),
receive
{io_request, From2, ReplyAs2, {put_chars, unicode, _Msg2}} ->
From2 ! {io_reply, ReplyAs2, ok},
?assert(false)
after
500 ->
?assert(true)
end
end
} }
] ]
}. }.
@ -278,7 +339,12 @@ set_loglevel_test_() ->
fun() -> fun() ->
?assertEqual(info, lager:get_loglevel(lager_console_backend)), ?assertEqual(info, lager:get_loglevel(lager_console_backend)),
lager:set_loglevel(lager_console_backend, debug), lager:set_loglevel(lager_console_backend, debug),
?assertEqual(debug, lager:get_loglevel(lager_console_backend))
?assertEqual(debug, lager:get_loglevel(lager_console_backend)),
lager:set_loglevel(lager_console_backend, '!=debug'),
?assertEqual(info, lager:get_loglevel(lager_console_backend)),
lager:set_loglevel(lager_console_backend, '!=info'),
?assertEqual(debug, lager:get_loglevel(lager_console_backend)),
ok
end end
}, },
{"Get/set invalid loglevel test", {"Get/set invalid loglevel test",

+ 33
- 18
src/lager_file_backend.erl View File

@ -45,7 +45,7 @@
-record(state, { -record(state, {
name :: string(), name :: string(),
level :: integer(),
level :: {'mask', integer()},
fd :: file:io_device(), fd :: file:io_device(),
inode :: integer(), inode :: integer(),
flap=false :: boolean(), flap=false :: boolean(),
@ -66,12 +66,12 @@ init([LogFile,{Formatter,FormatterConfig}]) ->
schedule_rotation(Name, Date), schedule_rotation(Name, Date),
State = case lager_util:open_logfile(Name, true) of State = case lager_util:open_logfile(Name, true) of
{ok, {FD, Inode, _}} -> {ok, {FD, Inode, _}} ->
#state{name=Name, level=lager_util:level_to_num(Level),
#state{name=Name, level=Level,
fd=FD, inode=Inode, size=Size, date=Date, count=Count, formatter=Formatter, formatter_config=FormatterConfig}; fd=FD, inode=Inode, size=Size, date=Date, count=Count, formatter=Formatter, formatter_config=FormatterConfig};
{error, Reason} -> {error, Reason} ->
?INT_LOG(error, "Failed to open log file ~s with error ~s", ?INT_LOG(error, "Failed to open log file ~s with error ~s",
[Name, file:format_error(Reason)]), [Name, file:format_error(Reason)]),
#state{name=Name, level=lager_util:level_to_num(Level),
#state{name=Name, level=Level,
flap=true, size=Size, date=Date, count=Count, formatter=Formatter, formatter_config=FormatterConfig} flap=true, size=Size, date=Date, count=Count, formatter=Formatter, formatter_config=FormatterConfig}
end, end,
@ -85,8 +85,13 @@ init(LogFile) ->
%% @private %% @private
handle_call({set_loglevel, Level}, #state{name=Ident} = State) -> handle_call({set_loglevel, Level}, #state{name=Ident} = State) ->
?INT_LOG(notice, "Changed loglevel of ~s to ~p", [Ident, Level]),
{ok, ok, State#state{level=lager_util:level_to_num(Level)}};
case validate_loglevel(Level) of
false ->
{ok, {error, bad_loglevel}, State};
Levels ->
?INT_LOG(notice, "Changed loglevel of ~s to ~p", [Ident, Level]),
{ok, ok, State#state{level=Levels}}
end;
handle_call(get_loglevel, #state{level=Level} = State) -> handle_call(get_loglevel, #state{level=Level} = State) ->
{ok, Level, State}; {ok, Level, State};
handle_call(_Request, State) -> handle_call(_Request, State) ->
@ -170,16 +175,16 @@ write(#state{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize,
end. end.
validate_logfile({Name, Level}) -> validate_logfile({Name, Level}) ->
case lists:member(Level, ?LEVELS) of
true ->
{Name, Level, 0, undefined, 0};
_ ->
case validate_loglevel(Level) of
false ->
?INT_LOG(error, "Invalid log level of ~p for ~s.", ?INT_LOG(error, "Invalid log level of ~p for ~s.",
[Level, Name]), [Level, Name]),
false
false;
Levels ->
{Name, Levels, 0, undefined, 0}
end; end;
validate_logfile({Name, Level, Size, Date, Count}) -> validate_logfile({Name, Level, Size, Date, Count}) ->
ValidLevel = (lists:member(Level, ?LEVELS)),
ValidLevel = validate_loglevel(Level),
ValidSize = (is_integer(Size) andalso Size >= 0), ValidSize = (is_integer(Size) andalso Size >= 0),
ValidCount = (is_integer(Count) andalso Count >= 0), ValidCount = (is_integer(Count) andalso Count >= 0),
case {ValidLevel, ValidSize, ValidCount} of case {ValidLevel, ValidSize, ValidCount} of
@ -195,13 +200,13 @@ validate_logfile({Name, Level, Size, Date, Count}) ->
?INT_LOG(error, "Invalid rotation count of ~p for ~s.", ?INT_LOG(error, "Invalid rotation count of ~p for ~s.",
[Count, Name]), [Count, Name]),
false; false;
{true, true, true} ->
{Levels, true, true} ->
case lager_util:parse_rotation_date_spec(Date) of case lager_util:parse_rotation_date_spec(Date) of
{ok, Spec} -> {ok, Spec} ->
{Name, Level, Size, Spec, Count};
{Name, Levels, Size, Spec, Count};
{error, _} when Date == "" -> {error, _} when Date == "" ->
%% blank ones are fine. %% blank ones are fine.
{Name, Level, Size, undefined, Count};
{Name, Levels, Size, undefined, Count};
{error, _} -> {error, _} ->
?INT_LOG(error, "Invalid rotation date of ~p for ~s.", ?INT_LOG(error, "Invalid rotation date of ~p for ~s.",
[Date, Name]), [Date, Name]),
@ -212,6 +217,16 @@ validate_logfile(H) ->
?INT_LOG(error, "Invalid log file config ~p.", [H]), ?INT_LOG(error, "Invalid log file config ~p.", [H]),
false. false.
validate_loglevel(Level) ->
try lager_util:config_to_mask(Level) of
Levels ->
Levels
catch
_:_ ->
false
end.
schedule_rotation(_, undefined) -> schedule_rotation(_, undefined) ->
ok; ok;
schedule_rotation(Name, Date) -> schedule_rotation(Name, Date) ->
@ -222,11 +237,11 @@ schedule_rotation(Name, Date) ->
get_loglevel_test() -> get_loglevel_test() ->
{ok, Level, _} = handle_call(get_loglevel, {ok, Level, _} = handle_call(get_loglevel,
#state{name="bar", level=lager_util:level_to_num(info), fd=0, inode=0}),
?assertEqual(Level, lager_util:level_to_num(info)),
#state{name="bar", level=lager_util:config_to_mask(info), fd=0, inode=0}),
?assertEqual(Level, lager_util:config_to_mask(info)),
{ok, Level2, _} = handle_call(get_loglevel, {ok, Level2, _} = handle_call(get_loglevel,
#state{name="foo", level=lager_util:level_to_num(warning), fd=0, inode=0}),
?assertEqual(Level2, lager_util:level_to_num(warning)).
#state{name="foo", level=lager_util:config_to_mask(warning), fd=0, inode=0}),
?assertEqual(Level2, lager_util:config_to_mask(warning)).
rotation_test() -> rotation_test() ->
{ok, {FD, Inode, _}} = lager_util:open_logfile("test.log", true), {ok, {FD, Inode, _}} = lager_util:open_logfile("test.log", true),

+ 165
- 48
src/lager_util.erl View File

@ -18,8 +18,8 @@
-include_lib("kernel/include/file.hrl"). -include_lib("kernel/include/file.hrl").
-export([levels/0, level_to_num/1, num_to_level/1, open_logfile/2,
ensure_logfile/4, rotate_logfile/2, format_time/0, format_time/1,
-export([levels/0, level_to_num/1, num_to_level/1, config_to_mask/1, config_to_levels/1, mask_to_levels/1,
open_logfile/2, ensure_logfile/4, rotate_logfile/2, format_time/0, format_time/1,
localtime_ms/0, maybe_utc/1, parse_rotation_date_spec/1, localtime_ms/0, maybe_utc/1, parse_rotation_date_spec/1,
calculate_next_rotation/1, validate_trace/1, check_traces/4, is_loggable/3]). calculate_next_rotation/1, validate_trace/1, check_traces/4, is_loggable/3]).
@ -32,25 +32,93 @@
levels() -> levels() ->
[debug, info, notice, warning, error, critical, alert, emergency]. [debug, info, notice, warning, error, critical, alert, emergency].
level_to_num(debug) -> 7;
level_to_num(info) -> 6;
level_to_num(notice) -> 5;
level_to_num(warning) -> 4;
level_to_num(error) -> 3;
level_to_num(critical) -> 2;
level_to_num(alert) -> 1;
level_to_num(emergency) -> 0;
level_to_num(none) -> -1.
num_to_level(7) -> debug;
num_to_level(6) -> info;
num_to_level(5) -> notice;
num_to_level(4) -> warning;
num_to_level(3) -> error;
num_to_level(2) -> critical;
num_to_level(1) -> alert;
num_to_level(0) -> emergency;
num_to_level(-1) -> none.
level_to_num(debug) -> ?DEBUG;
level_to_num(info) -> ?INFO;
level_to_num(notice) -> ?NOTICE;
level_to_num(warning) -> ?WARNING;
level_to_num(error) -> ?ERROR;
level_to_num(critical) -> ?CRITICAL;
level_to_num(alert) -> ?ALERT;
level_to_num(emergency) -> ?EMERGENCY;
level_to_num(none) -> ?LOG_NONE.
num_to_level(?DEBUG) -> debug;
num_to_level(?INFO) -> info;
num_to_level(?NOTICE) -> notice;
num_to_level(?WARNING) -> warning;
num_to_level(?ERROR) -> error;
num_to_level(?CRITICAL) -> critical;
num_to_level(?ALERT) -> alert;
num_to_level(?EMERGENCY) -> emergency;
num_to_level(?LOG_NONE) -> none.
-spec config_to_mask(atom()|string()) -> {'mask', integer()}.
config_to_mask(Conf) ->
Levels = config_to_levels(Conf),
{mask, lists:foldl(fun(Level, Acc) ->
level_to_num(Level) bor Acc
end, 0, Levels)}.
-spec mask_to_levels(non_neg_integer()) -> [lager:log_level()].
mask_to_levels(Mask) ->
mask_to_levels(Mask, levels(), []).
mask_to_levels(_Mask, [], Acc) ->
lists:reverse(Acc);
mask_to_levels(Mask, [Level|Levels], Acc) ->
NewAcc = case (level_to_num(Level) band Mask) /= 0 of
true ->
[Level|Acc];
false ->
Acc
end,
mask_to_levels(Mask, Levels, NewAcc).
-spec config_to_levels(atom()|string()) -> [lager:log_level()].
config_to_levels(Conf) when is_atom(Conf) ->
config_to_levels(atom_to_list(Conf));
config_to_levels([$! | Rest]) ->
levels() -- config_to_levels(Rest);
config_to_levels([$=, $< | Rest]) ->
[_|Levels] = config_to_levels_int(Rest),
lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
config_to_levels([$<, $= | Rest]) ->
[_|Levels] = config_to_levels_int(Rest),
lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
config_to_levels([$>, $= | Rest]) ->
config_to_levels_int(Rest);
config_to_levels([$=, $> | Rest]) ->
config_to_levels_int(Rest);
config_to_levels([$= | Rest]) ->
[level_to_atom(Rest)];
config_to_levels([$< | Rest]) ->
Levels = config_to_levels_int(Rest),
lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
config_to_levels([$> | Rest]) ->
[_|Levels] = config_to_levels_int(Rest),
lists:filter(fun(E) -> lists:member(E, Levels) end, levels());
config_to_levels(Conf) ->
config_to_levels_int(Conf).
%% internal function to break the recursion loop
config_to_levels_int(Conf) ->
Level = level_to_atom(Conf),
lists:dropwhile(fun(E) -> E /= Level end, levels()).
level_to_atom(String) ->
Levels = levels(),
try list_to_existing_atom(String) of
Atom ->
case lists:member(Atom, Levels) of
true ->
Atom;
false ->
erlang:error(badarg)
end
catch
_:_ ->
erlang:error(badarg)
end.
open_logfile(Name, Buffer) -> open_logfile(Name, Buffer) ->
case filelib:ensure_dir(Name) of case filelib:ensure_dir(Name) of
@ -283,7 +351,7 @@ validate_trace({Filter, Level, {Destination, ID}}) when is_list(Filter), is_atom
Error Error
end; end;
validate_trace({Filter, Level, Destination}) when is_list(Filter), is_atom(Level), is_atom(Destination) -> validate_trace({Filter, Level, Destination}) when is_list(Filter), is_atom(Level), is_atom(Destination) ->
try level_to_num(Level) of
try config_to_mask(Level) of
L -> L ->
case lists:all(fun({Key, _Value}) when is_atom(Key) -> true; (_) -> case lists:all(fun({Key, _Value}) when is_atom(Key) -> true; (_) ->
false end, Filter) of false end, Filter) of
@ -302,7 +370,7 @@ validate_trace(_) ->
check_traces(_, _, [], Acc) -> check_traces(_, _, [], Acc) ->
lists:flatten(Acc); lists:flatten(Acc);
check_traces(Attrs, Level, [{_, FilterLevel, _}|Flows], Acc) when Level > FilterLevel ->
check_traces(Attrs, Level, [{_, {mask, FilterLevel}, _}|Flows], Acc) when (Level band FilterLevel) == 0 ->
check_traces(Attrs, Level, Flows, Acc); check_traces(Attrs, Level, Flows, Acc);
check_traces(Attrs, Level, [{Filter, _, _}|Flows], Acc) when length(Attrs) < length(Filter) -> check_traces(Attrs, Level, [{Filter, _, _}|Flows], Acc) when length(Attrs) < length(Filter) ->
check_traces(Attrs, Level, Flows, Acc); check_traces(Attrs, Level, Flows, Acc);
@ -329,7 +397,13 @@ check_trace_iter(Attrs, [{Key, Match}|T]) ->
false false
end. end.
-spec is_loggable(lager_msg:lager_msg(),integer(),term()) -> boolean().
-spec is_loggable(lager_msg:lager_msg(), non_neg_integer()|{'mask', non_neg_integer()}, term()) -> boolean().
is_loggable(Msg, {mask, Mask}, MyName) ->
%% using syslog style comparison flags
%S = lager_msg:severity_as_int(Msg),
%?debugFmt("comparing masks ~.2B and ~.2B -> ~p~n", [S, Mask, S band Mask]),
(lager_msg:severity_as_int(Msg) band Mask) /= 0 orelse
lists:member(MyName, lager_msg:destinations(Msg));
is_loggable(Msg ,SeverityThreshold,MyName) -> is_loggable(Msg ,SeverityThreshold,MyName) ->
lager_msg:severity_as_int(Msg) =< SeverityThreshold orelse lager_msg:severity_as_int(Msg) =< SeverityThreshold orelse
lists:member(MyName, lager_msg:destinations(Msg)). lists:member(MyName, lager_msg:destinations(Msg)).
@ -440,30 +514,46 @@ rotate_file_test() ->
end || N <- lists:seq(0, 20)]. end || N <- lists:seq(0, 20)].
check_trace_test() -> check_trace_test() ->
?assertEqual([foo], check_traces([{module, ?MODULE}], 0, [{[{module, ?MODULE}],
0, foo},
{[{module, test}], 0, bar}], [])),
?assertEqual([], check_traces([{module, ?MODULE}], 0, [{[{module, ?MODULE},
{foo, bar}], 0, foo},
{[{module, test}], 0, bar}], [])),
?assertEqual([bar], check_traces([{module, ?MODULE}], 0, [{[{module, ?MODULE},
{foo, bar}], 0, foo},
{[{module, '*'}], 0, bar}], [])),
?assertEqual([bar], check_traces([{module, ?MODULE}], 0, [{[{module, '*'},
{foo, bar}], 0, foo},
{[{module, '*'}], 0, bar}], [])),
?assertEqual([bar], check_traces([{module, ?MODULE}], 0, [{[{module, '*'},
{foo, '*'}], 0, foo},
{[{module, '*'}], 0, bar}], [])),
?assertEqual([bar, foo], check_traces([{module, ?MODULE}, {foo, bar}], 0, [{[{module, '*'},
{foo, '*'}], 0, foo},
{[{module, '*'}], 0, bar}], [])),
?assertEqual([], check_traces([{module, ?MODULE}, {foo, bar}], 6, [{[{module, '*'},
{foo, '*'}], 0, foo},
{[{module, '*'}], 0, bar}], [])),
?assertEqual([foo], check_traces([{module, ?MODULE}, {foo, bar}], 6, [{[{module, '*'},
{foo, '*'}], 7, foo},
{[{module, '*'}], 0, bar}], [])),
%% match by module
?assertEqual([foo], check_traces([{module, ?MODULE}], ?EMERGENCY, [
{[{module, ?MODULE}], config_to_mask(emergency), foo},
{[{module, test}], config_to_mask(emergency), bar}], [])),
%% match by module, but other unsatisfyable attribute
?assertEqual([], check_traces([{module, ?MODULE}], ?EMERGENCY, [
{[{module, ?MODULE}, {foo, bar}], config_to_mask(emergency), foo},
{[{module, test}], config_to_mask(emergency), bar}], [])),
%% match by wildcard module
?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
{[{module, ?MODULE}, {foo, bar}], config_to_mask(emergency), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
%% wildcard module, one trace with unsatisfyable attribute
?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
{[{module, '*'}, {foo, bar}], config_to_mask(emergency), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
%% wildcard but not present custom trace attribute
?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
{[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
%% wildcarding a custom attribute works when it is present
?assertEqual([bar, foo], check_traces([{module, ?MODULE}, {foo, bar}], ?EMERGENCY, [
{[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
%% denied by level
?assertEqual([], check_traces([{module, ?MODULE}, {foo, bar}], ?INFO, [
{[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
%% allowed by level
?assertEqual([foo], check_traces([{module, ?MODULE}, {foo, bar}], ?INFO, [
{[{module, '*'}, {foo, '*'}], config_to_mask(debug), foo},
{[{module, '*'}], config_to_mask(emergency), bar}], [])),
?assertEqual([anythingbutnotice, infoandbelow, infoonly], check_traces([{module, ?MODULE}], ?INFO, [
{[{module, '*'}], config_to_mask('=debug'), debugonly},
{[{module, '*'}], config_to_mask('=info'), infoonly},
{[{module, '*'}], config_to_mask('<=info'), infoandbelow},
{[{module, '*'}], config_to_mask('!=info'), anythingbutinfo},
{[{module, '*'}], config_to_mask('!=notice'), anythingbutnotice}
], [])),
ok. ok.
is_loggable_test_() -> is_loggable_test_() ->
@ -504,4 +594,31 @@ format_time_test_() ->
end) end)
]. ].
config_to_levels_test() ->
?assertEqual([debug], config_to_levels('=debug')),
?assertEqual([debug], config_to_levels('<info')),
?assertEqual(levels() -- [debug], config_to_levels('!=debug')),
?assertEqual(levels() -- [debug], config_to_levels('>debug')),
?assertEqual(levels() -- [debug], config_to_levels('>=info')),
?assertEqual(levels() -- [debug], config_to_levels('=>info')),
?assertEqual([debug, info, notice], config_to_levels('<=notice')),
?assertEqual([debug, info, notice], config_to_levels('=<notice')),
?assertEqual([debug], config_to_levels('<info')),
?assertEqual([debug], config_to_levels('!info')),
?assertError(badarg, config_to_levels(ok)),
?assertError(badarg, config_to_levels('<=>info')),
?assertError(badarg, config_to_levels('=<=info')),
?assertError(badarg, config_to_levels('<==>=<=>info')),
%% double negatives DO work, however
?assertEqual([debug], config_to_levels('!!=debug')),
?assertEqual(levels() -- [debug], config_to_levels('!!!=debug')),
ok.
mask_to_levels_test() ->
?assertEqual([debug], mask_to_levels(2#10000000)),
?assertEqual([debug, info], mask_to_levels(2#11000000)),
?assertEqual([debug, info, emergency], mask_to_levels(2#11000001)),
?assertEqual([debug, notice, error], mask_to_levels(?DEBUG bor ?NOTICE bor ?ERROR)),
ok.
-endif. -endif.

+ 30
- 23
test/lager_test_backend.erl View File

@ -32,7 +32,7 @@
-endif. -endif.
init(Level) -> init(Level) ->
{ok, #state{level=lager_util:level_to_num(Level), buffer=[], ignored=[]}}.
{ok, #state{level=lager_util:config_to_mask(Level), buffer=[], ignored=[]}}.
handle_call(count, #state{buffer=Buffer} = State) -> handle_call(count, #state{buffer=Buffer} = State) ->
{ok, length(Buffer), State}; {ok, length(Buffer), State};
@ -50,7 +50,7 @@ handle_call(pop, #state{buffer=Buffer} = State) ->
handle_call(get_loglevel, #state{level=Level} = State) -> handle_call(get_loglevel, #state{level=Level} = State) ->
{ok, Level, State}; {ok, Level, State};
handle_call({set_loglevel, Level}, State) -> handle_call({set_loglevel, Level}, State) ->
{ok, ok, State#state{level=lager_util:level_to_num(Level)}};
{ok, ok, State#state{level=lager_util:config_to_mask(Level)}};
handle_call(print_state, State) -> handle_call(print_state, State) ->
spawn(fun() -> lager:info("State ~p", [lager:pr(State, ?MODULE)]) end), spawn(fun() -> lager:info("State ~p", [lager:pr(State, ?MODULE)]) end),
timer:sleep(100), timer:sleep(100),
@ -63,14 +63,16 @@ handle_call(_Request, State) ->
{ok, ok, State}. {ok, ok, State}.
handle_event({log, Msg}, handle_event({log, Msg},
#state{level=LogLevel,buffer=Buffer,ignored=Ignored} = State) ->
case lager_util:is_loggable(Msg, LogLevel, ?MODULE) of
true -> {ok, State#state{buffer=Buffer ++
[{lager_msg:severity_as_int(Msg),
lager_msg:timestamp(Msg),
lager_msg:message(Msg), lager_msg:metadata(Msg)}]}};
_ -> {ok, State#state{ignored=Ignored ++ [ignored]}}
end;
#state{level=LogLevel,buffer=Buffer,ignored=Ignored} = State) ->
case lager_util:is_loggable(Msg, LogLevel, ?MODULE) of
true ->
{ok, State#state{buffer=Buffer ++
[{lager_msg:severity_as_int(Msg),
lager_msg:timestamp(Msg),
lager_msg:message(Msg), lager_msg:metadata(Msg)}]}};
_ ->
{ok, State#state{ignored=Ignored ++ [ignored]}}
end;
handle_event(_Event, State) -> handle_event(_Event, State) ->
{ok, State}. {ok, State}.
@ -184,7 +186,7 @@ lager_test_() ->
lager:debug("this message will be ignored"), lager:debug("this message will be ignored"),
?assertEqual(0, count()), ?assertEqual(0, count()),
?assertEqual(0, count_ignored()), ?assertEqual(0, count_ignored()),
lager_config:set(loglevel, {?DEBUG, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(debug)), []}),
lager:debug("this message should be ignored"), lager:debug("this message should be ignored"),
?assertEqual(0, count()), ?assertEqual(0, count()),
?assertEqual(1, count_ignored()), ?assertEqual(1, count_ignored()),
@ -198,11 +200,10 @@ lager_test_() ->
}, },
{"tracing works", {"tracing works",
fun() -> fun() ->
lager_config:set(loglevel, {?ERROR, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(error)), []}),
ok = lager:info("hello world"), ok = lager:info("hello world"),
?assertEqual(0, count()), ?assertEqual(0, count()),
lager_config:set(loglevel, {?ERROR, [{[{module,
?MODULE}], ?DEBUG, ?MODULE}]}),
lager:trace(?MODULE, [{module, ?MODULE}], debug),
ok = lager:info("hello world"), ok = lager:info("hello world"),
?assertEqual(1, count()), ?assertEqual(1, count()),
ok ok
@ -210,15 +211,17 @@ lager_test_() ->
}, },
{"tracing works with custom attributes", {"tracing works with custom attributes",
fun() -> fun() ->
lager_config:set(loglevel, {?ERROR, []}),
lager:set_loglevel(?MODULE, error),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(error)), []}),
lager:info([{requestid, 6}], "hello world"), lager:info([{requestid, 6}], "hello world"),
?assertEqual(0, count()), ?assertEqual(0, count()),
lager_config:set(loglevel, {?ERROR,
[{[{requestid, 6}], ?DEBUG, ?MODULE}]}),
lager:trace(?MODULE, [{requestid, 6}, {foo, bar}], debug),
lager:info([{requestid, 6}, {foo, bar}], "hello world"), lager:info([{requestid, 6}, {foo, bar}], "hello world"),
?assertEqual(1, count()), ?assertEqual(1, count()),
lager_config:set(loglevel, {?ERROR,
[{[{requestid, '*'}], ?DEBUG, ?MODULE}]}),
lager:trace(?MODULE, [{requestid, '*'}], debug),
lager:info([{requestid, 6}], "hello world"),
?assertEqual(2, count()),
lager:clear_all_traces(),
lager:info([{requestid, 6}], "hello world"), lager:info([{requestid, 6}], "hello world"),
?assertEqual(2, count()), ?assertEqual(2, count()),
ok ok
@ -226,12 +229,15 @@ lager_test_() ->
}, },
{"tracing honors loglevel", {"tracing honors loglevel",
fun() -> fun() ->
lager_config:set(loglevel, {?ERROR, [{[{module,
?MODULE}], ?NOTICE, ?MODULE}]}),
lager:set_loglevel(?MODULE, error),
{ok, T} = lager:trace(?MODULE, [{module, ?MODULE}], notice),
ok = lager:info("hello world"), ok = lager:info("hello world"),
?assertEqual(0, count()), ?assertEqual(0, count()),
ok = lager:notice("hello world"), ok = lager:notice("hello world"),
?assertEqual(1, count()), ?assertEqual(1, count()),
lager:stop_trace(T),
ok = lager:notice("hello world"),
?assertEqual(1, count()),
ok ok
end end
}, },
@ -240,7 +246,8 @@ lager_test_() ->
print_state(), print_state(),
{Level, _Time, Message, _Metadata} = pop(), {Level, _Time, Message, _Metadata} = pop(),
?assertMatch(Level, lager_util:level_to_num(info)), ?assertMatch(Level, lager_util:level_to_num(info)),
?assertEqual("State #state{level=6,buffer=[],ignored=[]}", lists:flatten(Message)),
{mask, Mask} = lager_util:config_to_mask(info),
?assertEqual("State #state{level={mask,"++integer_to_list(Mask)++"},buffer=[],ignored=[]}", lists:flatten(Message)),
ok ok
end end
}, },
@ -772,7 +779,7 @@ error_logger_redirect_test_() ->
?assertEqual(1, count()), ?assertEqual(1, count()),
?assertEqual(0, count_ignored()), ?assertEqual(0, count_ignored()),
lager:set_loglevel(?MODULE, error), lager:set_loglevel(?MODULE, error),
lager_config:set(loglevel, {?DEBUG, []}),
lager_config:set(loglevel, {element(2, lager_util:config_to_mask(debug)), []}),
sync_error_logger:info_report([hello, world]), sync_error_logger:info_report([hello, world]),
_ = gen_event:which_handlers(error_logger), _ = gen_event:which_handlers(error_logger),
?assertEqual(1, count()), ?assertEqual(1, count()),

Loading…
Cancel
Save