From 0c6c4c13b31f2a91568bb3a04e63bc3c878d503c Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 14 Jun 2018 12:04:52 +0200 Subject: [logger] Stress overload_kill tests in disk_log handler --- lib/kernel/test/logger_disk_log_h_SUITE.erl | 59 ++++++++++++++++++++--------- lib/kernel/test/logger_std_h_SUITE.erl | 13 +++++-- 2 files changed, 51 insertions(+), 21 deletions(-) (limited to 'lib/kernel/test') diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 7225d4b57c..492730bd89 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -1063,7 +1063,7 @@ kill_disabled(cleanup, _Config) -> ok = stop_handler(?MODULE). qlen_kill_new(Config) -> - {_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), + {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), Pid0 = whereis(h_proc_name()), {_,Mem0} = process_info(Pid0, memory), RestartAfter = ?OVERLOAD_KILL_RESTART_AFTER, @@ -1076,7 +1076,7 @@ qlen_kill_new(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig), MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, - Procs = 2, + Procs = 4, send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive @@ -1087,8 +1087,8 @@ qlen_kill_new(Config) -> killed -> ct:pal("Slow shutdown, handler process was killed!", []) end, - timer:sleep(RestartAfter + 2000), - true = is_pid(whereis(h_proc_name())), + file_delete(Log), + {ok,_} = wait_for_process_up(RestartAfter * 3), ok after 5000 -> @@ -1100,7 +1100,7 @@ qlen_kill_new(cleanup, _Config) -> ok = stop_handler(?MODULE). mem_kill_new(Config) -> - {_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), + {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), Pid0 = whereis(h_proc_name()), {_,Mem0} = process_info(Pid0, memory), RestartAfter = ?OVERLOAD_KILL_RESTART_AFTER, @@ -1113,7 +1113,7 @@ mem_kill_new(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig), MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, - Procs = 2, + Procs = 4, send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive @@ -1124,8 +1124,8 @@ mem_kill_new(Config) -> killed -> ct:pal("Slow shutdown, handler process was killed!", []) end, - timer:sleep(RestartAfter + 2000), - true = is_pid(whereis(h_proc_name())), + file_delete(Log), + {ok,_} = wait_for_process_up(RestartAfter * 3), ok after 5000 -> @@ -1136,6 +1136,8 @@ mem_kill_new(Config) -> mem_kill_new(cleanup, _Config) -> ok = stop_handler(?MODULE). +restart_after() -> + [{timetrap,{minutes,2}}]. restart_after(Config) -> {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), NewHConfig1 = @@ -1145,14 +1147,16 @@ restart_after(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig1), MRef1 = erlang:monitor(process, whereis(h_proc_name())), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), + send_burst({n,100}, {spawn,4,0}, {chars,79}, notice), receive - {'DOWN', MRef1, _, _, _Info1} -> - timer:sleep(?OVERLOAD_KILL_RESTART_AFTER + 1000), - undefined = whereis(h_proc_name()), + {'DOWN', MRef1, _, _, _Reason1} -> + file_delete(Log), + error = wait_for_process_up(?OVERLOAD_KILL_RESTART_AFTER * 3), ok after 5000 -> + Info1 = logger_std_h:info(?MODULE), + ct:pal("Handler state = ~p", [Info1]), ct:fail("Handler not dead! It should not have survived this!") end, @@ -1166,16 +1170,17 @@ restart_after(Config) -> Pid0 = whereis(h_proc_name()), MRef2 = erlang:monitor(process, Pid0), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), + send_burst({n,100}, {spawn,4,0}, {chars,79}, notice), receive - {'DOWN', MRef2, _, _, _Info2} -> - timer:sleep(RestartAfter + 2000), - Pid1 = whereis(h_proc_name()), - true = is_pid(Pid1), + {'DOWN', MRef2, _, _, _Reason2} -> + file_delete(Log), + {ok,Pid1} = wait_for_process_up(RestartAfter * 3), false = (Pid1 == Pid0), ok after 5000 -> + Info2 = logger_std_h:info(?MODULE), + ct:pal("Handler state = ~p", [Info2]), ct:fail("Handler not dead! It should not have survived this!") end, ok. @@ -1539,3 +1544,23 @@ h_proc_name(Name) -> file_delete(Log) -> file:delete(Log). + +wait_for_process_up(T) -> + wait_for_process_up(h_proc_name(),T). + +wait_for_process_up(Name,T) -> + N = (T div 500) + 1, + wait_for_process_up1(Name,N). + +wait_for_process_up1(Name,0) -> + error; +wait_for_process_up1(Name,N) -> + timer:sleep(500), + case whereis(Name) of + Pid when is_pid(Pid) -> + %% ct:pal("Process ~p up (~p tries left)",[Name,N]), + {ok,Pid}; + undefined -> + %% ct:pal("Waiting for process ~p (~p tries left)",[Name,N]), + wait_for_process_up1(Name,N-1) + end. diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index e0bc79012c..c2cc7653ea 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -995,7 +995,7 @@ qlen_kill_new(Config) -> ct:pal("Slow shutdown, handler process was killed!", []) end, file_delete(Log), - {ok,_} = wait_for_process_up(h_proc_name(), RestartAfter * 3), + {ok,_} = wait_for_process_up(RestartAfter * 3), ok after 5000 -> @@ -1046,7 +1046,7 @@ mem_kill_new(Config) -> ct:pal("Slow shutdown, handler process was killed!", []) end, file_delete(Log), - {ok,_} = wait_for_process_up(h_proc_name(), RestartAfter * 3), + {ok,_} = wait_for_process_up(RestartAfter * 3), ok after 5000 -> @@ -1077,7 +1077,7 @@ restart_after(Config) -> receive {'DOWN', MRef1, _, _, _Reason1} -> file_delete(Log), - error = wait_for_process_up(h_proc_name(),?OVERLOAD_KILL_RESTART_AFTER * 3), + error = wait_for_process_up(?OVERLOAD_KILL_RESTART_AFTER * 3), ok after 5000 -> @@ -1100,7 +1100,7 @@ restart_after(Config) -> receive {'DOWN', MRef2, _, _, _Reason2} -> file_delete(Log), - {ok,Pid1} = wait_for_process_up(h_proc_name(),RestartAfter * 3), + {ok,Pid1} = wait_for_process_up(RestartAfter * 3), false = (Pid1 == Pid0), ok after @@ -1570,6 +1570,9 @@ h_proc_name(Name) -> file_delete(Log) -> file:delete(Log). +wait_for_process_up(T) -> + wait_for_process_up(h_proc_name(),T). + wait_for_process_up(Name,T) -> N = (T div 500) + 1, wait_for_process_up1(Name,N). @@ -1580,7 +1583,9 @@ wait_for_process_up1(Name,N) -> timer:sleep(500), case whereis(Name) of Pid when is_pid(Pid) -> + %% ct:pal("Process ~p up (~p tries left)",[Name,N]), {ok,Pid}; undefined -> + %% ct:pal("Waiting for process ~p (~p tries left)",[Name,N]), wait_for_process_up1(Name,N-1) end. -- cgit v1.2.3