Merge pull request #19 from basho/adt-test-less-dependant-on-timer
Make the tests less dependant on timer:sleep()
diff --git a/src/error_logger_lager_h.erl b/src/error_logger_lager_h.erl
index 30fa1bb..4c143d7 100644
--- a/src/error_logger_lager_h.erl
+++ b/src/error_logger_lager_h.erl
@@ -46,8 +46,14 @@
_ -> ok
end).
+-ifdef(TEST).
+%% Make CRASH synchronous when testing, to avoid timing headaches
+-define(CRASH_LOG(Event),
+ catch(gen_server:call(lager_crash_log, {log, Event}))).
+-else.
-define(CRASH_LOG(Event),
gen_server:cast(lager_crash_log, {log, Event})).
+-endif.
-spec init(any()) -> {ok, {}}.
init(_) ->
diff --git a/src/lager_crash_log.erl b/src/lager_crash_log.erl
index 430a046..75b2974 100644
--- a/src/lager_crash_log.erl
+++ b/src/lager_crash_log.erl
@@ -80,57 +80,16 @@
end.
%% @private
+handle_call({log, _} = Log, _From, State) ->
+ {Reply, NewState} = do_log(Log, State),
+ {reply, Reply, NewState};
handle_call(_Call, _From, State) ->
{reply, ok, State}.
%% @private
-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}} ->
- {"ERROR REPORT", Pid1, limited_fmt(Fmt, Args, FmtMaxBytes), true};
- {error_report, _GL, {Pid1, std_error, Rep}} ->
- {"ERROR REPORT", Pid1, limited_str(Rep, FmtMaxBytes), true};
- {error_report, _GL, Other} ->
- perhaps_a_sasl_report(error_report, Other, FmtMaxBytes);
- _ ->
- {ignore, ignore, ignore, false}
- end,
- if ReportStr == ignore ->
- {noreply, State};
- true ->
- case lager_util:ensure_logfile(Name, FD, Inode, false) of
- {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),
- 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)]),
- {noreply, State#state{fd=NewFD, inode=NewInode, flap=true}};
- ok ->
- {noreply, State#state{fd=NewFD, inode=NewInode, flap=false}};
- _ ->
- {noreply, State#state{fd=NewFD, inode=NewInode}}
- end;
- {error, Reason} ->
- case Flap of
- true ->
- {noreply, State};
- _ ->
- ?INT_LOG(error, "Failed to reopen crash log ~s with error: ~s",
- [Name, file:format_error(Reason)]),
- {noreply, State#state{flap=true}}
- end
- end
- end;
+handle_cast({log, _} = Log, State) ->
+ {_, NewState} = do_log(Log, State),
+ {noreply, NewState};
handle_cast(_Request, State) ->
{noreply, State}.
@@ -221,6 +180,55 @@
sasl_limited_str(crash_report, Report, FmtMaxBytes) ->
lager_stdlib:proc_lib_format(Report, FmtMaxBytes).
+do_log({log, Event}, #state{name=Name, fd=FD, inode=Inode, flap=Flap,
+ fmtmaxbytes=FmtMaxBytes, size=RotSize, count=Count} = State) ->
+ %% borrowed from riak_err
+ {ReportStr, Pid, MsgStr, _ErrorP} = case Event of
+ {error, _GL, {Pid1, Fmt, Args}} ->
+ {"ERROR REPORT", Pid1, limited_fmt(Fmt, Args, FmtMaxBytes), true};
+ {error_report, _GL, {Pid1, std_error, Rep}} ->
+ {"ERROR REPORT", Pid1, limited_str(Rep, FmtMaxBytes), true};
+ {error_report, _GL, Other} ->
+ perhaps_a_sasl_report(error_report, Other, FmtMaxBytes);
+ _ ->
+ {ignore, ignore, ignore, false}
+ end,
+ if ReportStr == ignore ->
+ {ok, State};
+ true ->
+ case lager_util:ensure_logfile(Name, FD, Inode, false) of
+ {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),
+ 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)]),
+ {ok, State#state{fd=NewFD, inode=NewInode, flap=true}};
+ ok ->
+ {ok, State#state{fd=NewFD, inode=NewInode, flap=false}};
+ _ ->
+ {ok, State#state{fd=NewFD, inode=NewInode}}
+ end;
+ {error, Reason} ->
+ case Flap of
+ true ->
+ {ok, State};
+ _ ->
+ ?INT_LOG(error, "Failed to reopen crash log ~s with error: ~s",
+ [Name, file:format_error(Reason)]),
+ {ok, State#state{flap=true}}
+ end
+ end
+ end.
+
+
-ifdef(TEST).
filesystem_test_() ->
@@ -250,8 +258,8 @@
{"under normal circumstances, file should be opened",
fun() ->
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
- error_logger:error_msg("Test message\n"),
- timer:sleep(100),
+ _ = gen_event:which_handlers(error_logger),
+ sync_error_logger:error_msg("Test message\n"),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}]))
end
@@ -270,18 +278,17 @@
fun() ->
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(0, lager_test_backend:count()),
- error_logger:error_msg("Test message\n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message\n"),
+ _ = gen_event:which_handlers(error_logger),
?assertEqual(1, lager_test_backend:count()),
file:delete("crash_test.log"),
file:write_file("crash_test.log", ""),
{ok, FInfo} = file:read_file_info("crash_test.log"),
file:write_file_info("crash_test.log", FInfo#file_info{mode = 0}),
- error_logger:error_msg("Test message\n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message\n"),
+ _ = gen_event:which_handlers(error_logger),
?assertEqual(3, lager_test_backend:count()),
lager_test_backend:pop(),
- lager_test_backend:pop(),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Failed to reopen crash log crash_test.log with error: permission denied", lists:flatten(Message))
end
@@ -296,8 +303,8 @@
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Failed to open crash log file crash_test.log with error: permission denied", lists:flatten(Message)),
file:write_file_info("crash_test.log", FInfo#file_info{mode = OldPerms}),
- error_logger:error_msg("Test message~n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message~n"),
+ _ = gen_event:which_handlers(error_logger),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}]))
end
@@ -306,19 +313,19 @@
fun() ->
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(0, lager_test_backend:count()),
- error_logger:error_msg("Test message~n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message~n"),
+ _ = gen_event:which_handlers(error_logger),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}])),
file:delete("crash_test.log"),
file:write_file("crash_test.log", ""),
- error_logger:error_msg("Test message1~n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message1~n"),
+ _ = gen_event:which_handlers(error_logger),
{ok, Bin1} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message1\n"], re:split(Bin1, "\n", [{return, list}, {parts, 2}])),
file:rename("crash_test.log", "crash_test.log.0"),
- error_logger:error_msg("Test message2~n"),
- timer:sleep(100),
+ sync_error_logger:error_msg("Test message2~n"),
+ _ = gen_event:which_handlers(error_logger),
{ok, Bin2} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message2\n"], re:split(Bin2, "\n", [{return, list}, {parts, 2}]))
end
diff --git a/src/lager_file_backend.erl b/src/lager_file_backend.erl
index 2562039..5debe3f 100644
--- a/src/lager_file_backend.erl
+++ b/src/lager_file_backend.erl
@@ -302,7 +302,6 @@
{ok, FInfo} = file:read_file_info("test.log"),
file:write_file_info("test.log", FInfo#file_info{mode = 0}),
lager:log(error, self(), "Test message"),
- timer:sleep(100),
?assertEqual(3, lager_test_backend:count()),
lager_test_backend:pop(),
lager_test_backend:pop(),
diff --git a/test/lager_test_backend.erl b/test/lager_test_backend.erl
index c216d44..445f5ce 100644
--- a/test/lager_test_backend.erl
+++ b/test/lager_test_backend.erl
@@ -194,12 +194,8 @@
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),
+ timer:sleep(100),
+ _ = gen_event:which_handlers(error_logger),
ok.
error_logger_redirect_crash_test_() ->
@@ -375,6 +371,7 @@
application:set_env(lager, error_logger_redirect, true),
application:set_env(lager, handlers, [{?MODULE, info}]),
application:start(lager),
+ lager:log(error, self(), "flush flush"),
timer:sleep(100),
gen_event:call(lager_event, ?MODULE, flush)
end,
@@ -386,8 +383,8 @@
[
{"error reports are printed",
fun() ->
- error_logger:error_report([{this, is}, a, {silly, format}]),
- custom_sleep(100),
+ sync_error_logger:error_report([{this, is}, a, {silly, format}]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[error] ~w this: is, a, silly: format", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -395,8 +392,8 @@
},
{"string error reports are printed",
fun() ->
- error_logger:error_report("this is less silly"),
- custom_sleep(100),
+ sync_error_logger:error_report("this is less silly"),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[error] ~w this is less silly", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -404,8 +401,8 @@
},
{"error messages are printed",
fun() ->
- error_logger:error_msg("doom, doom has come upon you all"),
- custom_sleep(100),
+ sync_error_logger:error_msg("doom, doom has come upon you all"),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[error] ~w doom, doom has come upon you all", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -413,16 +410,16 @@
},
{"error messages are truncated at 4096 characters",
fun() ->
- error_logger:error_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
- custom_sleep(1000),
+ sync_error_logger:error_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
?assert(length(lists:flatten(Msg)) < 5100)
end
},
{"info reports are printed",
fun() ->
- error_logger:info_report([{this, is}, a, {silly, format}]),
- custom_sleep(100),
+ sync_error_logger:info_report([{this, is}, a, {silly, format}]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w this: is, a, silly: format", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -430,16 +427,16 @@
},
{"info reports are truncated at 4096 characters",
fun() ->
- error_logger:info_report([[{this, is}, a, {silly, format}] || _ <- lists:seq(0, 600)]),
- custom_sleep(1000),
+ sync_error_logger:info_report([[{this, is}, a, {silly, format}] || _ <- lists:seq(0, 600)]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
?assert(length(lists:flatten(Msg)) < 5000)
end
},
{"single term info reports are printed",
fun() ->
- error_logger:info_report({foolish, bees}),
- custom_sleep(100),
+ sync_error_logger:info_report({foolish, bees}),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w {foolish,bees}", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -447,8 +444,8 @@
},
{"single term error reports are printed",
fun() ->
- error_logger:error_report({foolish, bees}),
- custom_sleep(100),
+ sync_error_logger:error_report({foolish, bees}),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[error] ~w {foolish,bees}", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -456,8 +453,8 @@
},
{"string info reports are printed",
fun() ->
- error_logger:info_report("this is less silly"),
- custom_sleep(100),
+ sync_error_logger:info_report("this is less silly"),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w this is less silly", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -465,8 +462,8 @@
},
{"string info reports are truncated at 4096 characters",
fun() ->
- error_logger:info_report(string:copies("this is less silly", 1000)),
- custom_sleep(1000),
+ sync_error_logger:info_report(string:copies("this is less silly", 1000)),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
?assert(length(lists:flatten(Msg)) < 5100)
end
@@ -474,8 +471,8 @@
{"info messages are printed",
fun() ->
- error_logger:info_msg("doom, doom has come upon you all"),
- custom_sleep(100),
+ sync_error_logger:info_msg("doom, doom has come upon you all"),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w doom, doom has come upon you all", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -483,8 +480,8 @@
},
{"info messages are truncated at 4096 characters",
fun() ->
- error_logger:info_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
- custom_sleep(1000),
+ sync_error_logger:info_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
?assert(length(lists:flatten(Msg)) < 5100)
end
@@ -492,9 +489,9 @@
{"warning messages are printed at the correct level",
fun() ->
- error_logger:warning_msg("doom, doom has come upon you all"),
+ sync_error_logger:warning_msg("doom, doom has come upon you all"),
Map = error_logger:warning_map(),
- custom_sleep(100),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[~w] ~w doom, doom has come upon you all", [Map, self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -502,9 +499,9 @@
},
{"warning reports are printed at the correct level",
fun() ->
- error_logger:warning_report([{i, like}, pie]),
+ sync_error_logger:warning_report([{i, like}, pie]),
Map = error_logger:warning_map(),
- custom_sleep(100),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[~w] ~w i: like, pie", [Map, self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -512,9 +509,9 @@
},
{"single term warning reports are printed at the correct level",
fun() ->
- error_logger:warning_report({foolish, bees}),
+ sync_error_logger:warning_report({foolish, bees}),
Map = error_logger:warning_map(),
- custom_sleep(100),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[~w] ~w {foolish,bees}", [Map, self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -522,8 +519,8 @@
},
{"application stop reports",
fun() ->
- error_logger:info_report([{application, foo}, {exited, quittin_time}, {type, lazy}]),
- custom_sleep(100),
+ sync_error_logger:info_report([{application, foo}, {exited, quittin_time}, {type, lazy}]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w Application foo exited with reason: quittin_time", [self()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -531,8 +528,8 @@
},
{"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}}]),
- custom_sleep(100),
+ sync_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),
{_, _, 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))
@@ -540,8 +537,8 @@
},
{"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}}]),
- custom_sleep(100),
+ sync_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),
{_, _, 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))
@@ -550,8 +547,8 @@
{"supervisor_bridge reports",
fun() ->
- error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{mod, mini_steve}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
- custom_sleep(100),
+ sync_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),
{_, _, 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))
@@ -559,8 +556,8 @@
},
{"application progress report",
fun() ->
- error_logger:info_report(progress, [{application, foo}, {started_at, node()}]),
- custom_sleep(100),
+ sync_error_logger:info_report(progress, [{application, foo}, {started_at, node()}]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, Msg} = pop(),
Expected = lists:flatten(io_lib:format("[info] ~w Application foo started on node ~w", [self(), node()])),
?assertEqual(Expected, lists:flatten(Msg))
@@ -569,8 +566,8 @@
{"supervisor progress report",
fun() ->
lager:set_loglevel(?MODULE, debug),
- error_logger:info_report(progress, [{supervisor, {local, foo}}, {started, [{mfargs, {foo, bar, 1}}, {pid, baz}]}]),
- custom_sleep(100),
+ sync_error_logger:info_report(progress, [{supervisor, {local, foo}}, {started, [{mfargs, {foo, bar, 1}}, {pid, baz}]}]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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))
@@ -578,8 +575,8 @@
},
{"crash report for emfile",
fun() ->
- error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {emfile, [{stack, trace, 1}]}, []}}], []]),
- custom_sleep(100),
+ sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {emfile, [{stack, trace, 1}]}, []}}], []]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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))
@@ -587,8 +584,8 @@
},
{"crash report for system process limit",
fun() ->
- error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn, 1}]}, []}}], []]),
- custom_sleep(100),
+ sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn, 1}]}, []}}], []]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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))
@@ -596,8 +593,8 @@
},
{"crash report for system process limit2",
fun() ->
- error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn_opt, 1}]}, []}}], []]),
- custom_sleep(100),
+ sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, spawn_opt, 1}]}, []}}], []]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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 +602,8 @@
},
{"crash report for system port limit",
fun() ->
- error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, open_port, 1}]}, []}}], []]),
- custom_sleep(100),
+ sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, open_port, 1}]}, []}}], []]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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))
@@ -614,8 +611,8 @@
},
{"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}]}, []}}], []]),
- custom_sleep(100),
+ sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit, [{erlang, list_to_atom, 1}]}, []}}], []]),
+ _ = gen_event:which_handlers(error_logger),
{_, _, 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))
@@ -623,8 +620,8 @@
},
{"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}]}, []}}], []]),
- custom_sleep(100),
+ sync_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),
{_, _, 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))
@@ -632,8 +629,8 @@
},
{"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)]}]}, []}}], []]),
- custom_sleep(1000),
+ sync_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),
{_, _, Msg} = pop(),
?assert(length(lists:flatten(Msg)) > 500),
?assert(length(lists:flatten(Msg)) < 700)
@@ -642,19 +639,19 @@
{"messages should not be generated if they don't satisfy the threshold",
fun() ->
lager:set_loglevel(?MODULE, error),
- error_logger:info_report([hello, world]),
- custom_sleep(100),
+ sync_error_logger:info_report([hello, world]),
+ _ = gen_event:which_handlers(error_logger),
?assertEqual(0, count()),
?assertEqual(0, count_ignored()),
lager:set_loglevel(?MODULE, info),
- error_logger:info_report([hello, world]),
- custom_sleep(100),
+ sync_error_logger:info_report([hello, world]),
+ _ = gen_event:which_handlers(error_logger),
?assertEqual(1, count()),
?assertEqual(0, count_ignored()),
lager:set_loglevel(?MODULE, error),
lager_mochiglobal:put(loglevel, ?DEBUG),
- error_logger:info_report([hello, world]),
- custom_sleep(100),
+ sync_error_logger:info_report([hello, world]),
+ _ = gen_event:which_handlers(error_logger),
?assertEqual(1, count()),
?assertEqual(1, count_ignored())
end
diff --git a/test/sync_error_logger.erl b/test/sync_error_logger.erl
new file mode 100644
index 0000000..078000f
--- /dev/null
+++ b/test/sync_error_logger.erl
@@ -0,0 +1,89 @@
+%%
+%% %CopyrightBegin%
+%%
+%% Copyright Ericsson AB 1996-2009. All Rights Reserved.
+%%
+%% The contents of this file are subject to the Erlang Public License,
+%% Version 1.1, (the "License"); you may not use this file except in
+%% compliance with the License. You should have received a copy of the
+%% Erlang Public License along with this software. If not, it can be
+%% retrieved online at http://www.erlang.org/.
+%%
+%% Software distributed under the License is distributed on an "AS IS"
+%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See
+%% the License for the specific language governing rights and limitations
+%% under the License.
+%%
+%% %CopyrightEnd%
+%%
+-module(sync_error_logger).
+
+%% The error_logger API, but synchronous!
+%% This is helpful for tests, otherwise you need lots of nasty timer:sleep.
+%% Additionally, the warning map can be set on a per-process level, for
+%% convienience, via the process dictionary value `warning_map'.
+
+-export([
+ info_msg/1, info_msg/2,
+ warning_msg/1, warning_msg/2,
+ error_msg/1,error_msg/2
+ ]).
+
+-export([
+ info_report/1, info_report/2,
+ warning_report/1, warning_report/2,
+ error_report/1, error_report/2
+ ]).
+
+info_msg(Format) ->
+ info_msg(Format, []).
+
+info_msg(Format, Args) ->
+ gen_event:sync_notify(error_logger, {info_msg, group_leader(), {self(), Format, Args}}).
+
+warning_msg(Format) ->
+ warning_msg(Format, []).
+
+warning_msg(Format, Args) ->
+ gen_event:sync_notify(error_logger, {warning_msg_tag(), group_leader(), {self(), Format, Args}}).
+
+error_msg(Format) ->
+ error_msg(Format, []).
+
+error_msg(Format, Args) ->
+ gen_event:sync_notify(error_logger, {error, group_leader(), {self(), Format, Args}}).
+
+info_report(Report) ->
+ info_report(std_info, Report).
+
+info_report(Type, Report) ->
+ gen_event:sync_notify(error_logger, {info_report, group_leader(), {self(), Type, Report}}).
+
+warning_report(Report) ->
+ warning_report(std_warning, Report).
+
+warning_report(Type, Report) ->
+ {Tag, NType} = warning_report_tag(Type),
+ gen_event:sync_notify(error_logger, {Tag, group_leader(), {self(), NType, Report}}).
+
+error_report(Report) ->
+ error_report(std_error, Report).
+
+error_report(Type, Report) ->
+ gen_event:sync_notify(error_logger, {error_report, group_leader(), {self(), Type, Report}}).
+
+warning_msg_tag() ->
+ case get(warning_map) of
+ warning -> warning_msg;
+ info -> info_msg;
+ _ -> error
+ end.
+
+warning_report_tag(Type) ->
+ case {get(warning_map), Type == std_warning} of
+ {warning, _} -> {warning_report, Type};
+ {info, true} -> {info_report, std_info};
+ {info, false} -> {info_report, Type};
+ {_, true} -> {error_report, std_error};
+ {_, false} -> {error_report, Type}
+ end.
