Check logged errors in tests and hide them from the output

This was implemented before for error_logger, but the errors
were not hidden for OTP >= 21.0, where logger is used. Also,
some tests didn't use this mechanism so the logged errors
were printed also when running under older OTP releases.

With this change, the output from a successful test run is
tidy, so it is easy to spot if anything unexpected happens.

test/error_logger_acc.erl

@@ -2,6 +2,15 @@
 %% tests. The current error report handlers are disabled during the execution
 %% of a function. Afterwards, they are restored and the errors that occered are
 %% returned along with the return value of the fun.
+%%
+%% This module was created before OTP 21 when logger didn't exist. Logger
+%% support has been added later, but the log entries are still returned in the
+%% old error_logger format. Logger events which are not backwards compatible
+%% with error_logger are silently ignored, which is OK as long as only OTP
+%% proc_lib based processes are crashing and explicit logging is done via
+%% error_logger.
+%%
+%% TODO: Use logger by default and use error_logger only for old OTP releases.
 -module(error_logger_acc).
 
 -include("exception.hrl").
@@ -24,20 +33,24 @@
        AccumulatedErrors :: [{error|warning_msg|info_msg, string()} |
                              {error_report|warning_report|info_report, term()}].
 capture(Fun) when is_function(Fun, 0) ->
-
-    start_error_logger(),
-
-    OldHandlers = gen_event:which_handlers(error_logger),
+    %% From OTP 21.0, error_logger is no longer started by default, but is
+    %% automatically started when an event handler is added with
+    %% error_logger:add_report_handler/1,2. The error_logger module is then
+    %% also added as a handler to the new logger.
     error_logger:add_report_handler(?MODULE),
+    OldHandlers = gen_event:which_handlers(error_logger) -- [?MODULE],
     lists:foreach(fun error_logger:delete_report_handler/1, OldHandlers),
+    DefaultLoggerHandler = remove_default_logger_handler(),
     try Fun() of
         Result ->
             lists:foreach(fun error_logger:add_report_handler/1, OldHandlers),
+            restore_default_logger_handler(DefaultLoggerHandler),
             {ok, Result, error_logger:delete_report_handler(?MODULE)}
     catch
         ?EXCEPTION(Class, Error, Stacktrace) ->
             lists:foreach(fun error_logger:add_report_handler/1, OldHandlers),
             AccumulatedErrors = error_logger:delete_report_handler(?MODULE),
+            restore_default_logger_handler(DefaultLoggerHandler),
             {Class, Error, ?GET_STACK(Stacktrace), AccumulatedErrors}
     end.
 
@@ -74,14 +87,22 @@ terminate(_Arg, _State) ->
 code_change(_OldVsn, State, _Extra) ->
     {ok, State}.
 
-%% error logger is no longer started since erlang 21, start it explicitly
 -ifdef(OTP_RELEASE).
-start_error_logger() ->
-    error_logger:start(),
-    logger:add_handler(error_logger,error_logger,#{level=>info,filter_default=>log}).
+
+remove_default_logger_handler() ->
+    {ok, Config} = logger:get_handler_config(default),
+    ok = logger:remove_handler(default),
+    Config.
+
+restore_default_logger_handler(#{id := Id, module := Module} = Config) ->
+    logger:add_handler(Id, Module, Config).
+
 -else.
-start_error_logger() ->
-    ok.
+
+remove_default_logger_handler() -> none.
+
+restore_default_logger_handler(none) -> ok.
+
 -endif.
 
 -ifdef(TEST).

test/mysql_change_user_tests.erl

@@ -40,9 +40,16 @@ correct_credentials_test() ->
 incorrect_credentials_fail_test() ->
     Pid = connect_db(?user1, ?password1),
     TrapExit = erlang:process_flag(trap_exit, true),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () -> mysql:change_user(Pid, ?user2, ?password1) end),
+    ?assertMatch([{error, "Connection Id " ++ _}, % closing with reason: cha...
+                  {error, "** Generic server" ++ _},
+                  {error_report, {crash_report, _}}], Logged),
     ?assertMatch({error, {1045, <<"28000">>, <<"Access denied", _/binary>>}},
-                 mysql:change_user(Pid, ?user2, ?password1)),
-    ExitReason = receive {'EXIT', Pid, Reason} -> Reason after 1000 -> error(timeout) end,
+                 Ret),
+    ExitReason = receive {'EXIT', Pid, Reason} -> Reason
+                 after 1000 -> error(timeout)
+                 end,
     erlang:process_flag(trap_exit, TrapExit),
     ?assertEqual(change_user_failed, ExitReason),
     ?assertExit(noproc, mysql:stop(Pid)),
@@ -129,7 +136,15 @@ execute_queries_test() ->
 execute_queries_failure_test() ->
     Pid = connect_db(?user1, ?password1),
     erlang:process_flag(trap_exit, true),
-    {error, Reason} = mysql:change_user(Pid, ?user2, ?password2, [{queries, [<<"foo">>]}]),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () ->
+            mysql:change_user(Pid, ?user2, ?password2, [{queries, [<<"foo">>]}])
+        end),
+    ?assertMatch([{error, "Connection Id " ++ _}, % closing with reason: {1064,
+                  {error, "** Generic server" ++ _},
+                  {error_report, {crash_report, _}}], Logged),
+    {error, Reason} = Ret,
+    ?assertMatch({1064, <<"42000">>, <<"You have an erro", _/binary>>}, Reason),
     receive
         {'EXIT', Pid, Reason} -> ok
     after 1000 ->
@@ -139,7 +154,8 @@ execute_queries_failure_test() ->
 
 prepare_statements_test() ->
     Pid = connect_db(?user1, ?password1),
-    ?assertEqual(ok, mysql:change_user(Pid, ?user2, ?password2, [{prepare, [{foo, <<"SELECT ? AS foo">>}]}])),
+    ?assertEqual(ok, mysql:change_user(Pid, ?user2, ?password2,
+                                       [{prepare, [{foo, <<"SELECT ? AS foo">>}]}])),
     ?assert(is_current_user(Pid, ?user2)),
     ?assertEqual({ok,
                   [<<"foo">>],
@@ -151,7 +167,16 @@ prepare_statements_test() ->
 prepare_statements_failure_test() ->
     Pid = connect_db(?user1, ?password1),
     erlang:process_flag(trap_exit, true),
-    {error, Reason} = mysql:change_user(Pid, ?user2, ?password2, [{prepare, [{foo, <<"foo">>}]}]),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () ->
+            mysql:change_user(Pid, ?user2, ?password2,
+                              [{prepare, [{foo, <<"foo">>}]}])
+        end),
+    ?assertMatch([{error, "Connection Id " ++ _}, % closing with reason: {1064,
+                  {error, "** Generic server" ++ _},
+                  {error_report, {crash_report, _}}], Logged),
+    {error, Reason} = Ret,
+    ?assertMatch({1064, <<"42000">>, <<"You have an erro", _/binary>>}, Reason),
     receive
         {'EXIT', Pid, Reason} -> ok
     after 1000 ->

test/mysql_tests.erl

@@ -47,7 +47,12 @@
 
 failing_connect_test() ->
     process_flag(trap_exit, true),
-    {error, Error} = mysql:start_link([{user, "dummy"}, {password, "junk"}]),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () ->
+            mysql:start_link([{user, "dummy"}, {password, "junk"}])
+        end),
+    ?assertMatch([_|_], Logged), % some errors logged
+    {error, Error} = Ret,
     case Error of
         {1045, <<"28000">>, <<"Access denie", _/binary>>} ->
             ok; % MySQL 5.x, etc.
@@ -234,8 +239,13 @@ unix_socket_test() ->
 
 connect_queries_failure_test() ->
     process_flag(trap_exit, true),
-    {error, Reason} = mysql:start_link([{user, ?user}, {password, ?password},
-                                        {queries, ["foo"]}]),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () ->
+            mysql:start_link([{user, ?user}, {password, ?password},
+                              {queries, ["foo"]}])
+        end),
+    ?assertMatch([{error_report, {crash_report, _}}], Logged),
+    {error, Reason} = Ret,
     receive
         {'EXIT', _Pid, Reason} -> ok
     after 1000 ->
@@ -245,8 +255,14 @@ connect_queries_failure_test() ->
 
 connect_prepare_failure_test() ->
     process_flag(trap_exit, true),
-    {error, Reason} = mysql:start_link([{user, ?user}, {password, ?password},
-                                        {prepare, [{foo, "foo"}]}]),
+    {ok, Ret, Logged} = error_logger_acc:capture(
+        fun () ->
+            mysql:start_link([{user, ?user}, {password, ?password},
+                                                {prepare, [{foo, "foo"}]}])
+        end),
+    ?assertMatch([{error_report, {crash_report, _}}], Logged),
+    {error, Reason} = Ret,
+    ?assertMatch({1064, <<"42000">>, <<"You have an erro", _/binary>>}, Reason),
     receive
         {'EXIT', _Pid, Reason} -> ok
     after 1000 ->