Move EUnit sleep & sync stuff to new custom_sleep() func

test/lager_test_backend.erl

@@ -193,6 +193,12 @@ crash(Type) ->
     spawn(fun() -> gen_server:call(crash, Type) end),
     timer:sleep(100).
 
+custom_sleep(MSec) ->
+    timer:sleep(MSec),
+    [_|_] = gen_event:which_handlers(error_logger),
+    [_|_] = gen_event:which_handlers(lager_event),
+    ok.
+
 error_logger_redirect_crash_test_() ->
     {foreach,
         fun() ->
@@ -362,8 +368,7 @@ error_logger_redirect_test_() ->
             {"error reports are printed",
                 fun() ->
                         error_logger:error_report([{this, is}, a, {silly, format}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w this: is, a, silly: format", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -372,8 +377,7 @@ error_logger_redirect_test_() ->
             {"string error reports are printed",
                 fun() ->
                         error_logger:error_report("this is less silly"),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w this is less silly", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -382,8 +386,7 @@ error_logger_redirect_test_() ->
             {"error messages are printed",
                 fun() ->
                         error_logger:error_msg("doom, doom has come upon you all"),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w doom, doom has come upon you all", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -392,8 +395,7 @@ error_logger_redirect_test_() ->
             {"error messages are truncated at 4096 characters",
                 fun() ->
                         error_logger:error_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(1000),
+                        custom_sleep(1000),
                         {_, _, Msg} = pop(),
                         ?assert(length(lists:flatten(Msg)) < 5100)
                 end
@@ -401,8 +403,7 @@ error_logger_redirect_test_() ->
             {"info reports are printed",
                 fun() ->
                         error_logger:info_report([{this, is}, a, {silly, format}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w this: is, a, silly: format", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -411,8 +412,7 @@ error_logger_redirect_test_() ->
             {"info reports are truncated at 4096 characters",
                 fun() ->
                         error_logger:info_report([[{this, is}, a, {silly, format}] || _ <- lists:seq(0, 600)]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(1000),
+                        custom_sleep(1000),
                         {_, _, Msg} = pop(),
                         ?assert(length(lists:flatten(Msg)) < 5000)
                 end
@@ -420,8 +420,7 @@ error_logger_redirect_test_() ->
             {"single term info reports are printed",
                 fun() ->
                         error_logger:info_report({foolish, bees}),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w {foolish,bees}", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -430,8 +429,7 @@ error_logger_redirect_test_() ->
             {"single term error reports are printed",
                 fun() ->
                         error_logger:error_report({foolish, bees}),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w {foolish,bees}", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -440,8 +438,7 @@ error_logger_redirect_test_() ->
             {"string info reports are printed",
                 fun() ->
                         error_logger:info_report("this is less silly"),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w this is less silly", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -450,8 +447,7 @@ error_logger_redirect_test_() ->
             {"string info reports are truncated at 4096 characters",
                 fun() ->
                         error_logger:info_report(string:copies("this is less silly", 1000)),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(1000),
+                        custom_sleep(1000),
                         {_, _, Msg} = pop(),
                         ?assert(length(lists:flatten(Msg)) < 5100)
                 end
@@ -460,8 +456,7 @@ error_logger_redirect_test_() ->
             {"info messages are printed",
                 fun() ->
                         error_logger:info_msg("doom, doom has come upon you all"),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w doom, doom has come upon you all", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -470,8 +465,7 @@ error_logger_redirect_test_() ->
             {"info messages are truncated at 4096 characters",
                 fun() ->
                         error_logger:info_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(1000),
+                        custom_sleep(1000),
                         {_, _, Msg} = pop(),
                         ?assert(length(lists:flatten(Msg)) < 5100)
                 end
@@ -481,8 +475,7 @@ error_logger_redirect_test_() ->
                 fun() ->
                         error_logger:warning_msg("doom, doom has come upon you all"),
                         Map = error_logger:warning_map(),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[~w] ~w doom, doom has come upon you all", [Map, self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -492,8 +485,7 @@ error_logger_redirect_test_() ->
                 fun() ->
                         error_logger:warning_report([{i, like}, pie]),
                         Map = error_logger:warning_map(),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[~w] ~w i: like, pie", [Map, self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -503,8 +495,7 @@ error_logger_redirect_test_() ->
                 fun() ->
                         error_logger:warning_report({foolish, bees}),
                         Map = error_logger:warning_map(),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[~w] ~w {foolish,bees}", [Map, self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -513,8 +504,7 @@ error_logger_redirect_test_() ->
             {"application stop reports",
                 fun() ->
                         error_logger:info_report([{application, foo}, {exited, quittin_time}, {type, lazy}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w Application foo exited with reason: quittin_time", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -523,8 +513,7 @@ error_logger_redirect_test_() ->
             {"supervisor reports",
                 fun() ->
                         error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{name, mini_steve}, {mfargs, {a, b, [c]}}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child mini_steve started with a:b(c) at bleh exit with reason fired in context france", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -533,8 +522,7 @@ error_logger_redirect_test_() ->
             {"supervisor reports with real error",
                 fun() ->
                         error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{name, mini_steve}, {mfargs, {a, b, [c]}}, {pid, bleh}]}, {reason, {function_clause,[{crash,handle_info,[foo]}]}}, {supervisor, {local, steve}}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child mini_steve started with a:b(c) at bleh exit with reason no function clause matching crash:handle_info(foo) in context france", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -544,8 +532,7 @@ error_logger_redirect_test_() ->
             {"supervisor_bridge reports",
                 fun() ->
                         error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{mod, mini_steve}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child at module mini_steve at bleh exit with reason fired in context france", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -554,8 +541,7 @@ error_logger_redirect_test_() ->
             {"application progress report",
                 fun() ->
                         error_logger:info_report(progress, [{application, foo}, {started_at, node()}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[info] ~w Application foo started on node ~w", [self(), node()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -565,8 +551,7 @@ error_logger_redirect_test_() ->
                 fun() ->
                         lager:set_loglevel(?MODULE, debug),
                         error_logger:info_report(progress, [{supervisor, {local, foo}}, {started, [{mfargs, {foo, bar, 1}}, {pid, baz}]}]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[debug] ~w Supervisor foo started foo:bar/1 at pid baz", [self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -575,8 +560,7 @@ error_logger_redirect_test_() ->
             {"crash report for emfile",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {emfile, [{stack, trace, 1}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: maximum number of file descriptors exhausted, check ulimit -n", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -585,8 +569,7 @@ error_logger_redirect_test_() ->
             {"crash report for system process limit",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn, 1}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of processes exceeded", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -595,8 +578,7 @@ error_logger_redirect_test_() ->
             {"crash report for system process limit2",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn_opt, 1}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of processes exceeded", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -605,8 +587,7 @@ error_logger_redirect_test_() ->
             {"crash report for system port limit",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, open_port, 1}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of ports exceeded", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -615,8 +596,7 @@ error_logger_redirect_test_() ->
             {"crash report for system port limit",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, list_to_atom, 1}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: tried to create an atom larger than 255, or maximum atom count exceeded", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -625,8 +605,7 @@ error_logger_redirect_test_() ->
             {"crash report for system ets table limit",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit,[{ets,new,[segment_offsets,[ordered_set,public]]},{mi_segment,open_write,1},{mi_buffer_converter,handle_cast,2},{gen_server,handle_msg,5},{proc_lib,init_p_do_apply,3}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         {_, _, Msg} = pop(),
                         Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of ETS tables exceeded", [self(), self()])),
                         ?assertEqual(Expected, lists:flatten(Msg))
@@ -635,8 +614,7 @@ error_logger_redirect_test_() ->
             {"crash report for unknown system limit should be truncated at 500 characters",
                 fun() ->
                         error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit,[{wtf,boom,[string:copies("aaaa", 4096)]}]}, []}}], []]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(1000),
+                        custom_sleep(1000),
                         {_, _, Msg} = pop(),
                         ?assert(length(lists:flatten(Msg)) > 500),
                         ?assert(length(lists:flatten(Msg)) < 700)
@@ -646,21 +624,18 @@ error_logger_redirect_test_() ->
                 fun() ->
                         lager:set_loglevel(?MODULE, error),
                         error_logger:info_report([hello, world]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         ?assertEqual(0, count()),
                         ?assertEqual(0, count_ignored()),
                         lager:set_loglevel(?MODULE, info),
                         error_logger:info_report([hello, world]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         ?assertEqual(1, count()),
                         ?assertEqual(0, count_ignored()),
                         lager:set_loglevel(?MODULE, error),
                         lager_mochiglobal:put(loglevel, ?DEBUG),
                         error_logger:info_report([hello, world]),
-                        _ = gen_event:which_handlers(error_logger),
-                        timer:sleep(100),
+                        custom_sleep(100),
                         ?assertEqual(1, count()),
                         ?assertEqual(1, count_ignored())
                 end