diff --git a/README.md b/README.md index 5858a8f5..3fa98a06 100644 --- a/README.md +++ b/README.md @@ -521,14 +521,59 @@ Some examples: 6:00 hr ``` +On top of the day, week and month time format from newsyslog, +hour specification is added from PR [#420](https://github.com/erlang-lager/lager/pull/420) + +``` +Format of hour specification is : [Hmm] +The range for minute specification is: + + mm minutes, range 0 ... 59 + +Some examples: + + $H00 rotate every hour at HH:00 + $D12H30 rotate every day at 12:30 + $W0D0H0 rotate every week on Sunday at 00:00 +``` + To configure the crash log rotation, the following application variables are used: * `crash_log_size` * `crash_log_date` * `crash_log_count` +* `crash_log_rotator` See the `.app.src` file for further details. +Custom Log Rotation +------------------- +Custom log rotator could be configured with option for `lager_file_backend` +```erlang +{rotator, lager_rotator_default} +``` + +The module should provide the following callbacks as `lager_rotator_behaviour` + +```erlang +%% @doc Create a log file +-callback(create_logfile(Name::list(), Buffer::{integer(), integer()} | any()) -> + {ok, {FD::file:io_device(), Inode::integer(), Size::integer()}} | {error, any()}). + +%% @doc Open a log file +-callback(open_logfile(Name::list(), Buffer::{integer(), integer()} | any()) -> + {ok, {FD::file:io_device(), Inode::integer(), Size::integer()}} | {error, any()}). + +%% @doc Ensure reference to current target, could be rotated +-callback(ensure_logfile(Name::list(), FD::file:io_device(), Inode::integer(), + Buffer::{integer(), integer()} | any()) -> + {ok, {FD::file:io_device(), Inode::integer(), Size::integer()}} | {error, any()}). + +%% @doc Rotate the log file +-callback(rotate_logfile(Name::list(), Count::integer()) -> + ok). +``` + Syslog Support -------------- Lager syslog output is provided as a separate application: diff --git a/src/lager.app.src b/src/lager.app.src index bd476a6e..29142e15 100644 --- a/src/lager.app.src +++ b/src/lager.app.src @@ -43,6 +43,8 @@ %% Number of rotated crash logs to keep, 0 means keep only the %% current one - default is 0 {crash_log_count, 5}, + %% Crash Log Rotator Module - default is lager_rotator_default + {crash_log_rotator, lager_rotator_default}, %% Whether to redirect error_logger messages into the default lager_event sink - defaults to true {error_logger_redirect, true}, %% How many messages per second to allow from error_logger before we start dropping them diff --git a/src/lager_crash_log.erl b/src/lager_crash_log.erl index 67289cc6..b40644b4 100644 --- a/src/lager_crash_log.erl +++ b/src/lager_crash_log.erl @@ -46,7 +46,7 @@ -export([init/1, handle_call/3, handle_cast/2, handle_info/2, terminate/2, code_change/3]). --export([start_link/5, start/5]). +-export([start_link/6, start/6]). -record(state, { name :: string(), @@ -56,32 +56,34 @@ size :: integer(), date :: undefined | string(), count :: integer(), - flap=false :: boolean() + flap=false :: boolean(), + rotator :: atom() }). %% @private -start_link(Filename, MaxBytes, Size, Date, Count) -> +start_link(Filename, MaxBytes, Size, Date, Count, Rotator) -> gen_server:start_link({local, ?MODULE}, ?MODULE, [Filename, MaxBytes, - Size, Date, Count], []). + Size, Date, Count, Rotator], []). %% @private -start(Filename, MaxBytes, Size, Date, Count) -> +start(Filename, MaxBytes, Size, Date, Count, Rotator) -> gen_server:start({local, ?MODULE}, ?MODULE, [Filename, MaxBytes, Size, - Date, Count], []). + Date, Count, Rotator], []). %% @private -init([RelFilename, MaxBytes, Size, Date, Count]) -> +init([RelFilename, MaxBytes, Size, Date, Count, Rotator]) -> Filename = lager_util:expand_path(RelFilename), - case lager_util:open_logfile(Filename, false) of + case Rotator:open_logfile(Filename, false) of {ok, {FD, Inode, _}} -> schedule_rotation(Date), {ok, #state{name=Filename, fd=FD, inode=Inode, - fmtmaxbytes=MaxBytes, size=Size, count=Count, date=Date}}; + fmtmaxbytes=MaxBytes, size=Size, count=Count, date=Date, + rotator=Rotator}}; {error, Reason} -> ?INT_LOG(error, "Failed to open crash log file ~s with error: ~s", [Filename, file:format_error(Reason)]), {ok, #state{name=Filename, fmtmaxbytes=MaxBytes, flap=true, - size=Size, count=Count, date=Date}} + size=Size, count=Count, date=Date, rotator=Rotator}} end. %% @private @@ -99,8 +101,8 @@ handle_cast(_Request, State) -> {noreply, State}. %% @private -handle_info(rotate, #state{name=Name, count=Count, date=Date} = State) -> - _ = lager_util:rotate_logfile(Name, Count), +handle_info(rotate, #state{name=Name, count=Count, date=Date, rotator=Rotator} = State) -> + _ = Rotator:rotate_logfile(Name, Count), schedule_rotation(Date), {noreply, State}; handle_info(_Info, State) -> @@ -187,7 +189,7 @@ sasl_limited_str(crash_report, Report, FmtMaxBytes) -> lager_stdlib:proc_lib_format(Report, FmtMaxBytes). do_log({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, - fmtmaxbytes=FmtMaxBytes, size=RotSize, count=Count} = State) -> + fmtmaxbytes=FmtMaxBytes, size=RotSize, count=Count, rotator=Rotator} = State) -> %% borrowed from riak_err {ReportStr, Pid, MsgStr, _ErrorP} = case Event of {error, _GL, {Pid1, Fmt, Args}} -> @@ -202,9 +204,9 @@ do_log({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, if ReportStr == ignore -> {ok, State}; true -> - case lager_util:ensure_logfile(Name, FD, Inode, false) of + case Rotator:ensure_logfile(Name, FD, Inode, false) of {ok, {_, _, Size}} when RotSize /= 0, Size > RotSize -> - _ = lager_util:rotate_logfile(Name, Count), + _ = Rotator:rotate_logfile(Name, Count), handle_cast({log, Event}, State); {ok, {NewFD, NewInode, _Size}} -> {Date, TS} = lager_util:format_time( @@ -268,7 +270,7 @@ filesystem_test_() -> fun(CrashLog) -> {"under normal circumstances, file should be opened", fun() -> - {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0), + {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default), _ = gen_event:which_handlers(error_logger), sync_error_logger:error_msg("Test message\n"), {ok, Bin} = file:read_file(CrashLog), @@ -280,7 +282,7 @@ filesystem_test_() -> fun() -> {ok, FInfo} = file:read_file_info(CrashLog), file:write_file_info(CrashLog, FInfo#file_info{mode = 0}), - {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0), + {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default), ?assertEqual(1, lager_test_backend:count()), {_Level, _Time, Message,_Metadata} = lager_test_backend:pop(), ?assertEqual( @@ -291,7 +293,7 @@ filesystem_test_() -> fun(CrashLog) -> {"file that becomes unavailable at runtime should trigger an error message", fun() -> - {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0), + {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default), ?assertEqual(0, lager_test_backend:count()), sync_error_logger:error_msg("Test message\n"), _ = gen_event:which_handlers(error_logger), @@ -316,7 +318,7 @@ filesystem_test_() -> {ok, FInfo} = file:read_file_info(CrashLog), OldPerms = FInfo#file_info.mode, file:write_file_info(CrashLog, FInfo#file_info{mode = 0}), - {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0), + {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default), ?assertEqual(1, lager_test_backend:count()), {_Level, _Time, Message,_Metadata} = lager_test_backend:pop(), ?assertEqual( @@ -332,7 +334,7 @@ filesystem_test_() -> fun(CrashLog) -> {"external logfile rotation/deletion should be handled", fun() -> - {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0), + {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default), ?assertEqual(0, lager_test_backend:count()), sync_error_logger:error_msg("Test message~n"), _ = gen_event:which_handlers(error_logger), diff --git a/src/lager_file_backend.erl b/src/lager_file_backend.erl index 1537b31d..a99c454a 100644 --- a/src/lager_file_backend.erl +++ b/src/lager_file_backend.erl @@ -53,6 +53,7 @@ -define(DEFAULT_ROTATION_SIZE, 10485760). %% 10mb -define(DEFAULT_ROTATION_DATE, "$D0"). %% midnight -define(DEFAULT_ROTATION_COUNT, 5). +-define(DEFAULT_ROTATION_MOD, lager_rotator_default). -define(DEFAULT_SYNC_LEVEL, error). -define(DEFAULT_SYNC_INTERVAL, 1000). -define(DEFAULT_SYNC_SIZE, 1024*64). %% 64kb @@ -67,6 +68,7 @@ size = 0 :: integer(), date :: undefined | string(), count = 10 :: integer(), + rotator = lager_util :: atom(), shaper :: lager_shaper(), formatter :: atom(), formatter_config :: any(), @@ -79,7 +81,8 @@ -type option() :: {file, string()} | {level, lager:log_level()} | {size, non_neg_integer()} | {date, string()} | - {count, non_neg_integer()} | {high_water_mark, non_neg_integer()} | + {count, non_neg_integer()} | {rotator, atom()} | + {high_water_mark, non_neg_integer()} | {sync_interval, non_neg_integer()} | {sync_size, non_neg_integer()} | {sync_on, lager:log_level()} | {check_interval, non_neg_integer()} | {formatter, atom()} | @@ -108,16 +111,16 @@ init(LogFileConfig) when is_list(LogFileConfig) -> {error, {fatal, bad_config}}; Config -> %% probabably a better way to do this, but whatever - [RelName, Level, Date, Size, Count, HighWaterMark, Flush, SyncInterval, SyncSize, SyncOn, CheckInterval, Formatter, FormatterConfig] = - [proplists:get_value(Key, Config) || Key <- [file, level, date, size, count, high_water_mark, flush_queue, sync_interval, sync_size, sync_on, check_interval, formatter, formatter_config]], + [RelName, Level, Date, Size, Count, Rotator, HighWaterMark, Flush, SyncInterval, SyncSize, SyncOn, CheckInterval, Formatter, FormatterConfig] = + [proplists:get_value(Key, Config) || Key <- [file, level, date, size, count, rotator, high_water_mark, flush_queue, sync_interval, sync_size, sync_on, check_interval, formatter, formatter_config]], FlushThr = proplists:get_value(flush_threshold, Config, 0), Name = lager_util:expand_path(RelName), schedule_rotation(Name, Date), Shaper = lager_util:maybe_flush(Flush, #lager_shaper{hwm=HighWaterMark, flush_threshold = FlushThr, id=Name}), - State0 = #state{name=Name, level=Level, size=Size, date=Date, count=Count, shaper=Shaper, formatter=Formatter, - formatter_config=FormatterConfig, sync_on=SyncOn, sync_interval=SyncInterval, sync_size=SyncSize, - check_interval=CheckInterval}, - State = case lager_util:open_logfile(Name, {SyncSize, SyncInterval}) of + State0 = #state{name=Name, level=Level, size=Size, date=Date, count=Count, rotator=Rotator, + shaper=Shaper, formatter=Formatter, formatter_config=FormatterConfig, + sync_on=SyncOn, sync_interval=SyncInterval, sync_size=SyncSize, check_interval=CheckInterval}, + State = case Rotator:create_logfile(Name, {SyncSize, SyncInterval}) of {ok, {FD, Inode, _}} -> State0#state{fd=FD, inode=Inode}; {error, Reason} -> @@ -184,8 +187,8 @@ handle_event(_Event, State) -> {ok, State}. %% @private -handle_info({rotate, File}, #state{name=File,count=Count,date=Date} = State) -> - _ = lager_util:rotate_logfile(File, Count), +handle_info({rotate, File}, #state{name=File,count=Count,date=Date,rotator=Rotator} = State) -> + _ = Rotator:rotate_logfile(File, Count), State1 = close_file(State), schedule_rotation(File, Date), {ok, State1}; @@ -229,14 +232,14 @@ config_to_id(Config) -> write(#state{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize, - count=Count} = State, Timestamp, Level, Msg) -> + count=Count, rotator=Rotator} = State, Timestamp, Level, Msg) -> LastCheck = timer:now_diff(Timestamp, State#state.last_check) div 1000, case LastCheck >= State#state.check_interval orelse FD == undefined of true -> %% need to check for rotation - case lager_util:ensure_logfile(Name, FD, Inode, {State#state.sync_size, State#state.sync_interval}) of + case Rotator:ensure_logfile(Name, FD, Inode, {State#state.sync_size, State#state.sync_interval}) of {ok, {_, _, Size}} when RotSize /= 0, Size > RotSize -> - case lager_util:rotate_logfile(Name, Count) of + case Rotator:rotate_logfile(Name, Count) of ok -> %% go around the loop again, we'll do another rotation check and hit the next clause of ensure_logfile write(State, Timestamp, Level, Msg); @@ -309,6 +312,7 @@ validate_logfile_proplist(List) -> lists:keymerge(1, lists:sort(Res), lists:sort([ {level, validate_loglevel(?DEFAULT_LOG_LEVEL)}, {date, DefaultRotationDate}, {size, ?DEFAULT_ROTATION_SIZE}, {count, ?DEFAULT_ROTATION_COUNT}, + {rotator, ?DEFAULT_ROTATION_MOD}, {sync_on, validate_loglevel(?DEFAULT_SYNC_LEVEL)}, {sync_interval, ?DEFAULT_SYNC_INTERVAL}, {sync_size, ?DEFAULT_SYNC_SIZE}, {check_interval, ?DEFAULT_CHECK_INTERVAL}, {formatter, lager_default_formatter}, {formatter_config, []} @@ -347,6 +351,13 @@ validate_logfile_proplist([{count, Count}|Tail], Acc) -> _ -> throw({bad_config, "Invalid rotation count", Count}) end; +validate_logfile_proplist([{rotator, Rotator}|Tail], Acc) -> + case is_atom(Rotator) of + true -> + validate_logfile_proplist(Tail, [{rotator, Rotator}|Acc]); + false -> + throw({bad_config, "Invalid rotation module", Rotator}) + end; validate_logfile_proplist([{high_water_mark, HighWaterMark}|Tail], Acc) -> case HighWaterMark of Hwm when is_integer(Hwm), Hwm >= 0 -> @@ -441,24 +452,26 @@ rotation_test_() -> SyncLevel = validate_loglevel(?DEFAULT_SYNC_LEVEL), SyncSize = ?DEFAULT_SYNC_SIZE, SyncInterval = ?DEFAULT_SYNC_INTERVAL, + Rotator = ?DEFAULT_ROTATION_MOD, CheckInterval = 0, %% hard to test delayed mode TestDir = lager_util:create_test_dir(), TestLog = filename:join(TestDir, "test.log"), #state{name=TestLog, level=?DEBUG, sync_on=SyncLevel, - sync_size=SyncSize, sync_interval=SyncInterval, check_interval=CheckInterval} + sync_size=SyncSize, sync_interval=SyncInterval, check_interval=CheckInterval, + rotator=Rotator} end, fun(#state{name=TestLog}) -> lager_util:delete_test_dir(filename:dirname(TestLog)) end, [ - fun(DefaultState = #state{name=TestLog, sync_size=SyncSize, sync_interval = SyncInterval}) -> + fun(DefaultState = #state{name=TestLog, sync_size=SyncSize, sync_interval = SyncInterval, rotator = Rotator}) -> {"External rotation should work", fun() -> - {ok, {FD, Inode, _}} = lager_util:open_logfile(TestLog, {SyncSize, SyncInterval}), + {ok, {FD, Inode, _}} = Rotator:open_logfile(TestLog, {SyncSize, SyncInterval}), State0 = DefaultState#state{fd=FD, inode=Inode}, ?assertMatch(#state{name=TestLog, level=?DEBUG, fd=FD, inode=Inode}, - write(State0, os:timestamp(), ?DEBUG, "hello world")), + write(State0, os:timestamp(), ?DEBUG, "hello world")), file:delete(TestLog), Result = write(State0, os:timestamp(), ?DEBUG, "hello world"), %% assert file has changed @@ -472,7 +485,7 @@ rotation_test_() -> ok end} end, - fun(DefaultState = #state{name=TestLog, sync_size=SyncSize, sync_interval = SyncInterval}) -> + fun(DefaultState = #state{name=TestLog, sync_size=SyncSize, sync_interval = SyncInterval, rotator = Rotator}) -> {"Internal rotation and delayed write", fun() -> TestLog0 = TestLog ++ ".0", @@ -480,7 +493,7 @@ rotation_test_() -> RotationSize = 15, PreviousCheck = os:timestamp(), - {ok, {FD, Inode, _}} = lager_util:open_logfile(TestLog, {SyncSize, SyncInterval}), + {ok, {FD, Inode, _}} = Rotator:open_logfile(TestLog, {SyncSize, SyncInterval}), State0 = DefaultState#state{ fd=FD, inode=Inode, size=RotationSize, check_interval=CheckInterval, last_check=PreviousCheck}, diff --git a/src/lager_rotator_behaviour.erl b/src/lager_rotator_behaviour.erl new file mode 100644 index 00000000..645cefb7 --- /dev/null +++ b/src/lager_rotator_behaviour.erl @@ -0,0 +1,18 @@ +-module(lager_rotator_behaviour). + +%% @doc Create a log file +-callback(create_logfile(Name::list(), Buffer::{integer(), integer()} | any()) -> + {ok, {file:io_device(), integer(), integer()}} | {error, any()}). + +%% @doc Open a log file +-callback(open_logfile(Name::list(), Buffer::{integer(), integer()} | any()) -> + {ok, {file:io_device(), integer(), integer()}} | {error, any()}). + +%% @doc Ensure reference to current target, could be rotated +-callback(ensure_logfile(Name::list(), FD::file:io_device(), Inode::integer(), + Buffer::{integer(), integer()} | any()) -> + {ok, {file:io_device(), integer(), integer()}} | {error, any()}). + +%% @doc Rotate the log file +-callback(rotate_logfile(Name::list(), Count::integer()) -> + ok). diff --git a/src/lager_rotator_default.erl b/src/lager_rotator_default.erl new file mode 100644 index 00000000..35d7638a --- /dev/null +++ b/src/lager_rotator_default.erl @@ -0,0 +1,131 @@ +-module(lager_rotator_default). + +-include_lib("kernel/include/file.hrl"). + +-behaviour(lager_rotator_behaviour). + +-export([ + create_logfile/2, open_logfile/2, ensure_logfile/4, rotate_logfile/2 +]). + +-ifdef(TEST). +-include_lib("eunit/include/eunit.hrl"). +-endif. + +create_logfile(Name, Buffer) -> + open_logfile(Name, Buffer). + +open_logfile(Name, Buffer) -> + case filelib:ensure_dir(Name) of + ok -> + Options = [append, raw] ++ + case Buffer of + {Size, Interval} when is_integer(Interval), Interval >= 0, is_integer(Size), Size >= 0 -> + [{delayed_write, Size, Interval}]; + _ -> [] + end, + case file:open(Name, Options) of + {ok, FD} -> + case file:read_file_info(Name) of + {ok, FInfo} -> + Inode = FInfo#file_info.inode, + {ok, {FD, Inode, FInfo#file_info.size}}; + X -> X + end; + Y -> Y + end; + Z -> Z + end. + +ensure_logfile(Name, FD, Inode, Buffer) -> + case file:read_file_info(Name) of + {ok, FInfo} -> + Inode2 = FInfo#file_info.inode, + case Inode == Inode2 of + true -> + {ok, {FD, Inode, FInfo#file_info.size}}; + false -> + %% delayed write can cause file:close not to do a close + _ = file:close(FD), + _ = file:close(FD), + case open_logfile(Name, Buffer) of + {ok, {FD2, Inode3, Size}} -> + %% inode changed, file was probably moved and + %% recreated + {ok, {FD2, Inode3, Size}}; + Error -> + Error + end + end; + _ -> + %% delayed write can cause file:close not to do a close + _ = file:close(FD), + _ = file:close(FD), + case open_logfile(Name, Buffer) of + {ok, {FD2, Inode3, Size}} -> + %% file was removed + {ok, {FD2, Inode3, Size}}; + Error -> + Error + end + end. + +%% renames failing are OK +rotate_logfile(File, 0) -> + file:delete(File); +rotate_logfile(File, 1) -> + case file:rename(File, File++".0") of + ok -> + ok; + _ -> + rotate_logfile(File, 0) + end; +rotate_logfile(File, Count) -> + _ = file:rename(File ++ "." ++ integer_to_list(Count - 2), File ++ "." ++ integer_to_list(Count - 1)), + rotate_logfile(File, Count - 1). + +-ifdef(TEST). + +rotate_file_test() -> + RotCount = 10, + TestDir = lager_util:create_test_dir(), + TestLog = filename:join(TestDir, "rotation.log"), + Outer = fun(N) -> + ?assertEqual(ok, file:write_file(TestLog, erlang:integer_to_list(N))), + Inner = fun(M) -> + File = lists:flatten([TestLog, $., erlang:integer_to_list(M)]), + ?assert(filelib:is_regular(File)), + %% check the expected value is in the file + Number = erlang:list_to_binary(integer_to_list(N - M - 1)), + ?assertEqual({ok, Number}, file:read_file(File)) + end, + Count = erlang:min(N, RotCount), + % The first time through, Count == 0, so the sequence is empty, + % effectively skipping the inner loop so a rotation can occur that + % creates the file that Inner looks for. + % Don't shoot the messenger, it was worse before this refactoring. + lists:foreach(Inner, lists:seq(0, Count-1)), + rotate_logfile(TestLog, RotCount) + end, + lists:foreach(Outer, lists:seq(0, (RotCount * 2))), + lager_util:delete_test_dir(TestDir). + +rotate_file_fail_test() -> + TestDir = lager_util:create_test_dir(), + TestLog = filename:join(TestDir, "rotation.log"), + %% set known permissions on it + os:cmd("chmod -R u+rwx " ++ TestDir), + %% write a file + file:write_file(TestLog, "hello"), + %% hose up the permissions + os:cmd("chmod u-w " ++ TestDir), + ?assertMatch({error, _}, rotate_logfile(TestLog, 10)), + ?assert(filelib:is_regular(TestLog)), + %% fix the permissions + os:cmd("chmod u+w " ++ TestDir), + ?assertMatch(ok, rotate_logfile(TestLog, 10)), + ?assert(filelib:is_regular(TestLog ++ ".0")), + ?assertEqual(false, filelib:is_regular(TestLog)), + lager_util:delete_test_dir(TestDir). + +-endif. diff --git a/src/lager_sup.erl b/src/lager_sup.erl index 57b214b6..adf95ade 100644 --- a/src/lager_sup.erl +++ b/src/lager_sup.erl @@ -69,6 +69,11 @@ determine_rotation_date({ok, Val3}) -> determine_rotation_date(_) -> undefined. +determine_rotator_mod({ok, Mod}, _Default) when is_atom(Mod) -> + Mod; +determine_rotator_mod(_, Default) -> + Default. + decide_crash_log(undefined) -> []; decide_crash_log(false) -> @@ -79,8 +84,9 @@ decide_crash_log(File) -> RotationCount = validate_positive(application:get_env(lager, crash_log_count), 0), RotationDate = determine_rotation_date(application:get_env(lager, crash_log_date)), + RotationMod = determine_rotator_mod(application:get_env(lager, crash_log_rotator), lager_rotator_default), [{lager_crash_log, {lager_crash_log, start_link, [File, MaxBytes, - RotationSize, RotationDate, RotationCount]}, + RotationSize, RotationDate, RotationCount, RotationMod]}, permanent, 5000, worker, [lager_crash_log]}]. diff --git a/src/lager_util.erl b/src/lager_util.erl index ee26ad2c..87729b59 100644 --- a/src/lager_util.erl +++ b/src/lager_util.erl @@ -20,12 +20,10 @@ -module(lager_util). --include_lib("kernel/include/file.hrl"). - -export([ levels/0, level_to_num/1, level_to_chr/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, + format_time/0, format_time/1, localtime_ms/0, localtime_ms/1, maybe_utc/1, parse_rotation_date_spec/1, calculate_next_rotation/1, validate_trace/1, check_traces/4, is_loggable/3, trace_filter/1, trace_filter/2, expand_path/1, find_file/2, check_hwm/1, check_hwm/2, @@ -140,61 +138,6 @@ level_to_atom(String) -> erlang:error(badarg) end. -open_logfile(Name, Buffer) -> - case filelib:ensure_dir(Name) of - ok -> - Options = [append, raw] ++ - case Buffer of - {Size, Interval} when is_integer(Interval), Interval >= 0, is_integer(Size), Size >= 0 -> - [{delayed_write, Size, Interval}]; - _ -> [] - end, - case file:open(Name, Options) of - {ok, FD} -> - case file:read_file_info(Name) of - {ok, FInfo} -> - Inode = FInfo#file_info.inode, - {ok, {FD, Inode, FInfo#file_info.size}}; - X -> X - end; - Y -> Y - end; - Z -> Z - end. - -ensure_logfile(Name, FD, Inode, Buffer) -> - case file:read_file_info(Name) of - {ok, FInfo} -> - Inode2 = FInfo#file_info.inode, - case Inode == Inode2 of - true -> - {ok, {FD, Inode, FInfo#file_info.size}}; - false -> - %% delayed write can cause file:close not to do a close - _ = file:close(FD), - _ = file:close(FD), - case open_logfile(Name, Buffer) of - {ok, {FD2, Inode3, Size}} -> - %% inode changed, file was probably moved and - %% recreated - {ok, {FD2, Inode3, Size}}; - Error -> - Error - end - end; - _ -> - %% delayed write can cause file:close not to do a close - _ = file:close(FD), - _ = file:close(FD), - case open_logfile(Name, Buffer) of - {ok, {FD2, Inode3, Size}} -> - %% file was removed - {ok, {FD2, Inode3, Size}}; - Error -> - Error - end - end. - %% returns localtime with milliseconds included localtime_ms() -> Now = os:timestamp(), @@ -214,20 +157,6 @@ maybe_utc({Date, {H, M, S, Ms}}) -> {Date1, {H1, M1, S1, Ms}} end. -%% renames failing are OK -rotate_logfile(File, 0) -> - file:delete(File); -rotate_logfile(File, 1) -> - case file:rename(File, File++".0") of - ok -> - ok; - _ -> - rotate_logfile(File, 0) - end; -rotate_logfile(File, Count) -> - _ = file:rename(File ++ "." ++ integer_to_list(Count - 2), File ++ "." ++ integer_to_list(Count - 1)), - rotate_logfile(File, Count - 1). - format_time() -> format_time(maybe_utc(localtime_ms())). @@ -244,19 +173,34 @@ format_time({{Y, M, D}, {H, Mi, S}}) -> {[integer_to_list(Y), $-, i2l(M), $-, i2l(D)], [i2l(H), $:, i2l(Mi), $:, i2l(S)]}. +parse_rotation_hour_spec([], Res) -> + {ok, Res}; +parse_rotation_hour_spec([$H, M1, M2], Res) -> + case list_to_integer([M1, M2]) of + X when X >= 0, X =< 59 -> + {ok, Res ++ [{minute, X}]}; + _ -> + {error, invalid_date_spec} + end; +parse_rotation_hour_spec([$H, M], Res) when M >= $0, M =< $9 -> + {ok, Res ++ [{minute, M - 48}]}; +parse_rotation_hour_spec(_,_) -> + {error, invalid_date_spec}. + +%% Default to 00:00:00 rotation parse_rotation_day_spec([], Res) -> - {ok, Res ++ [{hour, 0}]}; -parse_rotation_day_spec([$D, D1, D2], Res) -> + {ok, Res ++ [{hour ,0}]}; +parse_rotation_day_spec([$D, D1, D2|T], Res) -> case list_to_integer([D1, D2]) of X when X >= 0, X =< 23 -> - {ok, Res ++ [{hour, X}]}; + parse_rotation_hour_spec(T, Res ++ [{hour, X}]); _ -> {error, invalid_date_spec} end; -parse_rotation_day_spec([$D, D], Res) when D >= $0, D =< $9 -> - {ok, Res ++ [{hour, D - 48}]}; -parse_rotation_day_spec(_, _) -> - {error, invalid_date_spec}. +parse_rotation_day_spec([$D, D|T], Res) when D >= $0, D =< $9 -> + parse_rotation_hour_spec(T, Res ++ [{hour, D - 48 }]); +parse_rotation_day_spec(X, Res) -> + parse_rotation_hour_spec(X, Res). parse_rotation_date_spec([$$, $W, W|T]) when W >= $0, W =< $6 -> Week = W - 48, @@ -295,6 +239,17 @@ calculate_next_rotation(Spec) -> calculate_next_rotation([], Now) -> Now; +calculate_next_rotation([{minute, X}|T], {{_, _, _}, {Hour, Minute, _}} = Now) when Minute < X -> + %% rotation is this hour + NewNow = setelement(2, Now, {Hour, X, 0}), + calculate_next_rotation(T, NewNow); +calculate_next_rotation([{minute, X}|T], Now) -> + %% rotation is next hour + Seconds = calendar:datetime_to_gregorian_seconds(Now) + 3600, + DateTime = calendar:gregorian_seconds_to_datetime(Seconds), + {_, {NewHour, _, _}} = DateTime, + NewNow = setelement(2, DateTime, {NewHour, X, 0}), + calculate_next_rotation(T, NewNow); calculate_next_rotation([{hour, X}|T], {{_, _, _}, {Hour, _, _}} = Now) when Hour < X -> %% rotation is today, sometime NewNow = setelement(2, Now, {X, 0, 0}), @@ -630,10 +585,13 @@ maybe_flush(Flag, #lager_shaper{} = S) when is_boolean(Flag) -> -ifdef(TEST). parse_test() -> + ?assertEqual({ok, [{minute, 0}]}, parse_rotation_date_spec("$H0")), + ?assertEqual({ok, [{minute, 59}]}, parse_rotation_date_spec("$H59")), ?assertEqual({ok, [{hour, 0}]}, parse_rotation_date_spec("$D0")), ?assertEqual({ok, [{hour, 23}]}, parse_rotation_date_spec("$D23")), ?assertEqual({ok, [{day, 0}, {hour, 23}]}, parse_rotation_date_spec("$W0D23")), ?assertEqual({ok, [{day, 5}, {hour, 16}]}, parse_rotation_date_spec("$W5D16")), + ?assertEqual({ok, [{day, 0}, {hour, 12}, {minute, 30}]}, parse_rotation_date_spec("$W0D12H30")), ?assertEqual({ok, [{date, 1}, {hour, 0}]}, parse_rotation_date_spec("$M1D0")), ?assertEqual({ok, [{date, 5}, {hour, 6}]}, parse_rotation_date_spec("$M5D6")), ?assertEqual({ok, [{date, 5}, {hour, 0}]}, parse_rotation_date_spec("$M5")), @@ -645,6 +603,8 @@ parse_test() -> ok. parse_fail_test() -> + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$H")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$H60")), ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D")), ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D24")), ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$W7")), @@ -658,6 +618,12 @@ parse_fail_test() -> ok. rotation_calculation_test() -> + ?assertMatch({{2000, 1, 1}, {13, 0, 0}}, + calculate_next_rotation([{minute, 0}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 1}, {12, 45, 0}}, + calculate_next_rotation([{minute, 45}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 2}, {0, 0, 0}}, + calculate_next_rotation([{minute, 0}], {{2000, 1, 1}, {23, 45, 43}})), ?assertMatch({{2000, 1, 2}, {0, 0, 0}}, calculate_next_rotation([{hour, 0}], {{2000, 1, 1}, {12, 34, 43}})), ?assertMatch({{2000, 1, 1}, {16, 0, 0}}, @@ -707,48 +673,6 @@ rotation_calculation_test() -> calculate_next_rotation([{day, 1}, {hour, 16}], {{1999, 12, 28}, {17, 34, 43}})), ok. -rotate_file_test() -> - RotCount = 10, - TestDir = create_test_dir(), - TestLog = filename:join(TestDir, "rotation.log"), - Outer = fun(N) -> - ?assertEqual(ok, file:write_file(TestLog, erlang:integer_to_list(N))), - Inner = fun(M) -> - File = lists:flatten([TestLog, $., erlang:integer_to_list(M)]), - ?assert(filelib:is_regular(File)), - %% check the expected value is in the file - Number = erlang:list_to_binary(integer_to_list(N - M - 1)), - ?assertEqual({ok, Number}, file:read_file(File)) - end, - Count = erlang:min(N, RotCount), - % The first time through, Count == 0, so the sequence is empty, - % effectively skipping the inner loop so a rotation can occur that - % creates the file that Inner looks for. - % Don't shoot the messenger, it was worse before this refactoring. - lists:foreach(Inner, lists:seq(0, Count-1)), - rotate_logfile(TestLog, RotCount) - end, - lists:foreach(Outer, lists:seq(0, (RotCount * 2))), - delete_test_dir(TestDir). - -rotate_file_fail_test() -> - TestDir = create_test_dir(), - TestLog = filename:join(TestDir, "rotation.log"), - %% set known permissions on it - os:cmd("chmod -R u+rwx " ++ TestDir), - %% write a file - file:write_file(TestLog, "hello"), - %% hose up the permissions - os:cmd("chmod u-w " ++ TestDir), - ?assertMatch({error, _}, rotate_logfile(TestLog, 10)), - ?assert(filelib:is_regular(TestLog)), - %% fix the permissions - os:cmd("chmod u+w " ++ TestDir), - ?assertMatch(ok, rotate_logfile(TestLog, 10)), - ?assert(filelib:is_regular(TestLog ++ ".0")), - ?assertEqual(false, filelib:is_regular(TestLog)), - delete_test_dir(TestDir). - check_trace_test() -> lager:start(), trace_filter(none),