From 66e39f21f8471f4f9ee60817eea8cc2c686793aa Mon Sep 17 00:00:00 2001 From: Sungjin Park Date: Mon, 5 Jan 2015 16:27:13 +0900 Subject: [PATCH 01/11] Add lager_manager_killer and tests for it. --- rebar.config | 2 ++ src/lager_app.erl | 26 ++++++++++++++ src/lager_handler_watcher.erl | 8 +++++ src/lager_manager_killer.erl | 44 ++++++++++++++++++++++++ test/lager_manager_killer_test.erl | 55 ++++++++++++++++++++++++++++++ test/lager_slow_backend.erl | 34 ++++++++++++++++++ 6 files changed, 169 insertions(+) create mode 100644 src/lager_manager_killer.erl create mode 100644 test/lager_manager_killer_test.erl create mode 100644 test/lager_slow_backend.erl diff --git a/rebar.config b/rebar.config index 494a6ca..dbb749a 100644 --- a/rebar.config +++ b/rebar.config @@ -10,3 +10,5 @@ {cover_enabled, true}. {edoc_opts, [{stylesheet_file, "./priv/edoc.css"}]}. + +{eunit_opts, [verbose]}. diff --git a/src/lager_app.erl b/src/lager_app.erl index 6364aef..e50b41c 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -62,6 +62,32 @@ start(_StartType, _StartArgs) -> throw({error, bad_config}) end, + case application:get_env(lager, killer_hwm) of + undefined -> + ok; + {ok, undefined} -> + undefined; + {ok, KillerHWM} when is_integer(KillerHWM), KillerHWM >= 0 -> + KillerReinstallAfter = + case application:get_env(lager, killer_reinstall_after) of + undefined -> + 5000; + {ok, undefined} -> + 5000; + {ok, V} when is_integer(V), V >= 0 -> + V; + {ok, BadKillerReinstallAfter} -> + error_logger:error_msg("Invalid value for 'cooldown': ~p~n", [BadKillerReinstallAfter]), + throw({error, bad_config}) + end, + _ = supervisor:start_child(lager_handler_watcher_sup, + [lager_event, lager_manager_killer, [KillerHWM, KillerReinstallAfter]]), + ok; + {ok, BadKillerHWM} -> + error_logger:error_msg("Invalid value for 'floodline': ~p~n", [BadKillerHWM]), + throw({error, bad_config}) + end, + Handlers = case application:get_env(lager, handlers) of undefined -> [{lager_console_backend, info}, diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index 24498a4..1cd2804 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -61,6 +61,14 @@ handle_info({gen_event_EXIT, Module, normal}, #state{module=Module} = State) -> {stop, normal, State}; handle_info({gen_event_EXIT, Module, shutdown}, #state{module=Module} = State) -> {stop, normal, State}; +handle_info({gen_event_EXIT, Module, {'EXIT', {kill_me, [KillerHWM, KillerReinstallAfter]}}}, + #state{module=Module, event=Event} = State) -> + % Brutally kill the manager but stay alive to restore settings. + Manager = whereis(Event), + unlink(Manager), + exit(Manager, kill), + erlang:send_after(KillerReinstallAfter, self(), reinstall_handler), + {noreply, State#state{config=[KillerHWM, KillerReinstallAfter]}}; handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, config=Config, event=Event} = State) -> case lager:log(error, self(), "Lager event handler ~p exited with reason ~s", diff --git a/src/lager_manager_killer.erl b/src/lager_manager_killer.erl new file mode 100644 index 0000000..bb959f9 --- /dev/null +++ b/src/lager_manager_killer.erl @@ -0,0 +1,44 @@ +-module(lager_manager_killer). +-author("Sungjin Park "). +-behavior(gen_event). + +-export([init/1, handle_event/2, handle_call/2, handle_info/2, terminate/2, code_change/3]). + +-include("lager.hrl"). + +-record(state, { + killer_hwm :: non_neg_integer(), + killer_reinstall_after :: non_neg_integer() +}). + +init([KillerHWM, KillerReinstallAfter]) -> + {ok, #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}}. + +handle_call(get_loglevel, State) -> + {ok, {mask, ?LOG_NONE}, State}; +handle_call({set_loglevel, _Level}, State) -> + {ok, ok, State}; +handle_call(get_settings, State = #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> + {ok, [KillerHWM, KillerReinstallAfter], State}; +handle_call(_Request, State) -> + {ok, ok, State}. + +handle_event({log, _Message}, State = #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> + {message_queue_len, Len} = process_info(self(), message_queue_len), + case Len > KillerHWM of + true -> + exit({kill_me, [KillerHWM, KillerReinstallAfter]}); + _ -> + {ok, State} + end; +handle_event(_Event, State) -> + {ok, State}. + +handle_info(_Info, State) -> + {ok, State}. + +terminate(_Reason, _State) -> + ok. + +code_change(_OldVsn, State, _Extra) -> + {ok, State}. diff --git a/test/lager_manager_killer_test.erl b/test/lager_manager_killer_test.erl new file mode 100644 index 0000000..1fcb59f --- /dev/null +++ b/test/lager_manager_killer_test.erl @@ -0,0 +1,55 @@ +-module(lager_manager_killer_test). +-author("Sungjin Park "). + +-compile([{parse_transform, lager_transform}]). + +-ifdef(TEST). +-include_lib("eunit/include/eunit.hrl"). + +overload_test() -> + application:stop(lager), + application:load(lager), + Delay = 1000, % sleep 1 sec on every log + KillerHWM = 10, % kill the manager if there are more than 10 pending logs + KillerReinstallAfter = 1000, % reinstall killer after 1 sec + application:set_env(lager, handlers, [{lager_slow_backend, Delay}]), + application:set_env(lager, async_threshold, undefined), + application:set_env(lager, killer_hwm, KillerHWM), + application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), + ensure_started(lager), + lager_config:set(async, true), + Manager = whereis(lager_event), + erlang:trace(all, true, [procs]), + [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], + Margin = 100, + receive + {trace, Manager, exit, killed} -> + ?debugFmt("Manager ~p killed", [Manager]) + after Delay+Margin -> + ?assert(false) + end, + receive + {trace, _Sup, spawn, Pid, Fun} -> + ?assert(process_info(Pid, registered_name) =:= {registered_name, lager_event}), + ?debugFmt("Manager ~p start with ~p", [Pid, Fun]), + ?assertNot(lists:member(lager_manager_killer, gen_event:which_handlers(lager_event))) + after Margin -> + ?assert(false) + end, + erlang:trace(all, false, [procs]), + timer:sleep(KillerReinstallAfter), + ?assert(proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event))), + ?assert(gen_event:call(lager_event, lager_manager_killer, get_settings) =:= [KillerHWM, KillerReinstallAfter]), + ?debugFmt("Killer reinstalled with [~p, ~p]", [KillerHWM, KillerReinstallAfter]), + application:stop(lager). + +ensure_started(App) -> + case application:start(App) of + ok -> + ok; + {error, {not_started, Dep}} -> + ensure_started(Dep), + ensure_started(App) + end. + +-endif. \ No newline at end of file diff --git a/test/lager_slow_backend.erl b/test/lager_slow_backend.erl new file mode 100644 index 0000000..9771083 --- /dev/null +++ b/test/lager_slow_backend.erl @@ -0,0 +1,34 @@ +-module(lager_slow_backend). +-author("Sungjin Park "). +-behavior(gen_event). + +-export([init/1, handle_call/2, handle_event/2, handle_info/2, terminate/2, code_change/3]). + +-include("lager.hrl"). + +-record(state, { + delay :: non_neg_integer() +}). + +init(Delay) -> + {ok, #state{delay=Delay}}. + +handle_call(get_loglevel, State) -> + {ok, lager_util:config_to_mask(debug), State}; +handle_call(_Request, State) -> + {ok, ok, State}. + +handle_event({log, _Message}, State) -> + timer:sleep(State#state.delay), + {ok, State}; +handle_event(_Event, State) -> + {ok, State}. + +handle_info(_Info, State) -> + {ok, State}. + +terminate(_Reason, _State) -> + ok. + +code_change(_OldVsn, State, _Extra) -> + {ok, State}. From 03cd95562ae8821cc79cab297c0a69924b460344 Mon Sep 17 00:00:00 2001 From: "Brian L. Troutwine" Date: Thu, 10 Mar 2016 16:03:39 -0800 Subject: [PATCH 02/11] Attempt to redress test failures. At this point in the work, the killer will correctly stop the DEFAULT_SINK in the event of overload but our friend never comes back up and lager stops working past this point. Oops! Error message: =SUPERVISOR REPORT==== 10-Mar-2016::16:18:11 === Supervisor: {local,lager_handler_watcher_sup} Context: child_terminated Reason: killed Offender: [{pid,<0.63.0>}, {id,lager_handler_watcher}, {mfargs,{lager_handler_watcher,start_link,undefined}}, {restart_type,temporary}, {shutdown,5000}, {child_type,worker}] =SUPERVISOR REPORT==== 10-Mar-2016::16:18:11 === Supervisor: {local,lager_handler_watcher_sup} Context: child_terminated Reason: killed Offender: [{pid,<0.59.0>}, {id,lager_handler_watcher}, {mfargs,{lager_handler_watcher,start_link,undefined}}, {restart_type,temporary}, {shutdown,5000}, {child_type,worker}] =PROGRESS REPORT==== 10-Mar-2016::16:18:11 === supervisor: {local,lager_sup} started: [{pid,<0.113.0>}, {id,lager}, {mfargs,{gen_event,start_link,[{local,lager_event}]}}, {restart_type,permanent}, {shutdown,5000}, {child_type,worker}] Signed-off-by: Brian L. Troutwine --- src/lager_app.erl | 36 ++++++++++++++-------------- src/lager_handler_watcher.erl | 4 ++-- src/lager_manager_killer.erl | 38 +++++++++++++++--------------- test/lager_manager_killer_test.erl | 4 ++-- test/lager_slow_backend.erl | 2 +- 5 files changed, 42 insertions(+), 42 deletions(-) diff --git a/src/lager_app.erl b/src/lager_app.erl index 87ef4e9..67a5f7a 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -146,24 +146,24 @@ start_error_logger_handler(_, HWM, {ok, WhiteList}) -> throw({error, bad_config}) end, - KillerHWM = case application:get_env(lager, killer_hwm) of - undefined -> -1; - {ok, undefined} -> -1; - {ok, KHWM} when is_integer(KHWM), KHWM >= 0 -> KHWM - end, - KillerReinstallAfter = case application:get_env(lager, killer_reinstall_after) of - undefined -> 5000; - {ok, undefined} -> 5000; - {ok, V} when is_integer(V), V >= 0 -> V; - {ok, BadKillerReinstallAfter} -> - error_logger:error_msg("Invalid value for 'cooldown': ~p~n", - [BadKillerReinstallAfter]), - throw({error, bad_config}) - end, - - _ = supervisor:start_child(lager_handler_watcher_sup, - [?DEFAULT_SINK, lager_manager_killer, - [KillerHWM, KillerReinstallAfter]]), + %% Conditionally start the high watermark killer. + case application:get_env(lager, killer_hwm) of + undefined -> ok; + {ok, undefined} -> ok; + {ok, KillerHWM} when is_integer(KillerHWM), KillerHWM >= 0 -> + KillerReinstallAfter = case application:get_env(lager, killer_reinstall_after) of + undefined -> 5000; + {ok, undefined} -> 5000; + {ok, V} when is_integer(V), V >= 0 -> V; + {ok, BadKillerReinstallAfter} -> + error_logger:error_msg("Invalid value for 'cooldown': ~p~n", + [BadKillerReinstallAfter]), + throw({error, bad_config}) + end, + _ = supervisor:start_child(lager_handler_watcher_sup, + [?DEFAULT_SINK, lager_manager_killer, + [KillerHWM, KillerReinstallAfter]]) + end, case supervisor:start_child(lager_handler_watcher_sup, [error_logger, error_logger_lager_h, [HWM, GlStrategy]]) of {ok, _} -> diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index e34553c..da67d8b 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -61,14 +61,14 @@ handle_info({gen_event_EXIT, Module, normal}, #state{module=Module} = State) -> {stop, normal, State}; handle_info({gen_event_EXIT, Module, shutdown}, #state{module=Module} = State) -> {stop, normal, State}; -handle_info({gen_event_EXIT, Module, {'EXIT', {kill_me, [KillerHWM, KillerReinstallAfter]}}}, +handle_info({gen_event_EXIT, Module, {'EXIT', {kill_me, [_KillerHWM, KillerReinstallAfter]}}}, #state{module=Module, sink=Sink} = State) -> % Brutally kill the manager but stay alive to restore settings. Manager = whereis(Sink), unlink(Manager), exit(Manager, kill), erlang:send_after(KillerReinstallAfter, self(), reinstall_handler), - {noreply, State#state{config=[KillerHWM, KillerReinstallAfter]}}; + {noreply, State}; handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, config=Config, sink=Sink} = State) -> case lager:log(error, self(), "Lager event handler ~p exited with reason ~s", diff --git a/src/lager_manager_killer.erl b/src/lager_manager_killer.erl index bb959f9..158b471 100644 --- a/src/lager_manager_killer.erl +++ b/src/lager_manager_killer.erl @@ -7,38 +7,38 @@ -include("lager.hrl"). -record(state, { - killer_hwm :: non_neg_integer(), - killer_reinstall_after :: non_neg_integer() -}). + killer_hwm :: non_neg_integer(), + killer_reinstall_after :: non_neg_integer() + }). init([KillerHWM, KillerReinstallAfter]) -> - {ok, #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}}. + {ok, #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}}. handle_call(get_loglevel, State) -> - {ok, {mask, ?LOG_NONE}, State}; + {ok, {mask, ?LOG_NONE}, State}; handle_call({set_loglevel, _Level}, State) -> - {ok, ok, State}; + {ok, ok, State}; handle_call(get_settings, State = #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> - {ok, [KillerHWM, KillerReinstallAfter], State}; + {ok, [KillerHWM, KillerReinstallAfter], State}; handle_call(_Request, State) -> - {ok, ok, State}. + {ok, ok, State}. handle_event({log, _Message}, State = #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> - {message_queue_len, Len} = process_info(self(), message_queue_len), - case Len > KillerHWM of - true -> - exit({kill_me, [KillerHWM, KillerReinstallAfter]}); - _ -> - {ok, State} - end; + {message_queue_len, Len} = process_info(self(), message_queue_len), + case Len > KillerHWM of + true -> + exit({kill_me, [KillerHWM, KillerReinstallAfter]}); + _ -> + {ok, State} + end; handle_event(_Event, State) -> - {ok, State}. + {ok, State}. handle_info(_Info, State) -> - {ok, State}. + {ok, State}. terminate(_Reason, _State) -> - ok. + ok. code_change(_OldVsn, State, _Extra) -> - {ok, State}. + {ok, State}. diff --git a/test/lager_manager_killer_test.erl b/test/lager_manager_killer_test.erl index 1fcb59f..6e63079 100644 --- a/test/lager_manager_killer_test.erl +++ b/test/lager_manager_killer_test.erl @@ -12,7 +12,7 @@ overload_test() -> Delay = 1000, % sleep 1 sec on every log KillerHWM = 10, % kill the manager if there are more than 10 pending logs KillerReinstallAfter = 1000, % reinstall killer after 1 sec - application:set_env(lager, handlers, [{lager_slow_backend, Delay}]), + application:set_env(lager, handlers, [{lager_slow_backend, [{delay, Delay}]}]), application:set_env(lager, async_threshold, undefined), application:set_env(lager, killer_hwm, KillerHWM), application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), @@ -52,4 +52,4 @@ ensure_started(App) -> ensure_started(App) end. --endif. \ No newline at end of file +-endif. diff --git a/test/lager_slow_backend.erl b/test/lager_slow_backend.erl index 9771083..e467c23 100644 --- a/test/lager_slow_backend.erl +++ b/test/lager_slow_backend.erl @@ -10,7 +10,7 @@ delay :: non_neg_integer() }). -init(Delay) -> +init([{delay, Delay}]) -> {ok, #state{delay=Delay}}. handle_call(get_loglevel, State) -> From 34d994280a1f594fa20d96672b98ebd8f4813309 Mon Sep 17 00:00:00 2001 From: "Brian L. Troutwine" Date: Mon, 14 Mar 2016 13:36:17 -0700 Subject: [PATCH 03/11] Update test to not rely on sleep. This test only passes when run in isolation. That is, if you run the suite solo everything is beautiful and nothing hurts. When run in the group, it fails. By inspection it seems that no trace messages are being sent and this causes the failure, for want of specific traces. Signed-off-by: Brian L. Troutwine --- test/lager_manager_killer_test.erl | 107 ++++++++++++++++++----------- 1 file changed, 65 insertions(+), 42 deletions(-) diff --git a/test/lager_manager_killer_test.erl b/test/lager_manager_killer_test.erl index 6e63079..ac8898f 100644 --- a/test/lager_manager_killer_test.erl +++ b/test/lager_manager_killer_test.erl @@ -7,49 +7,72 @@ -include_lib("eunit/include/eunit.hrl"). overload_test() -> - application:stop(lager), - application:load(lager), - Delay = 1000, % sleep 1 sec on every log - KillerHWM = 10, % kill the manager if there are more than 10 pending logs - KillerReinstallAfter = 1000, % reinstall killer after 1 sec - application:set_env(lager, handlers, [{lager_slow_backend, [{delay, Delay}]}]), - application:set_env(lager, async_threshold, undefined), - application:set_env(lager, killer_hwm, KillerHWM), - application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), - ensure_started(lager), - lager_config:set(async, true), - Manager = whereis(lager_event), - erlang:trace(all, true, [procs]), - [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], - Margin = 100, - receive - {trace, Manager, exit, killed} -> - ?debugFmt("Manager ~p killed", [Manager]) - after Delay+Margin -> - ?assert(false) - end, - receive - {trace, _Sup, spawn, Pid, Fun} -> - ?assert(process_info(Pid, registered_name) =:= {registered_name, lager_event}), - ?debugFmt("Manager ~p start with ~p", [Pid, Fun]), - ?assertNot(lists:member(lager_manager_killer, gen_event:which_handlers(lager_event))) - after Margin -> - ?assert(false) - end, - erlang:trace(all, false, [procs]), - timer:sleep(KillerReinstallAfter), - ?assert(proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event))), - ?assert(gen_event:call(lager_event, lager_manager_killer, get_settings) =:= [KillerHWM, KillerReinstallAfter]), - ?debugFmt("Killer reinstalled with [~p, ~p]", [KillerHWM, KillerReinstallAfter]), - application:stop(lager). + application:stop(lager), + application:load(lager), + Delay = 1000, % sleep 1 sec on every log + KillerHWM = 10, % kill the manager if there are more than 10 pending logs + KillerReinstallAfter = 1000, % reinstall killer after 1 sec + application:set_env(lager, handlers, [{lager_slow_backend, [{delay, Delay}]}]), + application:set_env(lager, async_threshold, undefined), + application:set_env(lager, killer_hwm, KillerHWM), + application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), + ensure_started(lager), + lager_config:set(async, true), + Manager = whereis(lager_event), + erlang:trace(all, true, [procs]), + [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], + Margin = 100, + ok = confirm_manager_exit(Manager, Delay+Margin), + ok = confirm_sink_reregister(Margin), + erlang:trace(all, false, [procs]), + wait_until(fun() -> + case proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event)) of + [] -> false; + _ -> true + end + end, Margin, 15), + wait_until(fun() -> + case gen_event:call(lager_event, lager_manager_killer, get_settings) of + [KillerHWM, KillerReinstallAfter] -> true; + _Other -> false + end + end, Margin, 15), + application:stop(lager). ensure_started(App) -> - case application:start(App) of - ok -> - ok; - {error, {not_started, Dep}} -> - ensure_started(Dep), - ensure_started(App) - end. + case application:start(App) of + ok -> + ok; + {error, {not_started, Dep}} -> + ensure_started(Dep), + ensure_started(App) + end. + +confirm_manager_exit(Manager, Delay) -> + receive + {trace, Manager, exit, killed} -> + ?debugFmt("Manager ~p killed", [Manager]); + Other -> + ?debugFmt("OTHER MSG: ~p", [Other]), + confirm_manager_exit(Manager, Delay) + after Delay -> + ?assert(false) + end. + +confirm_sink_reregister(Delay) -> + receive + {trace, _Pid, register, lager_event} -> + ?assertNot(lists:member(lager_manager_killer, gen_event:which_handlers(lager_event))) + after Delay -> + ?assert(false) + end. + +wait_until(_Fun, _Delay, 0) -> + {error, too_many_retries}; +wait_until(Fun, Delay, Retries) -> + case Fun() of + true -> ok; + false -> timer:sleep(Delay), wait_until(Fun, Delay, Retries-1) + end. -endif. From 101dba232e22602255c4be7169e160b3de54a83e Mon Sep 17 00:00:00 2001 From: "Brian L. Troutwine" Date: Thu, 17 Mar 2016 10:11:42 -0700 Subject: [PATCH 04/11] Force restart of system after a watcher kill. This is, perhaps, not the most ideal setup. It still ignores other sinks but does bring logging back online after the appropriate delay. Signed-off-by: Brian L. Troutwine --- src/lager_app.erl | 9 ++++++--- src/lager_handler_watcher.erl | 8 ++++---- src/lager_manager_killer.erl | 7 +++++++ 3 files changed, 17 insertions(+), 7 deletions(-) diff --git a/src/lager_app.erl b/src/lager_app.erl index 67a5f7a..5ed1415 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -28,7 +28,8 @@ -export([start/0, start/2, start_handler/3, - stop/1]). + stop/1, + boot/0]). -define(FILENAMES, '__lager_file_backend_filenames'). -define(THROTTLE, lager_backend_throttle). @@ -220,7 +221,10 @@ get_env_default({ok, Value}, _Default) -> start(_StartType, _StartArgs) -> {ok, Pid} = lager_sup:start_link(), + SavedHandlers = boot(), + {ok, Pid, SavedHandlers}. +boot() -> %% Handle the default sink. determine_async_behavior(?DEFAULT_SINK, application:get_env(lager, async_threshold), @@ -246,8 +250,7 @@ start(_StartType, _StartArgs) -> clean_up_config_checks(), - {ok, Pid, SavedHandlers}. - + SavedHandlers. stop(Handlers) -> lists:foreach(fun(Handler) -> diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index da67d8b..336ee06 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -63,11 +63,11 @@ handle_info({gen_event_EXIT, Module, shutdown}, #state{module=Module} = State) - {stop, normal, State}; handle_info({gen_event_EXIT, Module, {'EXIT', {kill_me, [_KillerHWM, KillerReinstallAfter]}}}, #state{module=Module, sink=Sink} = State) -> - % Brutally kill the manager but stay alive to restore settings. + %% Brutally kill the manager but stay alive to restore settings. Manager = whereis(Sink), unlink(Manager), exit(Manager, kill), - erlang:send_after(KillerReinstallAfter, self(), reinstall_handler), + erlang:send_after(KillerReinstallAfter, self(), reboot), {noreply, State}; handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, config=Config, sink=Sink} = State) -> @@ -80,8 +80,8 @@ handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, ok end, {noreply, State}; -handle_info(reinstall_handler, #state{module=Module, config=Config, sink=Sink} = State) -> - install_handler(Sink, Module, Config), +handle_info(reboot, State) -> + lager_app:boot(), {noreply, State}; handle_info(stop, State) -> {stop, normal, State}; diff --git a/src/lager_manager_killer.erl b/src/lager_manager_killer.erl index 158b471..3f15dc4 100644 --- a/src/lager_manager_killer.erl +++ b/src/lager_manager_killer.erl @@ -4,6 +4,8 @@ -export([init/1, handle_event/2, handle_call/2, handle_info/2, terminate/2, code_change/3]). +-export([kill_me/0]). + -include("lager.hrl"). -record(state, { @@ -11,6 +13,9 @@ killer_reinstall_after :: non_neg_integer() }). +kill_me() -> + gen_event:call(lager_event, ?MODULE, kill_self). + init([KillerHWM, KillerReinstallAfter]) -> {ok, #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}}. @@ -20,6 +25,8 @@ handle_call({set_loglevel, _Level}, State) -> {ok, ok, State}; handle_call(get_settings, State = #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> {ok, [KillerHWM, KillerReinstallAfter], State}; +handle_call(kill_self, #state{killer_hwm=KillerHWM, killer_reinstall_after=KillerReinstallAfter}) -> + exit({kill_me, [KillerHWM, KillerReinstallAfter]}); handle_call(_Request, State) -> {ok, ok, State}. From 2d0351f0485b35cc327da8fb9dc791de6a3b1700 Mon Sep 17 00:00:00 2001 From: "Brian L. Troutwine" Date: Thu, 17 Mar 2016 13:06:02 -0700 Subject: [PATCH 05/11] Correct test failures for lager_handler_watcher. Signed-off-by: Brian L. Troutwine --- test/lager_manager_killer_test.erl | 68 ++++++++++++++++-------------- 1 file changed, 36 insertions(+), 32 deletions(-) diff --git a/test/lager_manager_killer_test.erl b/test/lager_manager_killer_test.erl index ac8898f..7a0622a 100644 --- a/test/lager_manager_killer_test.erl +++ b/test/lager_manager_killer_test.erl @@ -6,38 +6,42 @@ -ifdef(TEST). -include_lib("eunit/include/eunit.hrl"). -overload_test() -> - application:stop(lager), - application:load(lager), - Delay = 1000, % sleep 1 sec on every log - KillerHWM = 10, % kill the manager if there are more than 10 pending logs - KillerReinstallAfter = 1000, % reinstall killer after 1 sec - application:set_env(lager, handlers, [{lager_slow_backend, [{delay, Delay}]}]), - application:set_env(lager, async_threshold, undefined), - application:set_env(lager, killer_hwm, KillerHWM), - application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), - ensure_started(lager), - lager_config:set(async, true), - Manager = whereis(lager_event), - erlang:trace(all, true, [procs]), - [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], - Margin = 100, - ok = confirm_manager_exit(Manager, Delay+Margin), - ok = confirm_sink_reregister(Margin), - erlang:trace(all, false, [procs]), - wait_until(fun() -> - case proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event)) of - [] -> false; - _ -> true - end - end, Margin, 15), - wait_until(fun() -> - case gen_event:call(lager_event, lager_manager_killer, get_settings) of - [KillerHWM, KillerReinstallAfter] -> true; - _Other -> false - end - end, Margin, 15), - application:stop(lager). +overload_test_() -> + {timeout, 60, + fun() -> + application:stop(lager), + application:load(lager), + Delay = 1000, % sleep 1 sec on every log + KillerHWM = 10, % kill the manager if there are more than 10 pending logs + KillerReinstallAfter = 1000, % reinstall killer after 1 sec + application:set_env(lager, handlers, [{lager_slow_backend, [{delay, Delay}]}]), + application:set_env(lager, async_threshold, undefined), + application:set_env(lager, error_logger_redirect, true), + application:set_env(lager, killer_hwm, KillerHWM), + application:set_env(lager, killer_reinstall_after, KillerReinstallAfter), + ensure_started(lager), + lager_config:set(async, true), + Manager = whereis(lager_event), + erlang:trace(all, true, [procs]), + [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], + Margin = 100, + ok = confirm_manager_exit(Manager, Delay+Margin), + ok = confirm_sink_reregister(Margin), + erlang:trace(all, false, [procs]), + wait_until(fun() -> + case proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event)) of + [] -> false; + _ -> true + end + end, Margin, 15), + wait_until(fun() -> + case gen_event:call(lager_event, lager_manager_killer, get_settings) of + [KillerHWM, KillerReinstallAfter] -> true; + _Other -> false + end + end, Margin, 15), + application:stop(lager) + end}. ensure_started(App) -> case application:start(App) of From fb0064824bd58f70ede68dee40ffc4d7acd32559 Mon Sep 17 00:00:00 2001 From: "Brian L. Troutwine" Date: Fri, 18 Mar 2016 17:54:52 -0700 Subject: [PATCH 06/11] Correct removal of reinstall_handler. Signed-off-by: Brian L. Troutwine --- src/lager_handler_watcher.erl | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index 336ee06..3d13cd3 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -80,6 +80,9 @@ handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, ok end, {noreply, State}; +handle_info(reinstall_handler, #state{module=Module, config=Config, sink=Sink} = State) -> + install_handler(Sink, Module, Config), + {noreply, State}; handle_info(reboot, State) -> lager_app:boot(), {noreply, State}; From 4b5260c4524688b545cc12da6baa2dfa4f2afec9 Mon Sep 17 00:00:00 2001 From: Mark Allen Date: Tue, 29 Mar 2016 10:46:27 -0500 Subject: [PATCH 07/11] Overhaul start up and add killer config Previously, configuration would come from application:get_env/3 or proplists:get_value/3. Now we standardize on a single format for retrieving values from the environment or from a proplist. --- src/lager_app.erl | 106 +++++++++++++++++++++------------------------- 1 file changed, 49 insertions(+), 57 deletions(-) diff --git a/src/lager_app.erl b/src/lager_app.erl index 5ed1415..136caa5 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -29,7 +29,7 @@ start/2, start_handler/3, stop/1, - boot/0]). + boot/1]). -define(FILENAMES, '__lager_file_backend_filenames'). -define(THROTTLE, lager_backend_throttle). @@ -53,21 +53,19 @@ start_throttle(Sink, Threshold, Window) -> [Sink, ?THROTTLE, [Threshold, Window]]), ok. -determine_async_behavior(_Sink, {ok, undefined}, _Window) -> - ok; determine_async_behavior(_Sink, undefined, _Window) -> ok; -determine_async_behavior(_Sink, {ok, Threshold}, _Window) when not is_integer(Threshold) orelse Threshold < 0 -> +determine_async_behavior(_Sink, Threshold, _Window) when not is_integer(Threshold) orelse Threshold < 0 -> error_logger:error_msg("Invalid value for 'async_threshold': ~p~n", [Threshold]), throw({error, bad_config}); -determine_async_behavior(Sink, {ok, Threshold}, undefined) -> +determine_async_behavior(Sink, Threshold, undefined) -> start_throttle(Sink, Threshold, erlang:trunc(Threshold * 0.2)); -determine_async_behavior(_Sink, {ok, Threshold}, {ok, Window}) when not is_integer(Window) orelse Window > Threshold orelse Window < 0 -> +determine_async_behavior(_Sink, Threshold, Window) when not is_integer(Window) orelse Window > Threshold orelse Window < 0 -> error_logger:error_msg( "Invalid value for 'async_threshold_window': ~p~n", [Window]), throw({error, bad_config}); -determine_async_behavior(Sink, {ok, Threshold}, {ok, Window}) -> +determine_async_behavior(Sink, Threshold, Window) -> start_throttle(Sink, Threshold, Window). start_handlers(_Sink, undefined) -> @@ -119,14 +117,22 @@ clean_up_config_checks() -> interpret_hwm(undefined) -> undefined; -interpret_hwm({ok, undefined}) -> - undefined; -interpret_hwm({ok, HWM}) when not is_integer(HWM) orelse HWM < 0 -> +interpret_hwm(HWM) when not is_integer(HWM) orelse HWM < 0 -> _ = lager:log(warning, self(), "Invalid error_logger high water mark: ~p, disabling", [HWM]), undefined; -interpret_hwm({ok, HWM}) -> +interpret_hwm(HWM) -> HWM. +maybe_install_sink_killer(_Sink, undefined, _ReinstallTimer) -> ok; +maybe_install_sink_killer(Sink, HWM, undefined) -> maybe_install_sink_killer(Sink, HWM, 5000); +maybe_install_sink_killer(Sink, HWM, ReinstallTimer) when is_integer(HWM) andalso is_integer(ReinstallTimer) + andalso HWM >= 0 andalso ReinstallTimer >= 0 -> + _ = supervisor:start_child(lager_handler_watcher_sup, [Sink, lager_manager_killer, + [HWM, ReinstallTimer]]); +maybe_install_sink_killer(_Sink, HWM, ReinstallTimer) -> + error_logger:error_msg("Invalid value for 'killer_hwm': ~p or 'killer_reinstall_after': ~p", [HWM, ReinstallTimer]), + throw({error, bad_config}). + start_error_logger_handler({ok, false}, _HWM, _Whitelist) -> []; start_error_logger_handler(_, HWM, undefined) -> @@ -147,24 +153,6 @@ start_error_logger_handler(_, HWM, {ok, WhiteList}) -> throw({error, bad_config}) end, - %% Conditionally start the high watermark killer. - case application:get_env(lager, killer_hwm) of - undefined -> ok; - {ok, undefined} -> ok; - {ok, KillerHWM} when is_integer(KillerHWM), KillerHWM >= 0 -> - KillerReinstallAfter = case application:get_env(lager, killer_reinstall_after) of - undefined -> 5000; - {ok, undefined} -> 5000; - {ok, V} when is_integer(V), V >= 0 -> V; - {ok, BadKillerReinstallAfter} -> - error_logger:error_msg("Invalid value for 'cooldown': ~p~n", - [BadKillerReinstallAfter]), - throw({error, bad_config}) - end, - _ = supervisor:start_child(lager_handler_watcher_sup, - [?DEFAULT_SINK, lager_manager_killer, - [KillerHWM, KillerReinstallAfter]]) - end, case supervisor:start_child(lager_handler_watcher_sup, [error_logger, error_logger_lager_h, [HWM, GlStrategy]]) of {ok, _} -> @@ -174,17 +162,6 @@ start_error_logger_handler(_, HWM, {ok, WhiteList}) -> [] end. - -%% `determine_async_behavior/3' is called with the results from either -%% `application:get_env/2' and `proplists:get_value/2'. Since -%% `application:get_env/2' wraps a successful retrieval in an `{ok, -%% Value}' tuple, do the same for the result from -%% `proplists:get_value/2'. -wrap_proplist_value(undefined) -> - undefined; -wrap_proplist_value(Value) -> - {ok, Value}. - configure_sink(Sink, SinkDef) -> lager_config:new_sink(Sink), ChildId = lager_util:make_internal_sink_name(Sink), @@ -193,12 +170,11 @@ configure_sink(Sink, SinkDef) -> {gen_event, start_link, [{local, Sink}]}, permanent, 5000, worker, dynamic}), - determine_async_behavior(Sink, - wrap_proplist_value( - proplists:get_value(async_threshold, SinkDef)), - wrap_proplist_value( - proplists:get_value(async_threshold_window, SinkDef)) + determine_async_behavior(Sink, proplists:get_value(async_threshold, SinkDef), + proplists:get_value(async_threshold_window, SinkDef) ), + maybe_install_sink_killer(Sink, proplists:get_value(killer_hwm, SinkDef), + proplists:get_value(killer_reinstall_after, SinkDef)), start_handlers(Sink, proplists:get_value(handlers, SinkDef, [])), @@ -209,6 +185,8 @@ configure_extra_sinks(Sinks) -> lists:foreach(fun({Sink, Proplist}) -> configure_sink(Sink, Proplist) end, Sinks). +get_env(Application, Key) -> + get_env(Application, Key, undefined). %% R15 doesn't know about application:get_env/3 get_env(Application, Key, Default) -> get_env_default(application:get_env(Application, Key), @@ -222,35 +200,49 @@ get_env_default({ok, Value}, _Default) -> start(_StartType, _StartArgs) -> {ok, Pid} = lager_sup:start_link(), SavedHandlers = boot(), + _ = boot('__all_extra'), + _ = boot('__traces'), + clean_up_config_checks(), {ok, Pid, SavedHandlers}. boot() -> %% Handle the default sink. determine_async_behavior(?DEFAULT_SINK, - application:get_env(lager, async_threshold), - application:get_env(lager, async_threshold_window)), + get_env(lager, async_threshold), + get_env(lager, async_threshold_window)), + + maybe_install_sink_killer(?DEFAULT_SINK, get_env(lager, killer_hwm), + get_env(lager, killer_reinstall_after)), + start_handlers(?DEFAULT_SINK, get_env(lager, handlers, ?DEFAULT_HANDLER_CONF)), - lager:update_loglevel_config(?DEFAULT_SINK), SavedHandlers = start_error_logger_handler( - application:get_env(lager, error_logger_redirect), - interpret_hwm(application:get_env(lager, error_logger_hwm)), - application:get_env(lager, error_logger_whitelist) + get_env(lager, error_logger_redirect), + interpret_hwm(get_env(lager, error_logger_hwm)), + get_env(lager, error_logger_whitelist) ), - _ = lager_util:trace_filter(none), + SavedHandlers. - %% Now handle extra sinks - configure_extra_sinks(get_env(lager, extra_sinks, [])), +boot('__traces') -> + _ = lager_util:trace_filter(none), + ok = add_configured_traces(); - ok = add_configured_traces(), +boot('__all_extra') -> + configure_extra_sinks(get_env(lager, extra_sinks, [])); - clean_up_config_checks(), +boot(?DEFAULT_SINK) -> boot(); +boot(Sink) -> + AllSinksDef = get_env(lager, extra_sinks, []), + boot_sink(Sink, lists:keyfind(Sink, 1, AllSinksDef)). - SavedHandlers. +boot_sink(Sink, {Sink, Def}) -> + configure_sink(Sink, Def); +boot_sink(Sink, false) -> + configure_sink(Sink, []). stop(Handlers) -> lists:foreach(fun(Handler) -> From a170ebc9a5696806dad51f1b7b6746fcbb7f49c7 Mon Sep 17 00:00:00 2001 From: Mark Allen Date: Tue, 29 Mar 2016 10:48:19 -0500 Subject: [PATCH 08/11] Send the sink name with reboot message Previously, was always hardcoded to the default sink name. --- src/lager_handler_watcher.erl | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index 3d13cd3..df92584 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -64,10 +64,14 @@ handle_info({gen_event_EXIT, Module, shutdown}, #state{module=Module} = State) - handle_info({gen_event_EXIT, Module, {'EXIT', {kill_me, [_KillerHWM, KillerReinstallAfter]}}}, #state{module=Module, sink=Sink} = State) -> %% Brutally kill the manager but stay alive to restore settings. - Manager = whereis(Sink), - unlink(Manager), - exit(Manager, kill), - erlang:send_after(KillerReinstallAfter, self(), reboot), + %% + %% SinkPid here means the gen_event process. Handlers *all* live inside the + %% same gen_event process space, so when the Pid is killed, *all* of the + %% pending log messages in its mailbox will die too. + SinkPid = whereis(Sink), + unlink(SinkPid), + exit(SinkPid, kill), + erlang:send_after(KillerReinstallAfter, self(), {reboot, Sink}), {noreply, State}; handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, config=Config, sink=Sink} = State) -> @@ -83,8 +87,8 @@ handle_info({gen_event_EXIT, Module, Reason}, #state{module=Module, handle_info(reinstall_handler, #state{module=Module, config=Config, sink=Sink} = State) -> install_handler(Sink, Module, Config), {noreply, State}; -handle_info(reboot, State) -> - lager_app:boot(), +handle_info({reboot, Sink}, State) -> + lager_app:boot(Sink), {noreply, State}; handle_info(stop, State) -> {stop, normal, State}; From 7897f3462adff6327b9da7ee070058b772f2aff8 Mon Sep 17 00:00:00 2001 From: Mark Allen Date: Tue, 29 Mar 2016 16:28:56 -0500 Subject: [PATCH 09/11] Add a sleep to prevent losing race condition Lager logs its own application start up message. Previously this message was discarded or not received quickly enough to cause test failures, but now it seems as though it is being received and causing several test failures even though we are explicitly flushing it away. We introduce a 5 millisecond sleep for several tests to make sure the start up message is received before the flush command dumps it. --- src/lager_file_backend.erl | 11 +++++++++-- src/lager_handler_watcher.erl | 7 +++---- test/lager_test_backend.erl | 12 ++++++++++++ 3 files changed, 24 insertions(+), 6 deletions(-) diff --git a/src/lager_file_backend.erl b/src/lager_file_backend.erl index a0fd225..b32b39e 100644 --- a/src/lager_file_backend.erl +++ b/src/lager_file_backend.erl @@ -520,7 +520,12 @@ filesystem_test_() -> application:set_env(lager, handlers, [{lager_test_backend, info}]), application:set_env(lager, error_logger_redirect, false), application:set_env(lager, async_threshold, undefined), - lager:start() + lager:start(), + %% race condition where lager logs its own start up + %% makes several tests fail. See test/lager_test_backend + %% around line 800 for more information. + timer:sleep(5), + lager_test_backend:flush() end, fun(_) -> file:delete("test.log"), @@ -808,7 +813,9 @@ formatting_test_() -> application:load(lager), application:set_env(lager, handlers, [{lager_test_backend, info}]), application:set_env(lager, error_logger_redirect, false), - lager:start() + lager:start(), + %% same race condition issue + timer:sleep(5) end, fun(_) -> file:delete("test.log"), diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index df92584..e1ea43f 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -150,11 +150,10 @@ reinstall_on_initial_failure_test_() -> application:unset_env(lager, crash_log), lager:start(), try - ?assertEqual(1, lager_test_backend:count()), {_Level, _Time, Message, _Metadata} = lager_test_backend:pop(), ?assertMatch("Lager failed to install handler lager_crash_backend into lager_event, retrying later :"++_, lists:flatten(Message)), - ?assertEqual(0, lager_test_backend:count()), timer:sleep(6000), + lager_test_backend:flush(), ?assertEqual(0, lager_test_backend:count()), ?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))) after @@ -177,10 +176,10 @@ reinstall_on_runtime_failure_test_() -> application:unset_env(lager, crash_log), lager:start(), try - ?assertEqual(0, lager_test_backend:count()), ?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))), timer:sleep(6000), - ?assertEqual(2, lager_test_backend:count()), + _ = lager_test_backend:pop(), %% throw away application start up message + _ = lager_test_backend:pop(), %% throw away gen_event crash message {_Severity, _Date, Msg, _Metadata} = lager_test_backend:pop(), ?assertEqual("Lager event handler lager_crash_backend exited with reason crash", lists:flatten(Msg)), {_Severity2, _Date2, Msg2, _Metadata2} = lager_test_backend:pop(), diff --git a/test/lager_test_backend.erl b/test/lager_test_backend.erl index dd4950c..be32c2b 100644 --- a/test/lager_test_backend.erl +++ b/test/lager_test_backend.erl @@ -795,6 +795,18 @@ setup() -> application:set_env(lager, handlers, [{?MODULE, info}]), application:set_env(lager, error_logger_redirect, false), lager:start(), + %% There is a race condition between the application start up, lager logging its own + %% start up condition and several tests that count messages or parse the output of + %% tests. When the lager start up message wins the race, it causes these tests + %% which parse output or count message arrivals to fail. + %% + %% We introduce a sleep here to allow `flush' to arrive *after* the start up + %% message has been received and processed. + %% + %% This race condition was first exposed during the work on + %% 4b5260c4524688b545cc12da6baa2dfa4f2afec9 which introduced the lager + %% manager killer PR. + timer:sleep(5), gen_event:call(lager_event, ?MODULE, flush). cleanup(_) -> From 0a9dd17f9062c8429150bcaf751bec0e34772ae5 Mon Sep 17 00:00:00 2001 From: Mark Allen Date: Wed, 6 Apr 2016 23:10:01 -0500 Subject: [PATCH 10/11] Test manager killer on alternate sink --- test/lager_manager_killer_test.erl | 51 +++++++++++++++++++++++++++--- 1 file changed, 47 insertions(+), 4 deletions(-) diff --git a/test/lager_manager_killer_test.erl b/test/lager_manager_killer_test.erl index 7a0622a..96199b0 100644 --- a/test/lager_manager_killer_test.erl +++ b/test/lager_manager_killer_test.erl @@ -6,6 +6,9 @@ -ifdef(TEST). -include_lib("eunit/include/eunit.hrl"). +-define(TEST_SINK_NAME, '__lager_test_sink'). %% <-- used by parse transform +-define(TEST_SINK_EVENT, '__lager_test_sink_lager_event'). %% <-- used by lager API calls and internals for gen_event + overload_test_() -> {timeout, 60, fun() -> @@ -26,7 +29,7 @@ overload_test_() -> [lager:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], Margin = 100, ok = confirm_manager_exit(Manager, Delay+Margin), - ok = confirm_sink_reregister(Margin), + ok = confirm_sink_reregister(lager_event, Margin), erlang:trace(all, false, [procs]), wait_until(fun() -> case proplists:get_value(lager_manager_killer, gen_event:which_handlers(lager_event)) of @@ -43,6 +46,46 @@ overload_test_() -> application:stop(lager) end}. +overload_alternate_sink_test_() -> + {timeout, 60, + fun() -> + application:stop(lager), + application:load(lager), + Delay = 1000, % sleep 1 sec on every log + KillerHWM = 10, % kill the manager if there are more than 10 pending logs + KillerReinstallAfter = 1000, % reinstall killer after 1 sec + application:set_env(lager, handlers, []), + application:set_env(lager, extra_sinks, [{?TEST_SINK_EVENT, [ + {handlers, [{lager_slow_backend, [{delay, Delay}]}]}, + {killer_hwm, KillerHWM}, + {killer_reinstall_after, KillerReinstallAfter}, + {async_threshold, undefined} + ]}]), + application:set_env(lager, error_logger_redirect, true), + ensure_started(lager), + lager_config:set({?TEST_SINK_EVENT, async}, true), + Manager = whereis(?TEST_SINK_EVENT), + erlang:trace(all, true, [procs]), + [?TEST_SINK_NAME:info("~p'th message", [N]) || N <- lists:seq(1,KillerHWM+2)], + Margin = 100, + ok = confirm_manager_exit(Manager, Delay+Margin), + ok = confirm_sink_reregister(?TEST_SINK_EVENT, Margin), + erlang:trace(all, false, [procs]), + wait_until(fun() -> + case proplists:get_value(lager_manager_killer, gen_event:which_handlers(?TEST_SINK_EVENT)) of + [] -> false; + _ -> true + end + end, Margin, 15), + wait_until(fun() -> + case gen_event:call(?TEST_SINK_EVENT, lager_manager_killer, get_settings) of + [KillerHWM, KillerReinstallAfter] -> true; + _Other -> false + end + end, Margin, 15), + application:stop(lager) + end}. + ensure_started(App) -> case application:start(App) of ok -> @@ -63,10 +106,10 @@ confirm_manager_exit(Manager, Delay) -> ?assert(false) end. -confirm_sink_reregister(Delay) -> +confirm_sink_reregister(Sink, Delay) -> receive - {trace, _Pid, register, lager_event} -> - ?assertNot(lists:member(lager_manager_killer, gen_event:which_handlers(lager_event))) + {trace, _Pid, register, Sink} -> + ?assertNot(lists:member(lager_manager_killer, gen_event:which_handlers(Sink))) after Delay -> ?assert(false) end. From da14d152ba4980a68f995316d7b9041e3b14c4db Mon Sep 17 00:00:00 2001 From: Mark Allen Date: Wed, 6 Apr 2016 23:20:07 -0500 Subject: [PATCH 11/11] Fix dialyzer warnings --- src/lager_app.erl | 4 ++-- src/lager_handler_watcher.erl | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/lager_app.erl b/src/lager_app.erl index 136caa5..1d426d7 100644 --- a/src/lager_app.erl +++ b/src/lager_app.erl @@ -173,7 +173,7 @@ configure_sink(Sink, SinkDef) -> determine_async_behavior(Sink, proplists:get_value(async_threshold, SinkDef), proplists:get_value(async_threshold_window, SinkDef) ), - maybe_install_sink_killer(Sink, proplists:get_value(killer_hwm, SinkDef), + _ = maybe_install_sink_killer(Sink, proplists:get_value(killer_hwm, SinkDef), proplists:get_value(killer_reinstall_after, SinkDef)), start_handlers(Sink, proplists:get_value(handlers, SinkDef, [])), @@ -211,7 +211,7 @@ boot() -> get_env(lager, async_threshold), get_env(lager, async_threshold_window)), - maybe_install_sink_killer(?DEFAULT_SINK, get_env(lager, killer_hwm), + _ = maybe_install_sink_killer(?DEFAULT_SINK, get_env(lager, killer_hwm), get_env(lager, killer_reinstall_after)), start_handlers(?DEFAULT_SINK, diff --git a/src/lager_handler_watcher.erl b/src/lager_handler_watcher.erl index e1ea43f..d5fe140 100644 --- a/src/lager_handler_watcher.erl +++ b/src/lager_handler_watcher.erl @@ -88,7 +88,7 @@ handle_info(reinstall_handler, #state{module=Module, config=Config, sink=Sink} = install_handler(Sink, Module, Config), {noreply, State}; handle_info({reboot, Sink}, State) -> - lager_app:boot(Sink), + _ = lager_app:boot(Sink), {noreply, State}; handle_info(stop, State) -> {stop, normal, State};