From b07d6b52556f45c9f000d067baad2d6c93c6f58e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ignas=20Vy=C5=A1niauskas?= Date: Wed, 12 Feb 2014 16:27:45 +0100 Subject: [PATCH] Only discard gen_event notifications on high watermark Previously all messages were being flushed, which meant that trapped exits and internal gen_event messaging was also flushed, leading to undefined behaviour. closes #198 --- src/error_logger_lager_h.erl | 24 ++++------------ test/lager_test_backend.erl | 56 ++++++++++++++++++++++++++++++++++++ 2 files changed, 62 insertions(+), 18 deletions(-) diff --git a/src/error_logger_lager_h.erl b/src/error_logger_lager_h.erl index 4a64528..321afc7 100644 --- a/src/error_logger_lager_h.erl +++ b/src/error_logger_lager_h.erl @@ -131,7 +131,12 @@ discard_messages(Second, Count) -> case Second of {M, S, _} -> receive - _Msg -> + %% we only discard gen_event notifications, because + %% otherwise we might discard gen_event internal + %% messages, such as trapped EXITs + {notify, _Event} -> + discard_messages(Second, Count+1); + {_From, _Tag, {sync_notify, _Event}} -> discard_messages(Second, Count+1) after 0 -> Count @@ -419,20 +424,3 @@ get_value(Key, List, Default) -> supervisor_name({local, Name}) -> Name; supervisor_name(Name) -> Name. --ifdef(TEST). - -%% Not intended to be a fully paranoid EUnit test.... - -t0() -> - application:stop(lager), - application:stop(sasl), - lager:start(), - set_high_water(5), - [error_logger:warning_msg("Foo ~p!", [X]) || X <- lists:seq(1,10)], - timer:sleep(1000), - [error_logger:warning_msg("Bar ~p!", [X]) || X <- lists:seq(1,10)], - timer:sleep(1000), - error_logger:warning_msg("Baz!"), - ok. - --endif. % TEST diff --git a/test/lager_test_backend.erl b/test/lager_test_backend.erl index 648bdb9..c9d727f 100644 --- a/test/lager_test_backend.erl +++ b/test/lager_test_backend.erl @@ -1204,6 +1204,62 @@ collect_workers(Workers) -> collect_workers(lists:keydelete(Ref, 2, Workers)) end. +produce_n_error_logger_msgs(N) -> + lists:foreach(fun (K) -> + error_logger:error_msg("Foo ~p!", [K]) + end, + lists:seq(0, N-1) + ). + +high_watermark_test_() -> + {foreach, + fun() -> + error_logger:tty(false), + application:load(lager), + application:set_env(lager, error_logger_redirect, true), + application:set_env(lager, handlers, [{lager_test_backend, info}]), + application:set_env(lager, async_threshold, undefined), + lager:start() + end, + fun(_) -> + application:stop(lager), + error_logger:tty(true) + end, + [ + {"Nothing dropped when error_logger high watermark is undefined", + fun () -> + ok = error_logger_lager_h:set_high_water(undefined), + timer:sleep(100), + produce_n_error_logger_msgs(10), + timer:sleep(500), + ?assert(count() >= 10) + end + }, + {"Mostly dropped according to error_logger high watermark", + fun () -> + ok = error_logger_lager_h:set_high_water(5), + timer:sleep(100), + produce_n_error_logger_msgs(50), + timer:sleep(1000), + ?assert(count() < 20) + end + }, + {"Non-notifications are not dropped", + fun () -> + ok = error_logger_lager_h:set_high_water(2), + timer:sleep(100), + spawn(fun () -> produce_n_error_logger_msgs(300) end), + timer:sleep(50), + %% if everything were dropped, this call would be dropped + %% too, so lets hope it's not + ?assert(is_integer(count())), + timer:sleep(1000), + ?assert(count() < 10) + end + } + ] + }. + -endif.