diff --git a/README.org b/README.org index b76d6b9..16048d1 100644 --- a/README.org +++ b/README.org @@ -53,7 +53,10 @@ {lager, {handlers, [ {lager_console_backend, info}, - {lager_file_backend, [{"error.log", error}, {"console.log", info}]} + {lager_file_backend, [ + {"error.log", error, 10485760, "$D0", 5}, + {"console.log", info, 10485760, "$D0", 5} + ]} ]} }. #+END_EXAMPLE @@ -72,6 +75,9 @@ information. The location of the crash log can be specified by the crash_log application variable. If undefined it is not written at all. + Messages in the crash log are subject to a maximum message size which can be + specified via the crash_log_msg_size application variable. + * Runtime loglevel changes You can change the log level of any lager backend at runtime by doing the following: @@ -91,3 +97,56 @@ log messages, when no backend is consuming debug messages, are effectively free. A simple benchmark of doing 1 million debug log messages while the minimum threshold was above that takes less than half a second. + +* Internal log rotation + Lager can rotate its own logs or have it done via an external process. To + use internal rotation, use the last 3 values in the file backend's + configuration tuple. For example + +#+BEGIN_EXAMPLE + {"error.log", error, 10485760, "$D0", 5} +#+END_EXAMPLE + + This tells lager to log error and above messages to "error.log" and to + rotate the file at midnight or when it reaches 10mb, whichever comes first + and to keep 5 rotated logs, in addition to the current one. Setting the + count to 0 does not disable rotation, it instead rotates the file and keeps + no previous versions around. To disable rotation set the size to 0 and the + date to "". + + The "$D0" syntax is taken from the syntax newsyslog uses in newsyslog.conf. + The relevant extract follows: + +#+BEGIN_EXAMPLE + Day, week and month time format: The lead-in character + for day, week and month specification is a `$'-sign. + The particular format of day, week and month + specification is: [Dhh], [Ww[Dhh]] and [Mdd[Dhh]], + respectively. Optional time fields default to + midnight. The ranges for day and hour specifications + are: + + hh hours, range 0 ... 23 + w day of week, range 0 ... 6, 0 = Sunday + dd day of month, range 1 ... 31, or the + letter L or l to specify the last day of + the month. + + Some examples: + $D0 rotate every night at midnight + $D23 rotate every day at 23:00 hr + $W0D23 rotate every week on Sunday at 23:00 hr + $W5D16 rotate every week on Friday at 16:00 hr + $M1D0 rotate on the first day of every month at + midnight (i.e., the start of the day) + $M5D6 rotate on every 5th day of the month at + 6:00 hr +#+END_EXAMPLE + + To configure the crash log rotation, the following application variables are + used: + - crash_log_size + - crash_log_date + - crash_log_count + + See the .app.src file for further details. diff --git a/src/error_logger_lager_h.erl b/src/error_logger_lager_h.erl index b359ee5..41141e6 100644 --- a/src/error_logger_lager_h.erl +++ b/src/error_logger_lager_h.erl @@ -90,7 +90,9 @@ handle_event(Event, State) -> case lists:sort(D) of [{errorContext, Ctx}, {offender, Off}, {reason, Reason}, {supervisor, Name}] -> Offender = format_offender(Off), - ?LOG(error, Pid, "Supervisor ~w had child ~s exit with reason ~s in context ~w", [element(2, Name), Offender, format_reason(Reason), Ctx]); + ?LOG(error, Pid, + "Supervisor ~w had child ~s exit with reason ~s in context ~w", + [element(2, Name), Offender, format_reason(Reason), Ctx]); _ -> ?LOG(error, Pid, ["SUPERVISOR REPORT ", print_silly_list(D)]) end; @@ -107,7 +109,8 @@ handle_event(Event, State) -> Details = lists:sort(D), case Details of [{application, App}, {exited, Reason}, {type, _Type}] -> - ?LOG(info, Pid, "Application ~w exited with reason: ~w", [App, Reason]); + ?LOG(info, Pid, "Application ~w exited with reason: ~w", + [App, Reason]); _ -> ?LOG(info, Pid, print_silly_list(D)) end; @@ -122,7 +125,8 @@ handle_event(Event, State) -> [{started, Started}, {supervisor, Name}] -> MFA = format_mfa(proplists:get_value(mfargs, Started)), Pid = proplists:get_value(pid, Started), - ?LOG(debug, P, "Supervisor ~w started ~s at pid ~w", [element(2, Name), MFA, Pid]); + ?LOG(debug, P, "Supervisor ~w started ~s at pid ~w", + [element(2, Name), MFA, Pid]); _ -> ?LOG(info, P, ["PROGRESS REPORT ", print_silly_list(D)]) end; @@ -145,21 +149,25 @@ code_change(_OldVsn, State, _Extra) -> format_crash_report(Report, Neighbours) -> Name = proplists:get_value(registered_name, Report, proplists:get_value(pid, Report)), {_Class, Reason, _Trace} = proplists:get_value(error_info, Report), - io_lib:format("Process ~w with ~w neighbours crashed with reason: ~s", [Name, length(Neighbours), format_reason(Reason)]). + io_lib:format("Process ~w with ~w neighbours crashed with reason: ~s", + [Name, length(Neighbours), format_reason(Reason)]). format_offender(Off) -> case proplists:get_value(name, Off) of undefined -> %% supervisor_bridge - io_lib:format("at module ~w at ~w", [proplists:get_value(mod, Off), proplists:get_value(pid, Off)]); + io_lib:format("at module ~w at ~w", + [proplists:get_value(mod, Off), proplists:get_value(pid, Off)]); Name -> %% regular supervisor MFA = format_mfa(proplists:get_value(mfargs, Off)), - io_lib:format("~w started with ~s at ~w", [Name, MFA, proplists:get_value(pid, Off)]) + io_lib:format("~w started with ~s at ~w", + [Name, MFA, proplists:get_value(pid, Off)]) end. format_reason({'function not exported', [{M, F, A},MFA|_]}) -> - ["call to undefined function ", format_mfa({M, F, length(A)}), " from ", format_mfa(MFA)]; + ["call to undefined function ", format_mfa({M, F, length(A)}), + " from ", format_mfa(MFA)]; format_reason({undef, [MFA|_]}) -> ["call to undefined function ", format_mfa(MFA)]; format_reason({bad_return_value, Val}) -> @@ -205,7 +213,8 @@ format_reason({badarg, [MFA,MFA2|_]}) -> end; format_reason({{badarity, {Fun, Args}}, [MFA|_]}) -> {arity, Arity} = lists:keyfind(arity, 1, erlang:fun_info(Fun)), - [io_lib:format("fun called with wrong arity of ~w instead of ~w in ", [length(Args), Arity]), format_mfa(MFA)]; + [io_lib:format("fun called with wrong arity of ~w instead of ~w in ", + [length(Args), Arity]), format_mfa(MFA)]; format_reason({noproc, MFA}) -> ["no such process or port in call to ", format_mfa(MFA)]; format_reason({{badfun, Term}, [MFA|_]}) -> diff --git a/src/lager.app.src b/src/lager.app.src index c3f94bc..d1ad420 100644 --- a/src/lager.app.src +++ b/src/lager.app.src @@ -16,14 +16,23 @@ {handlers, [ {lager_console_backend, info}, {lager_file_backend, [ - {"log/error.log", error}, - {"log/console.log", info} + {"log/error.log", error, 10485760, "$D0", 5}, + {"log/console.log", info, 10485760, "$D0", 5} ]} ]}, %% Whether to write a crash log, and where. Undefined means no crash logger. {crash_log, "log/crash.log"}, %% Maximum size in bytes of events in the crash log - defaults to 65536 - {crash_log_size, 65536}, + {crash_log_msg_size, 65536}, + %% Maximum size of the crash log in bytes, before its rotated, set + %% to 0 to disable rotation - default is 0 + {crash_log_size, 10485760}, + %% What time to rotate the crash log - default is no time + %% rotation. See the README for a description of this format. + {crash_log_date, "$D0"}, + %% Number of rotated crash logs to keep, 0 means keep only the + %% current one - default is 0 + {crash_log_count, 5}, %% Whether to redirect error_logger messages into lager - defaults to true {error_logger_redirect, true} ]} diff --git a/src/lager.erl b/src/lager.erl index f63c0b2..cbd07b7 100644 --- a/src/lager.erl +++ b/src/lager.erl @@ -62,22 +62,25 @@ log(Level, Module, Function, Line, Pid, Time, Message) -> ok | {error, lager_not_running}. log(Level, Module, Function, Line, Pid, Time, Format, Args) -> Timestamp = lager_util:format_time(Time), - Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p@~p:~p:~p ", [Pid, Module, - Function, Line]), string:strip(lists:flatten(io_lib:format(Format, Args)), right, $\n)], + Msg = [["[", atom_to_list(Level), "] "], + io_lib:format("~p@~p:~p:~p ", [Pid, Module, Function, Line]), + string:strip(lists:flatten(io_lib:format(Format, Args)), right, $\n)], safe_notify(lager_util:level_to_num(Level), Timestamp, Msg). %% @doc Manually log a message into lager without using the parse transform. -spec log(log_level(), pid(), list()) -> ok | {error, lager_not_running}. log(Level, Pid, Message) -> Timestamp = lager_util:format_time(), - Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]), string:strip(lists:flatten(Message), right, $\n)], + Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]), + string:strip(lists:flatten(Message), right, $\n)], safe_notify(lager_util:level_to_num(Level), Timestamp, Msg). %% @doc Manually log a message into lager without using the parse transform. -spec log(log_level(), pid(), string(), list()) -> ok | {error, lager_not_running}. log(Level, Pid, Format, Args) -> Timestamp = lager_util:format_time(), - Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]), string:strip(lists:flatten(io_lib:format(Format, Args)), right, $\n)], + Msg = [["[", atom_to_list(Level), "] "], io_lib:format("~p ", [Pid]), + string:strip(lists:flatten(io_lib:format(Format, Args)), right, $\n)], safe_notify(lager_util:level_to_num(Level), Timestamp, Msg). %% @doc Set the loglevel for a particular backend. diff --git a/src/lager_app.erl b/src/lager_app.erl index 3b75c0b..7e1a8ee 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -34,7 +34,8 @@ start(_StartType, _StartArgs) -> Handlers = case application:get_env(lager, handlers) of undefined -> [{lager_console_backend, info}, - {lager_file_backend, [{"log/error.log", error}, {"log/console.log", info}]}]; + {lager_file_backend, [{"log/error.log", error, 10485760, "", 5}, + {"log/console.log", info, 10485760, "", 5}]}]; {ok, Val} -> Val end, diff --git a/src/lager_crash_log.erl b/src/lager_crash_log.erl index 4645149..b1d9677 100644 --- a/src/lager_crash_log.erl +++ b/src/lager_crash_log.erl @@ -16,9 +16,16 @@ %% @doc Lager crash log writer. This module implements a gen_server which writes %% error_logger error messages out to a file in their original format. The -%% location to which it logs is configured by the environment var `crash_log'. +%% location to which it logs is configured by the application var `crash_log'. %% Omitting this variable disables crash logging. Crash logs are printed safely %% using trunc_io via code mostly lifted from riak_err. +%% +%% The `crash_log_msg_size' application var is used to specify the maximum +%% size of any message to be logged. `crash_log_size' is used to specify the +%% maximum size of the crash log before it will be rotated (0 will disable). +%% Time based rotation is configurable via `crash_log_date', the syntax is +%% documented in the README. To control the number of rotated files to be +%% retained, use `crash_log_count'. -module(lager_crash_log). @@ -30,29 +37,36 @@ -export([init/1, handle_call/3, handle_cast/2, handle_info/2, terminate/2, code_change/3]). --export([start_link/2, start/2]). +-export([start_link/5, start/5]). -record(state, { name, fd, inode, fmtmaxbytes, + size, + date, + count, flap=false }). %% @private -start_link(Filename, MaxBytes) -> - gen_server:start_link({local, ?MODULE}, ?MODULE, [Filename, MaxBytes], []). +start_link(Filename, MaxBytes, Size, Date, Count) -> + gen_server:start_link({local, ?MODULE}, ?MODULE, [Filename, MaxBytes, + Size, Date, Count], []). %% @private -start(Filename, MaxBytes) -> - gen_server:start({local, ?MODULE}, ?MODULE, [Filename, MaxBytes], []). +start(Filename, MaxBytes, Size, Date, Count) -> + gen_server:start({local, ?MODULE}, ?MODULE, [Filename, MaxBytes, Size, + Date, Count], []). %% @private -init([Filename, MaxBytes]) -> +init([Filename, MaxBytes, Size, Date, Count]) -> case lager_util:open_logfile(Filename, false) of - {ok, {FD, Inode}} -> - {ok, #state{name=Filename, fd=FD, inode=Inode, fmtmaxbytes=MaxBytes}}; + {ok, {FD, Inode, _}} -> + schedule_rotation(Date), + {ok, #state{name=Filename, fd=FD, inode=Inode, + fmtmaxbytes=MaxBytes, size=Size, count=Count, date=Date}}; Error -> Error end. @@ -62,7 +76,8 @@ handle_call(_Call, _From, State) -> {reply, ok, State}. %% @private -handle_cast({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, fmtmaxbytes=FmtMaxBytes} = State) -> +handle_cast({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, + fmtmaxbytes=FmtMaxBytes, size=RotSize, count=Count} = State) -> %% borrowed from riak_err {ReportStr, Pid, MsgStr, _ErrorP} = case Event of {error, _GL, {Pid1, Fmt, Args}} -> @@ -78,13 +93,19 @@ handle_cast({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, fmtma {noreply, State}; true -> case lager_util:ensure_logfile(Name, FD, Inode, false) of - {ok, {NewFD, NewInode}} -> - {Date, TS} = lager_util:format_time(lager_stdlib:maybe_utc(erlang:localtime())), + {ok, {_, _, Size}} when RotSize /= 0, Size > RotSize -> + lager_util:rotate_logfile(Name, Count), + handle_cast({log, Event}, State); + {ok, {NewFD, NewInode, _Size}} -> + {Date, TS} = lager_util:format_time( + lager_stdlib:maybe_utc(erlang:localtime())), Time = [Date, " ", TS," =", ReportStr, "====\n"], NodeSuffix = other_node_suffix(Pid), - case file:write(NewFD, io_lib:format("~s~s~s", [Time, MsgStr, NodeSuffix])) of + Msg = io_lib:format("~s~s~s", [Time, MsgStr, NodeSuffix]), + case file:write(NewFD, Msg) of {error, Reason} when Flap == false -> - ?INT_LOG(error, "Failed to write log message to file ~s: ~s", [Name, file:format_error(Reason)]), + ?INT_LOG(error, "Failed to write log message to file ~s: ~s", + [Name, file:format_error(Reason)]), {noreply, State#state{fd=NewFD, inode=NewInode, flap=true}}; ok -> {noreply, State#state{fd=NewFD, inode=NewInode, flap=false}}; @@ -96,7 +117,8 @@ handle_cast({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap, fmtma true -> {noreply, State}; _ -> - ?INT_LOG(error, "Failed to reopen logfile ~s with error ~w", [Name, file:format_error(Reason)]), + ?INT_LOG(error, "Failed to reopen logfile ~s with error ~w", + [Name, file:format_error(Reason)]), {noreply, State#state{flap=true}} end end @@ -105,6 +127,10 @@ handle_cast(_Request, State) -> {noreply, State}. %% @private +handle_info(rotate, #state{name=Name, count=Count, date=Date} = State) -> + lager_util:rotate_logfile(Name, Count), + schedule_rotation(Date), + {noreply, State}; handle_info(_Info, State) -> {noreply, State}. @@ -116,6 +142,11 @@ terminate(_Reason, _State) -> code_change(_OldVsn, State, _Extra) -> {ok, State}. +schedule_rotation(undefined) -> + undefined; +schedule_rotation(Date) -> + erlang:send_after(lager_util:calculate_next_rotation(Date) * 1000, self(), rotate). + %% ===== Begin code lifted from riak_err ===== -spec limited_fmt(string(), list(), integer()) -> iolist(). diff --git a/src/lager_file_backend.erl b/src/lager_file_backend.erl index c1e2543..8777c9f 100644 --- a/src/lager_file_backend.erl +++ b/src/lager_file_backend.erl @@ -17,8 +17,14 @@ %% @doc File backend for lager, with multiple file support. %% Multiple files are supported, each with the path and the loglevel being %% configurable. The configuration paramter for this backend is a list of -%% 2-tuples of the form `{FileName, Level}'. This backend supports external log -%% rotation and will re-open handles to files if the inode changes. +%% 5-tuples of the form +%% `{FileName, Level, RotationSize, RotationDate, RotationCount}'. +%% This backend supports external and internal log +%% rotation and will re-open handles to files if the inode changes. It will +%% also rotate the files itself if the size of the file exceeds the +%% `RotationSize' and keep `RotationCount' rotated files. `RotationDate' is +%% an alternate rotation trigger, based on time. See the README for +%% documentation. -module(lager_file_backend). @@ -42,23 +48,29 @@ level :: integer(), fd :: file:io_device(), inode :: integer(), - flap=false :: boolean() + flap=false :: boolean(), + size = 0 :: integer(), + date, + count = 10 }). %% @private -spec init([{string(), lager:log_level()},...]) -> {ok, #state{}}. init(LogFiles) -> Files = [begin + schedule_rotation(Name, Date), case lager_util:open_logfile(Name, true) of - {ok, {FD, Inode}} -> - #file{name=Name, level=lager_util:level_to_num(Level), fd=FD, inode=Inode}; + {ok, {FD, Inode, _}} -> + #file{name=Name, level=lager_util:level_to_num(Level), + fd=FD, inode=Inode, size=Size, date=Date, count=Count}; {error, Reason} -> ?INT_LOG(error, "Failed to open log file ~s with error ~s", [Name, file:format_error(Reason)]), - #file{name=Name, level=lager_util:level_to_num(Level), flap=true} + #file{name=Name, level=lager_util:level_to_num(Level), + flap=true, size=Size, date=Date, count=Count} end end || - {Name, Level} <- LogFiles], + {Name, Level, Size, Date, Count} <- validate_logfiles(LogFiles)], {ok, #state{files=Files}}. %% @private @@ -72,7 +84,8 @@ handle_call({set_loglevel, Ident, Level}, #state{files=Files} = State) -> _ -> NewFiles = lists:map( fun(#file{name=Name} = File) when Name == Ident -> - ?INT_LOG(notice, "Changed loglevel of ~s to ~p", [Ident, Level]), + ?INT_LOG(notice, "Changed loglevel of ~s to ~p", + [Ident, Level]), File#file{level=lager_util:level_to_num(Level)}; (X) -> X end, Files), @@ -99,6 +112,17 @@ handle_event(_Event, State) -> {ok, State}. %% @private +handle_info({rotate, File}, #state{files=Files} = State) -> + case lists:keyfind(File, #file.name, Files) of + false -> + %% no such file exists + ?INT_LOG(warning, "Asked to rotate non-existant file ~p", [File]), + {ok, State}; + #file{name=Name, date=Date, count=Count} -> + lager_util:rotate_logfile(Name, Count), + schedule_rotation(Name, Date), + {ok, State} + end; handle_info(_Info, State) -> {ok, State}. @@ -114,16 +138,21 @@ terminate(_Reason, State) -> code_change(_OldVsn, State, _Extra) -> {ok, State}. -write(#file{name=Name, fd=FD, inode=Inode, flap=Flap} = File, Level, Msg) -> +write(#file{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize, + count=Count} = File, Level, Msg) -> case lager_util:ensure_logfile(Name, FD, Inode, true) of - {ok, {NewFD, NewInode}} -> + {ok, {_, _, Size}} when RotSize /= 0, Size > RotSize -> + lager_util:rotate_logfile(Name, Count), + write(File, Level, Msg); + {ok, {NewFD, NewInode, _}} -> file:write(NewFD, Msg), case Level of _ when Level =< ?ERROR -> %% force a sync on any message at error severity or above Flap2 = case file:datasync(NewFD) of {error, Reason2} when Flap == false -> - ?INT_LOG(error, "Failed to write log message to file ~s: ~s", [Name, file:format_error(Reason2)]), + ?INT_LOG(error, "Failed to write log message to file ~s: ~s", + [Name, file:format_error(Reason2)]), true; ok -> false; @@ -139,11 +168,55 @@ write(#file{name=Name, fd=FD, inode=Inode, flap=Flap} = File, Level, Msg) -> true -> File; _ -> - ?INT_LOG(error, "Failed to reopen logfile ~s with error ~s", [Name, file:format_error(Reason)]), + ?INT_LOG(error, "Failed to reopen logfile ~s with error ~s", + [Name, file:format_error(Reason)]), File#file{flap=true} end end. +validate_logfiles([]) -> + []; +validate_logfiles([{Name, Level, Size, Date, Count}|T]) -> + ValidLevel = (lists:member(Level, ?LEVELS)), + ValidSize = (is_integer(Size) andalso Size >= 0), + ValidCount = (is_integer(Count) andalso Count >= 0), + case {ValidLevel, ValidSize, ValidCount} of + {false, _, _} -> + ?INT_LOG(error, "Invalid log level of ~p for ~s.", + [Level, Name]), + validate_logfiles(T); + {_, false, _} -> + ?INT_LOG(error, "Invalid rotation size of ~p for ~s.", + [Size, Name]), + validate_logfiles(T); + {_, _, false} -> + ?INT_LOG(error, "Invalid rotation count of ~p for ~s.", + [Count, Name]), + validate_logfiles(T); + {true, true, true} -> + case lager_util:parse_rotation_date_spec(Date) of + {ok, Spec} -> + [{Name, Level, Size, Spec, + Count}|validate_logfiles(T)]; + {error, _} when Date == "" -> + %% blank ones are fine. + [{Name, Level, Size, undefined, + Count}|validate_logfiles(T)]; + {error, _} -> + ?INT_LOG(error, "Invalid rotation date of ~p for ~s.", + [Date, Name]), + validate_logfiles(T) + end + end; +validate_logfiles([H|T]) -> + ?INT_LOG(error, "Invalid logfile config ~p.", [H]), + validate_logfiles(T). + +schedule_rotation(_, undefined) -> + undefined; +schedule_rotation(Name, Date) -> + erlang:send_after(lager_util:calculate_next_rotation(Date) * 1000, self(), {rotate, Name}). + -ifdef(TEST). get_loglevel_test() -> @@ -160,7 +233,7 @@ get_loglevel_test() -> ?assertEqual(Level2, lager_util:level_to_num(warning)). rotation_test() -> - {ok, {FD, Inode}} = lager_util:open_logfile("test.log", true), + {ok, {FD, Inode, _}} = lager_util:open_logfile("test.log", true), ?assertMatch(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, write(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, 0, "hello world")), file:delete("test.log"), diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index 20167bd..7c00e61 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -80,9 +80,10 @@ install_handler(Event, Module, Config) -> ok -> lager:log(debug, self(), "Lager installed handler ~p into ~p", [Module, Event]), ok; - _ -> + Error -> %% try to reinstall it later - lager:log(error, self(), "Lager failed to install handler ~p into ~p, retrying later", [Module, Event]), + lager:log(error, self(), "Lager failed to install handler ~p into" + " ~p, retrying later : ~p", [Module, Event, Error]), erlang:send_after(5000, self(), reinstall_handler) end. diff --git a/src/lager_sup.erl b/src/lager_sup.erl index 0cee8f5..cec2da1 100644 --- a/src/lager_sup.erl +++ b/src/lager_sup.erl @@ -41,11 +41,33 @@ init([]) -> %% check if the crash log is enabled Crash = case application:get_env(lager, crash_log) of {ok, File} -> - MaxBytes = case application:get_env(lager, crash_log_size) of - {ok, Val} -> Val; + MaxBytes = case application:get_env(lager, crash_log_msg_size) of + {ok, Val} when is_integer(Val) andalso Val > 0 -> Val; _ -> 65536 end, - [{lager_crash_log, {lager_crash_log, start_link, [File, MaxBytes]}, + RotationSize = case application:get_env(lager, crash_log_size) of + {ok, Val1} when is_integer(Val1) andalso Val1 >= 0 -> Val1; + _ -> 0 + end, + RotationCount = case application:get_env(lager, crash_log_count) of + {ok, Val2} when is_integer(Val2) andalso Val2 >=0 -> Val2; + _ -> 0 + end, + RotationDate = case application:get_env(lager, crash_log_date) of + {ok, Val3} -> + case lager_util:parse_rotation_date_spec(Val3) of + {ok, Spec} -> Spec; + {error, _} when Val3 == "" -> undefined; %% blank is ok + {error, _} -> + error_logger:error_msg("Invalid date spec for " + "crash log ~p~n", [Val3]), + undefined + end; + _ -> undefined + end, + + [{lager_crash_log, {lager_crash_log, start_link, [File, MaxBytes, + RotationSize, RotationDate, RotationCount]}, permanent, 5000, worker, [lager_crash_log]}]; _ -> [] diff --git a/src/lager_util.erl b/src/lager_util.erl index 404bd2f..60e25a0 100644 --- a/src/lager_util.erl +++ b/src/lager_util.erl @@ -19,7 +19,13 @@ -include_lib("kernel/include/file.hrl"). -export([levels/0, level_to_num/1, num_to_level/1, open_logfile/2, - ensure_logfile/4, format_time/0, format_time/1, localtime_ms/0, maybe_utc/1]). + ensure_logfile/4, rotate_logfile/2, format_time/0, format_time/1, + localtime_ms/0, maybe_utc/1, parse_rotation_date_spec/1, + calculate_next_rotation/1]). + +-ifdef(TEST). +-include_lib("eunit/include/eunit.hrl"). +-endif. levels() -> [debug, info, notice, warning, error, critical, alert, emergency]. @@ -54,7 +60,7 @@ open_logfile(Name, Buffer) -> case file:read_file_info(Name) of {ok, FInfo} -> Inode = FInfo#file_info.inode, - {ok, {FD, Inode}}; + {ok, {FD, Inode, FInfo#file_info.size}}; X -> X end; Y -> Y @@ -68,16 +74,16 @@ ensure_logfile(Name, FD, Inode, Buffer) -> Inode2 = FInfo#file_info.inode, case Inode == Inode2 of true -> - {ok, {FD, Inode}}; + {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}} -> + {ok, {FD2, Inode3, Size}} -> %% inode changed, file was probably moved and %% recreated - {ok, {FD2, Inode3}}; + {ok, {FD2, Inode3, Size}}; Error -> Error end @@ -87,9 +93,9 @@ ensure_logfile(Name, FD, Inode, Buffer) -> file:close(FD), file:close(FD), case open_logfile(Name, Buffer) of - {ok, {FD2, Inode3}} -> + {ok, {FD2, Inode3, Size}} -> %% file was removed - {ok, {FD2, Inode3}}; + {ok, {FD2, Inode3, Size}}; Error -> Error end @@ -109,14 +115,260 @@ maybe_utc({Date, {H, M, S, Ms}}) -> {Date1, {H1, M1, S1, Ms}} end. +rotate_logfile(File, 0) -> + file:delete(File); +rotate_logfile(File, 1) -> + file:rename(File, File++".0"), + rotate_logfile(File, 0); +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())). format_time({utc, {{Y, M, D}, {H, Mi, S, Ms}}}) -> - {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), io_lib:format("~2..0b:~2..0b:~2..0b.~3..0b UTC", [H, Mi, S, Ms])}; + {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), + io_lib:format("~2..0b:~2..0b:~2..0b.~3..0b UTC", [H, Mi, S, Ms])}; format_time({{Y, M, D}, {H, Mi, S, Ms}}) -> - {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), io_lib:format("~2..0b:~2..0b:~2..0b.~3..0b", [H, Mi, S, Ms])}; + {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), + io_lib:format("~2..0b:~2..0b:~2..0b.~3..0b", [H, Mi, S, Ms])}; format_time({utc, {{Y, M, D}, {H, Mi, S}}}) -> - {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), io_lib:format("~2..0b:~2..0b:~2..0b UTC", [H, Mi, S])}; + {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), + io_lib:format("~2..0b:~2..0b:~2..0b UTC", [H, Mi, S])}; format_time({{Y, M, D}, {H, Mi, S}}) -> - {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), io_lib:format("~2..0b:~2..0b:~2..0b", [H, Mi, S])}. + {io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]), + io_lib:format("~2..0b:~2..0b:~2..0b", [H, Mi, S])}. + +parse_rotation_day_spec([], Res) -> + {ok, Res ++ [{hour, 0}]}; +parse_rotation_day_spec([$D, D1, D2], Res) -> + case list_to_integer([D1, D2]) of + X when X >= 0, X =< 23 -> + {ok, 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_date_spec([$$, $W, W|T]) when W >= $0, W =< $6 -> + Week = W - 48, + parse_rotation_day_spec(T, [{day, Week}]); +parse_rotation_date_spec([$$, $M, L|T]) when L == $L; L == $l -> + %% last day in month. + parse_rotation_day_spec(T, [{date, last}]); +parse_rotation_date_spec([$$, $M, M1, M2|[$D|_]=T]) -> + case list_to_integer([M1, M2]) of + X when X >= 1, X =< 31 -> + parse_rotation_day_spec(T, [{date, X}]); + _ -> + {error, invalid_date_spec} + end; +parse_rotation_date_spec([$$, $M, M|[$D|_]=T]) -> + parse_rotation_day_spec(T, [{date, M - 48}]); +parse_rotation_date_spec([$$, $M, M1, M2]) -> + case list_to_integer([M1, M2]) of + X when X >= 1, X =< 31 -> + {ok, [{date, X}, {hour, 0}]}; + _ -> + {error, invalid_date_spec} + end; +parse_rotation_date_spec([$$, $M, M]) -> + {ok, [{date, M - 48}, {hour, 0}]}; +parse_rotation_date_spec([$$|X]) when X /= [] -> + parse_rotation_day_spec(X, []); +parse_rotation_date_spec(_) -> + {error, invalid_date_spec}. + +calculate_next_rotation(Spec) -> + Now = calendar:local_time(), + Later = calculate_next_rotation(Spec, Now), + calendar:datetime_to_gregorian_seconds(Later) - + calendar:datetime_to_gregorian_seconds(Now). + +calculate_next_rotation([], Now) -> + Now; +calculate_next_rotation([{hour, X}|T], {{_, _, _}, {Hour, _, _}} = Now) when Hour < X -> + %% rotation is today, sometime + NewNow = setelement(2, Now, {X, 0, 0}), + calculate_next_rotation(T, NewNow); +calculate_next_rotation([{hour, X}|T], {{_, _, _}, _} = Now) -> + %% rotation is not today + Seconds = calendar:datetime_to_gregorian_seconds(Now) + 86400, + DateTime = calendar:gregorian_seconds_to_datetime(Seconds), + NewNow = setelement(2, DateTime, {X, 0, 0}), + calculate_next_rotation(T, NewNow); +calculate_next_rotation([{day, Day}|T], {Date, _Time} = Now) -> + DoW = calendar:day_of_the_week(Date), + AdjustedDay = case Day of + 0 -> 7; + X -> X + end, + case AdjustedDay of + DoW -> %% rotation is today + OldDate = element(1, Now), + case calculate_next_rotation(T, Now) of + {OldDate, _} = NewNow -> NewNow; + {NewDate, _} -> + %% rotation *isn't* today! rerun the calculation + NewNow = {NewDate, {0, 0, 0}}, + calculate_next_rotation([{day, Day}|T], NewNow) + end; + Y when Y > DoW -> %% rotation is later this week + PlusDays = Y - DoW, + Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays), + {NewDate, _} = calendar:gregorian_seconds_to_datetime(Seconds), + NewNow = {NewDate, {0, 0, 0}}, + calculate_next_rotation(T, NewNow); + Y when Y < DoW -> %% rotation is next week + PlusDays = ((7 - DoW) + Y), + Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays), + {NewDate, _} = calendar:gregorian_seconds_to_datetime(Seconds), + NewNow = {NewDate, {0, 0, 0}}, + calculate_next_rotation(T, NewNow) + end; +calculate_next_rotation([{date, last}|T], {{Year, Month, Day}, _} = Now) -> + Last = calendar:last_day_of_the_month(Year, Month), + case Last == Day of + true -> %% doing rotation today + OldDate = element(1, Now), + case calculate_next_rotation(T, Now) of + {OldDate, _} = NewNow -> NewNow; + {NewDate, _} -> + %% rotation *isn't* today! rerun the calculation + NewNow = {NewDate, {0, 0, 0}}, + calculate_next_rotation([{date, last}|T], NewNow) + end; + false -> + NewNow = setelement(1, Now, {Year, Month, Last}), + calculate_next_rotation(T, NewNow) + end; +calculate_next_rotation([{date, Date}|T], {{_, _, Date}, _} = Now) -> + %% rotation is today + OldDate = element(1, Now), + case calculate_next_rotation(T, Now) of + {OldDate, _} = NewNow -> NewNow; + {NewDate, _} -> + %% rotation *isn't* today! rerun the calculation + NewNow = setelement(1, Now, NewDate), + calculate_next_rotation([{date, Date}|T], NewNow) + end; +calculate_next_rotation([{date, Date}|T], {{Year, Month, Day}, _} = Now) -> + PlusDays = case Date of + X when X < Day -> %% rotation is next month + Last = calendar:last_day_of_the_month(Year, Month), + (Last - Day); + X when X > Day -> %% rotation is later this month + X - Day + end, + Seconds = calendar:datetime_to_gregorian_seconds(Now) + (86400 * PlusDays), + NewNow = calendar:gregorian_seconds_to_datetime(Seconds), + calculate_next_rotation(T, NewNow). + +-ifdef(TEST). + +parse_test() -> + ?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, [{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")), + ?assertEqual({ok, [{date, 31}, {hour, 0}]}, parse_rotation_date_spec("$M31")), + ?assertEqual({ok, [{date, 31}, {hour, 1}]}, parse_rotation_date_spec("$M31D1")), + ?assertEqual({ok, [{date, last}, {hour, 0}]}, parse_rotation_date_spec("$ML")), + ?assertEqual({ok, [{date, last}, {hour, 0}]}, parse_rotation_date_spec("$Ml")), + ?assertEqual({ok, [{day, 5}, {hour, 0}]}, parse_rotation_date_spec("$W5")), + ok. + +parse_fail_test() -> + ?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")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$W7D1")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M32")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M32D1")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$D15M5")), + ?assertEqual({error, invalid_date_spec}, parse_rotation_date_spec("$M5W5")), + ok. + +rotation_calculation_test() -> + ?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}}, + calculate_next_rotation([{hour, 16}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 2}, {12, 0, 0}}, + calculate_next_rotation([{hour, 12}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 2, 1}, {12, 0, 0}}, + calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 2, 1}, {12, 0, 0}}, + calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 15}, {12, 34, 43}})), + ?assertMatch({{2000, 2, 1}, {12, 0, 0}}, + calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 2}, {12, 34, 43}})), + ?assertMatch({{2000, 2, 1}, {12, 0, 0}}, + calculate_next_rotation([{date, 1}, {hour, 12}], {{2000, 1, 31}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 1}, {16, 0, 0}}, + calculate_next_rotation([{date, 1}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 15}, {16, 0, 0}}, + calculate_next_rotation([{date, 15}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 31}, {16, 0, 0}}, + calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 31}, {16, 0, 0}}, + calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 31}, {12, 34, 43}})), + ?assertMatch({{2000, 2, 29}, {16, 0, 0}}, + calculate_next_rotation([{date, last}, {hour, 16}], {{2000, 1, 31}, {17, 34, 43}})), + ?assertMatch({{2001, 2, 28}, {16, 0, 0}}, + calculate_next_rotation([{date, last}, {hour, 16}], {{2001, 1, 31}, {17, 34, 43}})), + + ?assertMatch({{2000, 1, 1}, {16, 0, 0}}, + calculate_next_rotation([{day, 6}, {hour, 16}], {{2000, 1, 1}, {12, 34, 43}})), + ?assertMatch({{2000, 1, 8}, {16, 0, 0}}, + calculate_next_rotation([{day, 6}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})), + ?assertMatch({{2000, 1, 7}, {16, 0, 0}}, + calculate_next_rotation([{day, 5}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})), + ?assertMatch({{2000, 1, 3}, {16, 0, 0}}, + calculate_next_rotation([{day, 1}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})), + ?assertMatch({{2000, 1, 2}, {16, 0, 0}}, + calculate_next_rotation([{day, 0}, {hour, 16}], {{2000, 1, 1}, {17, 34, 43}})), + ?assertMatch({{2000, 1, 9}, {16, 0, 0}}, + calculate_next_rotation([{day, 0}, {hour, 16}], {{2000, 1, 2}, {17, 34, 43}})), + ?assertMatch({{2000, 2, 3}, {16, 0, 0}}, + calculate_next_rotation([{day, 4}, {hour, 16}], {{2000, 1, 29}, {17, 34, 43}})), + + ?assertMatch({{2000, 1, 7}, {16, 0, 0}}, + calculate_next_rotation([{day, 5}, {hour, 16}], {{2000, 1, 3}, {17, 34, 43}})), + + ?assertMatch({{2000, 1, 3}, {16, 0, 0}}, + calculate_next_rotation([{day, 1}, {hour, 16}], {{1999, 12, 28}, {17, 34, 43}})), + ok. + +rotate_file_test() -> + file:delete("rotation.log"), + [file:delete(["rotation.log.", integer_to_list(N)]) || N <- lists:seq(0, 9)], + [begin + file:write_file("rotation.log", integer_to_list(N)), + Count = case N > 10 of + true -> 10; + _ -> N + end, + [begin + FileName = ["rotation.log.", integer_to_list(M)], + ?assert(filelib:is_regular(FileName)), + %% check the expected value is in the file + Number = list_to_binary(integer_to_list(N - M - 1)), + ?assertEqual({ok, Number}, file:read_file(FileName)) + end + || M <- lists:seq(0, Count-1)], + rotate_logfile("rotation.log", 10) + end || N <- lists:seq(0, 20)]. + + + +-endif.