kernel: Make all handler callbacks not block logger

2 files changed, 84 insertions, 11 deletions

diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
index 8a757f0078..8c5d4da70d 100644
--- a/lib/kernel/test/logger_SUITE.erl
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -218,14 +218,17 @@ change_config(_Config) ->
     {ok,{?MODULE,#{level:=info,filter_default:=stop}=C2}} =
         logger:get_handler_config(h1),
     false = maps:is_key(custom,C2),
-    {error,fail} = logger:set_handler_config(h1,#{fail=>true}),
+    {error,fail} = logger:set_handler_config(h1,#{conf_call=>fun() -> {error,fail} end}),
     {error,{attempting_syncronous_call_to_self,_}} =
         logger:set_handler_config(
-          h1,#{call=>fun() -> logger:set_module_level(?MODULE,debug) end}),
+          h1,#{conf_call=>fun() -> logger:set_handler_config(?MODULE,#{}) end}),
+    ok =
+        logger:set_handler_config(
+          h1,#{conf_call=>fun() -> logger:set_module_level(?MODULE,debug) end}),
     {ok,{?MODULE,C2}} = logger:get_handler_config(h1),
 
     %% Change one key only
-    {error,fail} = logger:set_handler_config(h1,fail,true),
+    {error,fail} = logger:set_handler_config(h1,conf_call,fun() -> {error,fail} end),
     ok = logger:set_handler_config(h1,custom,custom),
     [changing_config] = test_server:messages_get(),
     {ok,{?MODULE,#{custom:=custom}=C3}} = logger:get_handler_config(h1),
@@ -425,6 +428,7 @@ filter_failed(cleanup,_Config) ->
     ok.
 
 handler_failed(_Config) ->
+    register(callback_receiver,self()),
     {error,{invalid_id,1}} = logger:add_handler(1,?MODULE,#{}),
     {error,{invalid_module,"nomodule"}} = logger:add_handler(h1,"nomodule",#{}),
     {error,{invalid_handler_config,bad}} = logger:add_handler(h1,?MODULE,bad),
@@ -443,17 +447,58 @@ handler_failed(_Config) ->
     false = lists:keymember(h1,1,H1),
     {error,{not_found,h1}} = logger:remove_handler(h1),
 
-    ok = logger:add_handler(h2,?MODULE,#{filter_default=>log,crash=>true}),
+    ok = logger:add_handler(h2,?MODULE,#{filter_default=>log,log_call=>fun() -> a = b end}),
     {error,{already_exist,h2}} = logger:add_handler(h2,othermodule,#{}),
+    [add] = test_server:messages_get(),
 
     logger:info(?map_rep),
-    check_no_log(),
+    [remove] = test_server:messages_get(),
+
     #{logger:=#{handlers:=Ids2},
       handlers:=H2} = logger:i(),
     false = lists:member(h2,Ids2),
     false = lists:keymember(h2,1,H2),
     {error,{not_found,h2}} = logger:remove_handler(h2),
 
+    CallAddHandler = fun() -> logger:add_handler(h2,?MODULE,#{}) end,
+    CrashHandler = fun() -> a = b end,
+    KillHandler = fun() -> exit(self(), die) end,
+
+    {error,{handler_not_added,{attempting_syncronous_call_to_self,_}}} =
+        logger:add_handler(h1,?MODULE,#{add_call=>CallAddHandler}),
+    {error,{handler_not_added,{callback_crashed,_}}} =
+        logger:add_handler(h1,?MODULE,#{add_call=>CrashHandler}),
+    {error,{handler_not_added,{logger_process_exited,_,die}}} =
+        logger:add_handler(h1,?MODULE,#{add_call=>KillHandler}),
+
+    check_no_log(),
+    ok = logger:add_handler(h1,?MODULE,#{}),
+    {error,{attempting_syncronous_call_to_self,_}} =
+        logger:set_handler_config(h1,#{conf_call=>CallAddHandler}),
+    {error,{callback_crashed,_}} =
+        logger:set_handler_config(h1,#{conf_call=>CrashHandler}),
+    {error,{logger_process_exited,_,die}} =
+        logger:set_handler_config(h1,#{conf_call=>KillHandler}),
+
+    {error,{attempting_syncronous_call_to_self,_}} =
+        logger:set_handler_config(h1,conf_call,CallAddHandler),
+    {error,{callback_crashed,_}} =
+        logger:set_handler_config(h1,conf_call,CrashHandler),
+    {error,{logger_process_exited,_,die}} =
+        logger:set_handler_config(h1,conf_call,KillHandler),
+
+    ok = logger:remove_handler(h1),
+    [add,remove] = test_server:messages_get(),
+
+    check_no_log(),
+    ok = logger:add_handler(h1,?MODULE,#{rem_call=>CallAddHandler}),
+    ok = logger:remove_handler(h1),
+    ok = logger:add_handler(h1,?MODULE,#{rem_call=>CrashHandler}),
+    ok = logger:remove_handler(h1),
+    ok = logger:add_handler(h1,?MODULE,#{rem_call=>KillHandler}),
+    ok = logger:remove_handler(h1),
+    [add,add,add] = test_server:messages_get(),
+
     ok.
 
 handler_failed(cleanup,_Config) ->
@@ -720,16 +765,19 @@ check_maps(Expected,Got,What) ->
     end.
 
 %% Handler
+adding_handler(_Id,#{add_call:=Fun}) ->
+    Fun();
 adding_handler(_Id,Config) ->
     maybe_send(add),
     {ok,Config}.
+
+removing_handler(_Id,#{rem_call:=Fun}) ->
+    Fun();
 removing_handler(_Id,_Config) ->
     maybe_send(remove),
     ok.
-changing_config(_Id,_Old,#{call:=Fun}) ->
+changing_config(_Id,_Old,#{conf_call:=Fun}) ->
     Fun();
-changing_config(_Id,_Old,#{fail:=true}) ->
-    {error,fail};
 changing_config(_Id,_Old,Config) ->
     maybe_send(changing_config),
     {ok,Config}.
@@ -740,8 +788,8 @@ maybe_send(Msg) ->
         Pid -> Pid ! Msg
     end.
 
-log(_Log,#{crash:=true}) ->
-    a=b;
+log(_Log,#{log_call:=Fun}) ->
+    Fun();
 log(Log,Config) ->
     TcProc  = maps:get(tc_proc,Config,self()),
     TcProc ! {Log,Config},
diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl
index e976a10b21..764f443634 100644
--- a/lib/kernel/test/logger_env_var_SUITE.erl
+++ b/lib/kernel/test/logger_env_var_SUITE.erl
@@ -58,7 +58,8 @@ groups() ->
                  logger_disk_log_formatter,
                  logger_undefined,
                  logger_many_handlers_default_first,
-                 logger_many_handlers_default_last
+                 logger_many_handlers_default_last,
+                 logger_many_handlers_default_last_broken_filter
                 ]},
      {bad,[],[bad_error_logger,
               bad_level,
@@ -470,6 +471,8 @@ logger_undefined(Config) ->
     false = lists:keymember(sasl_h,1,Hs),
     ok.
 
+
+%% Test that we can add multiple handlers with the default first
 logger_many_handlers_default_first(Config) ->
     LogErr = file(Config,logger_many_handlers_default_first_error),
     LogInfo = file(Config,logger_many_handlers_default_first_info),
@@ -508,6 +511,28 @@ logger_many_handlers_default_last(Config) ->
                 }
                ]}], LogErr, LogInfo, 7).
 
+%% Check that we can handle that an added logger has a broken filter
+%% This used to cause a deadlock.
+logger_many_handlers_default_last_broken_filter(Config) ->
+    LogErr = file(Config,logger_many_handlers_default_first_broken_filter_error),
+    LogInfo = file(Config,logger_many_handlers_default_first_broken_filter_info),
+
+    logger_many_handlers(
+      Config,[{logger,
+               [{handler,info,logger_std_h,
+                 #{level=>info,
+                   filters=>[{broken,{fun logger_filters:level/2,broken_state}},
+                             {level,{fun logger_filters:level/2,{stop,gteq,error}}}],
+                   logger_std_h=>#{type=>{file,LogInfo}}}
+                },
+                {handler,?STANDARD_HANDLER,logger_std_h,
+                 #{level=>error,
+                   filters=>[],
+                   formatter=>{logger_formatter,#{}},
+                   logger_std_h=>#{type=>{file,LogErr}}}
+                }
+               ]}], LogErr, LogInfo, 7).
+
 logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) ->
     {ok,#{handlers:=Hs},Node} = setup(Config,Env),
     check_single_log(Node,LogErr,