1%% Copyright (c) 2011-2012 Basho Technologies, Inc.  All Rights Reserved.
2%%
3%% This file is provided to you under the Apache License,
4%% Version 2.0 (the "License"); you may not use this file
5%% except in compliance with the License.  You may obtain
6%% a copy of the License at
7%%
8%%   http://www.apache.org/licenses/LICENSE-2.0
9%%
10%% Unless required by applicable law or agreed to in writing,
11%% software distributed under the License is distributed on an
12%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
13%% KIND, either express or implied.  See the License for the
14%% specific language governing permissions and limitations
15%% under the License.
16
17-module(lager_util).
18
19-include_lib("kernel/include/file.hrl").
20
21-export([levels/0, level_to_num/1, level_to_chr/1,
22        num_to_level/1, config_to_mask/1, config_to_levels/1, mask_to_levels/1,
23        open_logfile/2, ensure_logfile/4, rotate_logfile/2, format_time/0, format_time/1,
24        localtime_ms/0, localtime_ms/1, maybe_utc/1, parse_rotation_date_spec/1,
25        calculate_next_rotation/1, validate_trace/1, check_traces/4, is_loggable/3,
26        trace_filter/1, trace_filter/2, expand_path/1, check_hwm/1, make_internal_sink_name/1]).
27
28-ifdef(TEST).
29-include_lib("eunit/include/eunit.hrl").
30-endif.
31
32-include("lager.hrl").
33
34levels() ->
35    [debug, info, notice, warning, error, critical, alert, emergency, none].
36
37level_to_num(debug)      -> ?DEBUG;
38level_to_num(info)       -> ?INFO;
39level_to_num(notice)     -> ?NOTICE;
40level_to_num(warning)    -> ?WARNING;
41level_to_num(error)      -> ?ERROR;
42level_to_num(critical)   -> ?CRITICAL;
43level_to_num(alert)      -> ?ALERT;
44level_to_num(emergency)  -> ?EMERGENCY;
45level_to_num(none)       -> ?LOG_NONE.
46
47level_to_chr(debug)      -> $D;
48level_to_chr(info)       -> $I;
49level_to_chr(notice)     -> $N;
50level_to_chr(warning)    -> $W;
51level_to_chr(error)      -> $E;
52level_to_chr(critical)   -> $C;
53level_to_chr(alert)      -> $A;
54level_to_chr(emergency)  -> $M;
55level_to_chr(none)       -> $ .
56
57num_to_level(?DEBUG)     -> debug;
58num_to_level(?INFO)      -> info;
59num_to_level(?NOTICE)    -> notice;
60num_to_level(?WARNING)   -> warning;
61num_to_level(?ERROR)     -> error;
62num_to_level(?CRITICAL)  -> critical;
63num_to_level(?ALERT)     -> alert;
64num_to_level(?EMERGENCY) -> emergency;
65num_to_level(?LOG_NONE)  -> none.
66
67-spec config_to_mask(atom()|string()) -> {'mask', integer()}.
68config_to_mask(Conf) ->
69    Levels = config_to_levels(Conf),
70    {mask, lists:foldl(fun(Level, Acc) ->
71                level_to_num(Level) bor Acc
72            end, 0, Levels)}.
73
74-spec mask_to_levels(non_neg_integer()) -> [lager:log_level()].
75mask_to_levels(Mask) ->
76    mask_to_levels(Mask, levels(), []).
77
78mask_to_levels(_Mask, [], Acc) ->
79    lists:reverse(Acc);
80mask_to_levels(Mask, [Level|Levels], Acc) ->
81    NewAcc = case (level_to_num(Level) band Mask) /= 0 of
82        true ->
83            [Level|Acc];
84        false ->
85            Acc
86    end,
87    mask_to_levels(Mask, Levels, NewAcc).
88
89-spec config_to_levels(atom()|string()) -> [lager:log_level()].
90config_to_levels(Conf) when is_atom(Conf) ->
91    config_to_levels(atom_to_list(Conf));
92config_to_levels([$! | Rest]) ->
93    levels() -- config_to_levels(Rest);
94config_to_levels([$=, $< | Rest]) ->
95    [_|Levels] = config_to_levels_int(Rest),
96    lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
97config_to_levels([$<, $= | Rest]) ->
98    [_|Levels] = config_to_levels_int(Rest),
99    lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
100config_to_levels([$>, $= | Rest]) ->
101    config_to_levels_int(Rest);
102config_to_levels([$=, $> | Rest]) ->
103    config_to_levels_int(Rest);
104config_to_levels([$= | Rest]) ->
105    [level_to_atom(Rest)];
106config_to_levels([$< | Rest]) ->
107    Levels = config_to_levels_int(Rest),
108    lists:filter(fun(E) -> not lists:member(E, Levels) end, levels());
109config_to_levels([$> | Rest]) ->
110    [_|Levels] = config_to_levels_int(Rest),
111    lists:filter(fun(E) -> lists:member(E, Levels) end, levels());
112config_to_levels(Conf) ->
113    config_to_levels_int(Conf).
114
115%% internal function to break the recursion loop
116config_to_levels_int(Conf) ->
117    Level = level_to_atom(Conf),
118    lists:dropwhile(fun(E) -> E /= Level end, levels()).
119
120level_to_atom(String) ->
121    Levels = levels(),
122    try list_to_existing_atom(String) of
123        Atom ->
124            case lists:member(Atom, Levels) of
125                true ->
126                    Atom;
127                false ->
128                    erlang:error(badarg)
129            end
130    catch
131        _:_ ->
132            erlang:error(badarg)
133    end.
134
135open_logfile(Name, Buffer) ->
136    case filelib:ensure_dir(Name) of
137        ok ->
138            Options = [append, raw] ++
139            case  Buffer of
140                {Size, Interval} when is_integer(Interval), Interval >= 0, is_integer(Size), Size >= 0 ->
141                    [{delayed_write, Size, Interval}];
142                _ -> []
143            end,
144            case file:open(Name, Options) of
145                {ok, FD} ->
146                    case file:read_file_info(Name) of
147                        {ok, FInfo} ->
148                            Inode = FInfo#file_info.inode,
149                            {ok, {FD, Inode, FInfo#file_info.size}};
150                        X -> X
151                    end;
152                Y -> Y
153            end;
154        Z -> Z
155    end.
156
157ensure_logfile(Name, FD, Inode, Buffer) ->
158    case file:read_file_info(Name) of
159        {ok, FInfo} ->
160            Inode2 = FInfo#file_info.inode,
161            case Inode == Inode2 of
162                true ->
163                    {ok, {FD, Inode, FInfo#file_info.size}};
164                false ->
165                    %% delayed write can cause file:close not to do a close
166                    _ = file:close(FD),
167                    _ = file:close(FD),
168                    case open_logfile(Name, Buffer) of
169                        {ok, {FD2, Inode3, Size}} ->
170                            %% inode changed, file was probably moved and
171                            %% recreated
172                            {ok, {FD2, Inode3, Size}};
173                        Error ->
174                            Error
175                    end
176            end;
177        _ ->
178            %% delayed write can cause file:close not to do a close
179            _ = file:close(FD),
180            _ = file:close(FD),
181            case open_logfile(Name, Buffer) of
182                {ok, {FD2, Inode3, Size}} ->
183                    %% file was removed
184                    {ok, {FD2, Inode3, Size}};
185                Error ->
186                    Error
187            end
188    end.
189
190%% returns localtime with milliseconds included
191localtime_ms() ->
192    Now = os:timestamp(),
193    localtime_ms(Now).
194
195localtime_ms(Now) ->
196    {_, _, Micro} = Now,
197    {Date, {Hours, Minutes, Seconds}} = calendar:now_to_local_time(Now),
198    {Date, {Hours, Minutes, Seconds, Micro div 1000 rem 1000}}.
199
200
201maybe_utc({Date, {H, M, S, Ms}}) ->
202    case lager_stdlib:maybe_utc({Date, {H, M, S}}) of
203        {utc, {Date1, {H1, M1, S1}}} ->
204            {utc, {Date1, {H1, M1, S1, Ms}}};
205        {Date1, {H1, M1, S1}} ->
206            {Date1, {H1, M1, S1, Ms}}
207    end.
208
209%% renames failing are OK
210rotate_logfile(File, 0) ->
211    file:delete(File);
212rotate_logfile(File, 1) ->
213    case file:rename(File, File++".0") of
214        ok ->
215            ok;
216        _ ->
217            rotate_logfile(File, 0)
218    end;
219rotate_logfile(File, Count) ->
220    _ = file:rename(File ++ "." ++ integer_to_list(Count - 2), File ++ "." ++ integer_to_list(Count - 1)),
221    rotate_logfile(File, Count - 1).
222
223format_time() ->
224    format_time(maybe_utc(localtime_ms())).
225
226format_time({utc, {{Y, M, D}, {H, Mi, S, Ms}}}) ->
227    {[integer_to_list(Y), $-, i2l(M), $-, i2l(D)],
228     [i2l(H), $:, i2l(Mi), $:, i2l(S), $., i3l(Ms), $ , $U, $T, $C]};
229format_time({{Y, M, D}, {H, Mi, S, Ms}}) ->
230    {[integer_to_list(Y), $-, i2l(M), $-, i2l(D)],
231     [i2l(H), $:, i2l(Mi), $:, i2l(S), $., i3l(Ms)]};
232format_time({utc, {{Y, M, D}, {H, Mi, S}}}) ->
233    {[integer_to_list(Y), $-, i2l(M), $-, i2l(D)],
234     [i2l(H), $:, i2l(Mi), $:, i2l(S), $ , $U, $T, $C]};
235format_time({{Y, M, D}, {H, Mi, S}}) ->
236    {[integer_to_list(Y), $-, i2l(M), $-, i2l(D)],
237     [i2l(H), $:, i2l(Mi), $:, i2l(S)]}.
238
239parse_rotation_day_spec([], Res) ->
240    {ok, Res ++ [{hour, 0}]};
241parse_rotation_day_spec([$D, D1, D2], Res) ->
242    case list_to_integer([D1, D2]) of
243        X when X >= 0, X =< 23 ->
244            {ok, Res ++ [{hour, X}]};
245        _ ->
246            {error, invalid_date_spec}
247    end;
248parse_rotation_day_spec([$D, D], Res)  when D >= $0, D =< $9 ->
249    {ok, Res ++ [{hour, D - 48}]};
250parse_rotation_day_spec(_, _) ->
251    {error, invalid_date_spec}.
252
253parse_rotation_date_spec([$$, $W, W|T]) when W >= $0, W =< $6 ->
254    Week = W - 48,
255    parse_rotation_day_spec(T, [{day, Week}]);
256parse_rotation_date_spec([$$, $M, L|T]) when L == $L; L == $l ->
257    %% last day in month.
258    parse_rotation_day_spec(T, [{date, last}]);
259parse_rotation_date_spec([$$, $M, M1, M2|[$D|_]=T]) ->
260    case list_to_integer([M1, M2]) of
261        X when X >= 1, X =< 31 ->
262            parse_rotation_day_spec(T, [{date, X}]);
263        _ ->
264            {error, invalid_date_spec}
265    end;
266parse_rotation_date_spec([$$, $M, M|[$D|_]=T]) ->
267    parse_rotation_day_spec(T, [{date, M - 48}]);
268parse_rotation_date_spec([$$, $M, M1, M2]) ->
269    case list_to_integer([M1, M2]) of
270        X when X >= 1, X =< 31 ->
271            {ok, [{date, X}, {hour, 0}]};
272        _ ->
273            {error, invalid_date_spec}
274    end;
275parse_rotation_date_spec([$$, $M, M]) ->
276    {ok, [{date, M - 48}, {hour, 0}]};
277parse_rotation_date_spec([$$|X]) when X /= [] ->
278    parse_rotation_day_spec(X, []);
279parse_rotation_date_spec(_) ->
280    {error, invalid_date_spec}.
281
282calculate_next_rotation(Spec) ->
283    Now = calendar:local_time(),
284    Later = calculate_next_rotation(Spec, Now),
285    calendar:datetime_to_gregorian_seconds(Later) -
286      calendar:datetime_to_gregorian_seconds(Now).
287
288calculate_next_rotation([], Now) ->
289    Now;
290calculate_next_rotation([{hour, X}|T], {{_, _, _}, {Hour, _, _}} = Now) when Hour < X ->
291    %% rotation is today, sometime
292    NewNow = setelement(2, Now, {X, 0, 0}),
293    calculate_next_rotation(T, NewNow);
294calculate_next_rotation([{hour, X}|T], {{_, _, _}, _} = Now) ->
295    %% rotation is not today
296    Seconds = calendar:datetime_to_gregorian_seconds(Now) + 86400,
297    DateTime = calendar:gregorian_seconds_to_datetime(Seconds),
298    NewNow = setelement(2, DateTime, {X, 0, 0}),
299    calculate_next_rotation(T, NewNow);
300calculate_next_rotation([{day, Day}|T], {Date, _Time} = Now) ->
301    DoW = calendar:day_of_the_week(Date),
302    AdjustedDay = case Day of
303        0 -> 7;
304        X -> X
305    end,
306    case AdjustedDay of
307        DoW -> %% rotation is today
308            OldDate = element(1, Now),
309            case calculate_next_rotation(T, Now) of
310                {OldDate, _} = NewNow -> NewNow;
311                {NewDate, _} ->
312                    %% rotation *isn't* today! rerun the calculation
313                    NewNow = {NewDate, {0, 0, 0}},
314                    calculate_next_rotation([{day, Day}|T], NewNow)
315            end;
316        Y when Y > DoW -> %% rotation is later this week
317            PlusDays = Y - DoW,
318            Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays),
319            {NewDate, _} = calendar:gregorian_seconds_to_datetime(Seconds),
320            NewNow = {NewDate, {0, 0, 0}},
321            calculate_next_rotation(T, NewNow);
322        Y when Y < DoW -> %% rotation is next week
323            PlusDays = ((7 - DoW) + Y),
324            Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays),
325            {NewDate, _} = calendar:gregorian_seconds_to_datetime(Seconds),
326            NewNow = {NewDate, {0, 0, 0}},
327            calculate_next_rotation(T, NewNow)
328    end;
329calculate_next_rotation([{date, last}|T], {{Year, Month, Day}, _} = Now) ->
330    Last = calendar:last_day_of_the_month(Year, Month),
331    case Last == Day of
332        true -> %% doing rotation today
333            OldDate = element(1, Now),
334            case calculate_next_rotation(T, Now) of
335                {OldDate, _} = NewNow -> NewNow;
336                {NewDate, _} ->
337                    %% rotation *isn't* today! rerun the calculation
338                    NewNow = {NewDate, {0, 0, 0}},
339                    calculate_next_rotation([{date, last}|T], NewNow)
340            end;
341        false ->
342            NewNow = setelement(1, Now, {Year, Month, Last}),
343            calculate_next_rotation(T, NewNow)
344    end;
345calculate_next_rotation([{date, Date}|T], {{_, _, Date}, _} = Now) ->
346    %% rotation is today
347    OldDate = element(1, Now),
348    case calculate_next_rotation(T, Now) of
349        {OldDate, _} = NewNow -> NewNow;
350        {NewDate, _} ->
351            %% rotation *isn't* today! rerun the calculation
352            NewNow = setelement(1, Now, NewDate),
353            calculate_next_rotation([{date, Date}|T], NewNow)
354    end;
355calculate_next_rotation([{date, Date}|T], {{Year, Month, Day}, _} = Now) ->
356    PlusDays = case Date of
357        X when X < Day -> %% rotation is next month
358            Last = calendar:last_day_of_the_month(Year, Month),
359            (Last - Day);
360        X when X > Day -> %% rotation is later this month
361            X - Day
362    end,
363    Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays),
364    NewNow = calendar:gregorian_seconds_to_datetime(Seconds),
365    calculate_next_rotation(T, NewNow).
366
367-spec trace_filter(Query :: 'none' | [tuple()]) -> {ok, any()}.
368trace_filter(Query) ->
369    trace_filter(?DEFAULT_TRACER, Query).
370
371%% TODO: Support multiple trace modules
372%-spec trace_filter(Module :: atom(), Query :: 'none' | [tuple()]) -> {ok, any()}.
373trace_filter(Module, Query) when Query == none; Query == [] ->
374    {ok, _} = glc:compile(Module, glc:null(false));
375trace_filter(Module, Query) when is_list(Query) ->
376    {ok, _} = glc:compile(Module, glc_lib:reduce(trace_any(Query))).
377
378validate_trace({Filter, Level, {Destination, ID}}) when is_tuple(Filter); is_list(Filter), is_atom(Level), is_atom(Destination) ->
379    case validate_trace({Filter, Level, Destination}) of
380        {ok, {F, L, D}} ->
381            {ok, {F, L, {D, ID}}};
382        Error ->
383            Error
384    end;
385validate_trace({Filter, Level, Destination}) when is_tuple(Filter); is_list(Filter), is_atom(Level), is_atom(Destination) ->
386    ValidFilter = validate_trace_filter(Filter),
387    try config_to_mask(Level) of
388        _ when not ValidFilter ->
389            {error, invalid_trace};
390        L when is_list(Filter)  ->
391            {ok, {trace_all(Filter), L, Destination}};
392        L ->
393            {ok, {Filter, L, Destination}}
394    catch
395        _:_ ->
396            {error, invalid_level}
397    end;
398validate_trace(_) ->
399    {error, invalid_trace}.
400
401validate_trace_filter(Filter) when is_tuple(Filter), is_atom(element(1, Filter)) =:= false ->
402    false;
403validate_trace_filter(Filter) ->
404        case lists:all(fun({Key, '*'}) when is_atom(Key) -> true;
405                          ({Key, '!'}) when is_atom(Key) -> true;
406                          ({Key, _Value})      when is_atom(Key) -> true;
407                          ({Key, '=', _Value}) when is_atom(Key) -> true;
408                          ({Key, '<', _Value}) when is_atom(Key) -> true;
409                          ({Key, '>', _Value}) when is_atom(Key) -> true;
410                          (_) -> false end, Filter) of
411            true ->
412                true;
413            _ ->
414                false
415        end.
416
417trace_all(Query) ->
418	glc:all(trace_acc(Query)).
419
420trace_any(Query) ->
421	glc:any(Query).
422
423trace_acc(Query) ->
424    trace_acc(Query, []).
425
426trace_acc([], Acc) ->
427	lists:reverse(Acc);
428trace_acc([{Key, '*'}|T], Acc) ->
429	trace_acc(T, [glc:wc(Key)|Acc]);
430trace_acc([{Key, '!'}|T], Acc) ->
431	trace_acc(T, [glc:nf(Key)|Acc]);
432trace_acc([{Key, Val}|T], Acc) ->
433	trace_acc(T, [glc:eq(Key, Val)|Acc]);
434trace_acc([{Key, '=', Val}|T], Acc) ->
435	trace_acc(T, [glc:eq(Key, Val)|Acc]);
436trace_acc([{Key, '>', Val}|T], Acc) ->
437	trace_acc(T, [glc:gt(Key, Val)|Acc]);
438trace_acc([{Key, '<', Val}|T], Acc) ->
439	trace_acc(T, [glc:lt(Key, Val)|Acc]).
440
441
442check_traces(_, _,  [], Acc) ->
443    lists:flatten(Acc);
444check_traces(Attrs, Level, [{_, {mask, FilterLevel}, _}|Flows], Acc) when (Level band FilterLevel) == 0 ->
445    check_traces(Attrs, Level, Flows, Acc);
446check_traces(Attrs, Level, [{Filter, _, _}|Flows], Acc) when length(Attrs) < length(Filter) ->
447    check_traces(Attrs, Level, Flows, Acc);
448check_traces(Attrs, Level, [Flow|Flows], Acc) ->
449    check_traces(Attrs, Level, Flows, [check_trace(Attrs, Flow)|Acc]).
450
451check_trace(Attrs, {Filter, _Level, Dest}) when is_list(Filter) ->
452    check_trace(Attrs, {trace_all(Filter), _Level, Dest});
453
454check_trace(Attrs, {Filter, _Level, Dest}) when is_tuple(Filter) ->
455    Made = gre:make(Attrs, [list]),
456    glc:handle(?DEFAULT_TRACER, Made),
457    Match = glc_lib:matches(Filter, Made),
458    case Match of
459	true ->
460	    Dest;
461	false ->
462	    []
463    end.
464
465-spec is_loggable(lager_msg:lager_msg(), non_neg_integer()|{'mask', non_neg_integer()}, term()) -> boolean().
466is_loggable(Msg, {mask, Mask}, MyName) ->
467    %% using syslog style comparison flags
468    %S = lager_msg:severity_as_int(Msg),
469    %?debugFmt("comparing masks ~.2B and ~.2B -> ~p~n", [S, Mask, S band Mask]),
470    (lager_msg:severity_as_int(Msg) band Mask) /= 0 orelse
471    lists:member(MyName, lager_msg:destinations(Msg));
472is_loggable(Msg ,SeverityThreshold,MyName) ->
473    lager_msg:severity_as_int(Msg) =< SeverityThreshold orelse
474    lists:member(MyName, lager_msg:destinations(Msg)).
475
476i2l(I) when I < 10  -> [$0, $0+I];
477i2l(I)              -> integer_to_list(I).
478i3l(I) when I < 100 -> [$0 | i2l(I)];
479i3l(I)              -> integer_to_list(I).
480
481%% When log_root option is provided, get the real path to a file
482expand_path(RelPath) ->
483    case application:get_env(lager, log_root) of
484        {ok, LogRoot} when is_list(LogRoot) -> % Join relative path
485            %% check if the given RelPath contains LogRoot, if so, do not add
486            %% it again; see gh #304
487            case string:str(filename:dirname(RelPath), LogRoot) of
488                X when X > 0 ->
489                    RelPath;
490                _Zero ->
491                    filename:join(LogRoot, RelPath)
492            end;
493        undefined -> % No log_root given, keep relative path
494            RelPath
495    end.
496
497%% Log rate limit, i.e. high water mark for incoming messages
498
499check_hwm(Shaper = #lager_shaper{hwm = undefined}) ->
500    {true, 0, Shaper};
501check_hwm(Shaper = #lager_shaper{mps = Mps, hwm = Hwm}) when Mps < Hwm ->
502    %% haven't hit high water mark yet, just log it
503    {true, 0, Shaper#lager_shaper{mps=Mps+1}};
504check_hwm(Shaper = #lager_shaper{lasttime = Last, dropped = Drop}) ->
505    %% are we still in the same second?
506    {M, S, _} = Now = os:timestamp(),
507    case Last of
508        {M, S, _} ->
509            %% still in same second, but have exceeded the high water mark
510            NewDrops = discard_messages(Now, 0),
511            {false, 0, Shaper#lager_shaper{dropped=Drop+NewDrops}};
512        _ ->
513            %% different second, reset all counters and allow it
514            {true, Drop, Shaper#lager_shaper{dropped = 0, mps=1, lasttime = Now}}
515    end.
516
517discard_messages(Second, Count) ->
518    {M, S, _} = os:timestamp(),
519    case Second of
520        {M, S, _} ->
521            receive
522                %% we only discard gen_event notifications, because
523                %% otherwise we might discard gen_event internal
524                %% messages, such as trapped EXITs
525                {notify, _Event} ->
526                    discard_messages(Second, Count+1)
527            after 0 ->
528                    Count
529            end;
530        _ ->
531            Count
532    end.
533
534%% @private Build an atom for the gen_event process based on a sink name.
535%% For historical reasons, the default gen_event process for lager itself is named
536%% `lager_event'. For all other sinks, it is SinkName++`_lager_event'
537make_internal_sink_name(lager) ->
538    ?DEFAULT_SINK;
539make_internal_sink_name(Sink) ->
540    list_to_atom(atom_to_list(Sink) ++ "_lager_event").
541
542-ifdef(TEST).
543
544parse_test() ->
545    ?assertEqual({ok, [{hour, 0}]}, parse_rotation_date_spec("$D0")),
546    ?assertEqual({ok, [{hour, 23}]}, parse_rotation_date_spec("$D23")),
547    ?assertEqual({ok, [{day, 0}, {hour, 23}]}, parse_rotation_date_spec("$W0D23")),
548    ?assertEqual({ok, [{day, 5}, {hour, 16}]}, parse_rotation_date_spec("$W5D16")),
549    ?assertEqual({ok, [{date, 1}, {hour, 0}]}, parse_rotation_date_spec("$M1D0")),
550    ?assertEqual({ok, [{date, 5}, {hour, 6}]}, parse_rotation_date_spec("$M5D6")),
551    ?assertEqual({ok, [{date, 5}, {hour, 0}]}, parse_rotation_date_spec("$M5")),
552    ?assertEqual({ok, [{date, 31}, {hour, 0}]}, parse_rotation_date_spec("$M31")),
553    ?assertEqual({ok, [{date, 31}, {hour, 1}]}, parse_rotation_date_spec("$M31D1")),
554    ?assertEqual({ok, [{date, last}, {hour, 0}]}, parse_rotation_date_spec("$ML")),
555    ?assertEqual({ok, [{date, last}, {hour, 0}]}, parse_rotation_date_spec("$Ml")),
556    ?assertEqual({ok, [{day, 5}, {hour, 0}]}, parse_rotation_date_spec("$W5")),
557    ok.
558
559parse_fail_test() ->
560    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D")),
561    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D24")),
562    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$W7")),
563    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$W7D1")),
564    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M32")),
565    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M32D1")),
566    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$")),
567    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("")),
568    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D15M5")),
569    ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M5W5")),
570    ok.
571
572rotation_calculation_test() ->
573    ?assertMatch({{2000, 1, 2}, {0, 0, 0}},
574        calculate_next_rotation([{hour, 0}], {{2000, 1, 1}, {12, 34, 43}})),
575    ?assertMatch({{2000, 1, 1}, {16, 0, 0}},
576        calculate_next_rotation([{hour, 16}], {{2000, 1, 1}, {12, 34, 43}})),
577    ?assertMatch({{2000, 1, 2}, {12, 0, 0}},
578        calculate_next_rotation([{hour, 12}], {{2000, 1, 1}, {12, 34, 43}})),
579    ?assertMatch({{2000, 2, 1}, {12, 0, 0}},
580        calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 1}, {12, 34, 43}})),
581    ?assertMatch({{2000, 2, 1}, {12, 0, 0}},
582        calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 15}, {12, 34, 43}})),
583    ?assertMatch({{2000, 2, 1}, {12, 0, 0}},
584        calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 2}, {12, 34, 43}})),
585    ?assertMatch({{2000, 2, 1}, {12, 0, 0}},
586        calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 31}, {12, 34, 43}})),
587    ?assertMatch({{2000, 1, 1}, {16, 0, 0}},
588        calculate_next_rotation([{date, 1}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})),
589    ?assertMatch({{2000, 1, 15}, {16, 0, 0}},
590        calculate_next_rotation([{date, 15}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})),
591    ?assertMatch({{2000, 1, 31}, {16, 0, 0}},
592        calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})),
593    ?assertMatch({{2000, 1, 31}, {16, 0, 0}},
594        calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 31}, {12, 34, 43}})),
595    ?assertMatch({{2000, 2, 29}, {16, 0, 0}},
596        calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 31}, {17, 34, 43}})),
597    ?assertMatch({{2001, 2, 28}, {16, 0, 0}},
598        calculate_next_rotation([{date, last}, {hour, 16}], {{2001, 1, 31}, {17, 34, 43}})),
599
600    ?assertMatch({{2000, 1, 1}, {16, 0, 0}},
601        calculate_next_rotation([{day, 6}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})),
602    ?assertMatch({{2000, 1, 8}, {16, 0, 0}},
603        calculate_next_rotation([{day, 6}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})),
604    ?assertMatch({{2000, 1, 7}, {16, 0, 0}},
605        calculate_next_rotation([{day, 5}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})),
606    ?assertMatch({{2000, 1, 3}, {16, 0, 0}},
607        calculate_next_rotation([{day, 1}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})),
608    ?assertMatch({{2000, 1, 2}, {16, 0, 0}},
609        calculate_next_rotation([{day, 0}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})),
610    ?assertMatch({{2000, 1, 9}, {16, 0, 0}},
611        calculate_next_rotation([{day, 0}, {hour, 16}], {{2000, 1, 2}, {17, 34, 43}})),
612    ?assertMatch({{2000, 2, 3}, {16, 0, 0}},
613        calculate_next_rotation([{day, 4}, {hour, 16}], {{2000, 1, 29}, {17, 34, 43}})),
614
615    ?assertMatch({{2000, 1, 7}, {16, 0, 0}},
616        calculate_next_rotation([{day, 5}, {hour, 16}], {{2000, 1, 3}, {17, 34, 43}})),
617
618    ?assertMatch({{2000, 1, 3}, {16, 0, 0}},
619        calculate_next_rotation([{day, 1}, {hour, 16}], {{1999, 12, 28}, {17, 34, 43}})),
620    ok.
621
622rotate_file_test() ->
623    file:delete("rotation.log"),
624    [file:delete(["rotation.log.", integer_to_list(N)]) || N <- lists:seq(0, 9)],
625    [begin
626                file:write_file("rotation.log", integer_to_list(N)),
627                Count = case N > 10 of
628                    true -> 10;
629                    _ -> N
630                end,
631                [begin
632                            FileName = ["rotation.log.", integer_to_list(M)],
633                            ?assert(filelib:is_regular(FileName)),
634                            %% check the expected value is in the file
635                            Number = list_to_binary(integer_to_list(N - M - 1)),
636                            ?assertEqual({ok, Number}, file:read_file(FileName))
637                end
638                || M <- lists:seq(0, Count-1)],
639                rotate_logfile("rotation.log", 10)
640    end || N <- lists:seq(0, 20)].
641
642rotate_file_fail_test() ->
643    %% make sure the directory exists
644    ?assertEqual(ok, filelib:ensure_dir("rotation/rotation.log")),
645    %% fix the permissions on it
646    os:cmd("chown -R u+rwx rotation"),
647    %% delete any old files
648    [ok = file:delete(F) || F <- filelib:wildcard("rotation/*")],
649    %% write a file
650    file:write_file("rotation/rotation.log", "hello"),
651    %% hose up the permissions
652    os:cmd("chown u-w rotation"),
653    ?assertMatch({error, _}, rotate_logfile("rotation.log", 10)),
654    ?assert(filelib:is_regular("rotation/rotation.log")),
655    os:cmd("chown u+w rotation"),
656    ?assertMatch(ok, rotate_logfile("rotation/rotation.log", 10)),
657    ?assert(filelib:is_regular("rotation/rotation.log.0")),
658    ?assertEqual(false, filelib:is_regular("rotation/rotation.log")),
659    ok.
660
661check_trace_test() ->
662    lager:start(),
663    trace_filter(none),
664    %% match by module
665    ?assertEqual([foo], check_traces([{module, ?MODULE}], ?EMERGENCY, [
666                {[{module, ?MODULE}], config_to_mask(emergency), foo},
667                {[{module, test}], config_to_mask(emergency), bar}], [])),
668    %% match by module, but other unsatisfyable attribute
669    ?assertEqual([], check_traces([{module, ?MODULE}], ?EMERGENCY, [
670                {[{module, ?MODULE}, {foo, bar}], config_to_mask(emergency), foo},
671                {[{module, test}], config_to_mask(emergency), bar}], [])),
672    %% match by wildcard module
673    ?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
674                {[{module, ?MODULE}, {foo, bar}], config_to_mask(emergency), foo},
675                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
676    %% wildcard module, one trace with unsatisfyable attribute
677    ?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
678                {[{module, '*'}, {foo, bar}], config_to_mask(emergency), foo},
679                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
680    %% wildcard but not present custom trace attribute
681    ?assertEqual([bar], check_traces([{module, ?MODULE}], ?EMERGENCY, [
682                {[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
683                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
684    %% wildcarding a custom attribute works when it is present
685    ?assertEqual([bar, foo], check_traces([{module, ?MODULE}, {foo, bar}], ?EMERGENCY, [
686                {[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
687                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
688    %% denied by level
689    ?assertEqual([], check_traces([{module, ?MODULE}, {foo, bar}], ?INFO, [
690                {[{module, '*'}, {foo, '*'}], config_to_mask(emergency), foo},
691                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
692    %% allowed by level
693    ?assertEqual([foo], check_traces([{module, ?MODULE}, {foo, bar}], ?INFO, [
694                {[{module, '*'}, {foo, '*'}], config_to_mask(debug), foo},
695                {[{module, '*'}], config_to_mask(emergency), bar}], [])),
696    ?assertEqual([anythingbutnotice, infoandbelow, infoonly], check_traces([{module, ?MODULE}], ?INFO, [
697                {[{module, '*'}], config_to_mask('=debug'), debugonly},
698                {[{module, '*'}], config_to_mask('=info'), infoonly},
699                {[{module, '*'}], config_to_mask('<=info'), infoandbelow},
700                {[{module, '*'}], config_to_mask('!=info'), anythingbutinfo},
701                {[{module, '*'}], config_to_mask('!=notice'), anythingbutnotice}
702                ], [])),
703    application:stop(lager),
704    application:stop(goldrush),
705    ok.
706
707is_loggable_test_() ->
708    [
709        {"Loggable by severity only", ?_assert(is_loggable(lager_msg:new("", alert, [], []),2,me))},
710        {"Not loggable by severity only", ?_assertNot(is_loggable(lager_msg:new("", critical, [], []),1,me))},
711        {"Loggable by severity with destination", ?_assert(is_loggable(lager_msg:new("", alert, [], [you]),2,me))},
712        {"Not loggable by severity with destination", ?_assertNot(is_loggable(lager_msg:new("", critical, [], [you]),1,me))},
713        {"Loggable by destination overriding severity", ?_assert(is_loggable(lager_msg:new("", critical, [], [me]),1,me))}
714    ].
715
716format_time_test_() ->
717    [
718        ?_assertEqual("2012-10-04 11:16:23.002",
719            begin
720                {D, T} = format_time({{2012,10,04},{11,16,23,2}}),
721                lists:flatten([D,$ ,T])
722            end),
723        ?_assertEqual("2012-10-04 11:16:23.999",
724            begin
725                {D, T} = format_time({{2012,10,04},{11,16,23,999}}),
726                lists:flatten([D,$ ,T])
727            end),
728        ?_assertEqual("2012-10-04 11:16:23",
729            begin
730                {D, T} = format_time({{2012,10,04},{11,16,23}}),
731                lists:flatten([D,$ ,T])
732            end),
733        ?_assertEqual("2012-10-04 00:16:23.092 UTC",
734            begin
735                {D, T} = format_time({utc, {{2012,10,04},{0,16,23,92}}}),
736                lists:flatten([D,$ ,T])
737            end),
738        ?_assertEqual("2012-10-04 11:16:23 UTC",
739            begin
740                {D, T} = format_time({utc, {{2012,10,04},{11,16,23}}}),
741                lists:flatten([D,$ ,T])
742            end)
743    ].
744
745config_to_levels_test() ->
746    ?assertEqual([none], config_to_levels('none')),
747    ?assertEqual({mask, 0}, config_to_mask('none')),
748    ?assertEqual([debug], config_to_levels('=debug')),
749    ?assertEqual([debug], config_to_levels('<info')),
750    ?assertEqual(levels() -- [debug], config_to_levels('!=debug')),
751    ?assertEqual(levels() -- [debug], config_to_levels('>debug')),
752    ?assertEqual(levels() -- [debug], config_to_levels('>=info')),
753    ?assertEqual(levels() -- [debug], config_to_levels('=>info')),
754    ?assertEqual([debug, info, notice], config_to_levels('<=notice')),
755    ?assertEqual([debug, info, notice], config_to_levels('=<notice')),
756    ?assertEqual([debug], config_to_levels('<info')),
757    ?assertEqual([debug], config_to_levels('!info')),
758    ?assertError(badarg, config_to_levels(ok)),
759    ?assertError(badarg, config_to_levels('<=>info')),
760    ?assertError(badarg, config_to_levels('=<=info')),
761    ?assertError(badarg, config_to_levels('<==>=<=>info')),
762    %% double negatives DO work, however
763    ?assertEqual([debug], config_to_levels('!!=debug')),
764    ?assertEqual(levels() -- [debug], config_to_levels('!!!=debug')),
765    ok.
766
767config_to_mask_test() ->
768    ?assertEqual({mask, 0}, config_to_mask('none')),
769    ?assertEqual({mask, ?DEBUG bor ?INFO bor ?NOTICE bor ?WARNING bor ?ERROR bor ?CRITICAL bor ?ALERT bor ?EMERGENCY}, config_to_mask('debug')),
770    ?assertEqual({mask, ?WARNING bor ?ERROR bor ?CRITICAL bor ?ALERT bor ?EMERGENCY}, config_to_mask('warning')),
771    ?assertEqual({mask, ?DEBUG bor ?NOTICE bor ?WARNING bor ?ERROR bor ?CRITICAL bor ?ALERT bor ?EMERGENCY}, config_to_mask('!=info')),
772    ok.
773
774mask_to_levels_test() ->
775    ?assertEqual([], mask_to_levels(0)),
776    ?assertEqual([debug], mask_to_levels(2#10000000)),
777    ?assertEqual([debug, info], mask_to_levels(2#11000000)),
778    ?assertEqual([debug, info, emergency], mask_to_levels(2#11000001)),
779    ?assertEqual([debug, notice, error], mask_to_levels(?DEBUG bor ?NOTICE bor ?ERROR)),
780    ok.
781
782expand_path_test() ->
783    OldRootVal = application:get_env(lager, log_root),
784
785    ok = application:unset_env(lager, log_root),
786    ?assertEqual("/foo/bar", expand_path("/foo/bar")),
787    ?assertEqual("foo/bar", expand_path("foo/bar")),
788
789    ok = application:set_env(lager, log_root, "log/dir"),
790    ?assertEqual("/foo/bar", expand_path("/foo/bar")), % Absolute path should not be changed
791    ?assertEqual("log/dir/foo/bar", expand_path("foo/bar")),
792    ?assertEqual("log/dir/foo/bar", expand_path("log/dir/foo/bar")), %% gh #304
793
794    case OldRootVal of
795        undefined -> application:unset_env(lager, log_root);
796        {ok, Root} -> application:set_env(lager, log_root, Root)
797    end,
798    ok.
799
800sink_name_test_() ->
801    [
802        ?_assertEqual(lager_event, make_internal_sink_name(lager)),
803        ?_assertEqual(audit_lager_event, make_internal_sink_name(audit))
804    ].
805
806-endif.
807