Merge branch 'peppe/common_test/crash_during_close' into maint

* peppe/common_test/crash_during_close:
  Solve memory consumption problem
  Fix problem with buffered async io messages executed too late
  Don't generate weird exit if ct_logs has terminated before shut down

OTP-12159

1 files changed, 49 insertions, 18 deletions

diff --git a/lib/common_test/src/ct_logs.erl b/lib/common_test/src/ct_logs.erl
index 43eabb18d5..7037cdca73 100644
--- a/lib/common_test/src/ct_logs.erl
+++ b/lib/common_test/src/ct_logs.erl
@@ -129,7 +129,13 @@ datestr_from_dirname([]) ->
 close(Info, StartDir) ->
     %% close executes on the ct_util process, not on the logger process
     %% so we need to use a local copy of the log cache data
-    LogCacheBin = make_last_run_index(),
+    LogCacheBin = 
+	case make_last_run_index() of
+	    {error,_} ->  % log server not responding
+		undefined;
+	    LCB ->
+		LCB
+	end,
     put(ct_log_cache,LogCacheBin),
     Cache2File = fun() ->
 			 case get(ct_log_cache) of
@@ -710,6 +716,7 @@ logger_loop(State) ->
 			end
 		end,
 	    if Importance >= (100-VLvl) ->
+		    CtLogFd = State#logger_state.ct_log_fd,
 		    case get_groupleader(Pid, GL, State) of
 			{tc_log,TCGL,TCGLs} ->
 			    case erlang:is_process_alive(TCGL) of
@@ -723,14 +730,15 @@ logger_loop(State) ->
 				    %% Group leader is dead, so write to the
 				    %% CtLog or unexpected_io log instead
 				    unexpected_io(Pid,Category,Importance,
-						  List,State),
+						  List,CtLogFd),
+
 				    logger_loop(State)			    
 			    end;
 			{ct_log,_Fd,TCGLs} ->
 			    %% If category is ct_internal then write
 			    %% to ct_log, else write to unexpected_io
 			    %% log
-			    unexpected_io(Pid,Category,Importance,List,State),
+			    unexpected_io(Pid,Category,Importance,List,CtLogFd),
 			    logger_loop(State#logger_state{
 					  tc_groupleaders = TCGLs})
 		    end;
@@ -803,16 +811,15 @@ logger_loop(State) ->
 	    ok
     end.
 
-create_io_fun(FromPid, State) ->
+create_io_fun(FromPid, CtLogFd) ->
     %% we have to build one io-list of all strings
     %% before printing, or other io printouts (made in
     %% parallel) may get printed between this header 
     %% and footer
-    Fd = State#logger_state.ct_log_fd,
     fun({Str,Args}, IoList) ->
 	    case catch io_lib:format(Str,Args) of
 		{'EXIT',_Reason} ->
-		    io:format(Fd, "Logging fails! Str: ~p, Args: ~p~n",
+		    io:format(CtLogFd, "Logging fails! Str: ~p, Args: ~p~n",
 			      [Str,Args]),
 		    %% stop the testcase, we need to see the fault
 		    exit(FromPid, {log_printout_error,Str,Args}),
@@ -827,28 +834,53 @@ create_io_fun(FromPid, State) ->
 print_to_log(sync, FromPid, Category, TCGL, List, State) ->
     %% in some situations (exceptions), the printout is made from the
     %% test server IO process and there's no valid group leader to send to
+    CtLogFd = State#logger_state.ct_log_fd,
     if FromPid /= TCGL ->
-	    IoFun = create_io_fun(FromPid, State),
+	    IoFun = create_io_fun(FromPid, CtLogFd),
 	    io:format(TCGL,"~ts", [lists:foldl(IoFun, [], List)]);
        true ->
-	    unexpected_io(FromPid,Category,?MAX_IMPORTANCE,List,State)
+	    unexpected_io(FromPid,Category,?MAX_IMPORTANCE,List,CtLogFd)
     end,
     State;
 
 print_to_log(async, FromPid, Category, TCGL, List, State) ->
     %% in some situations (exceptions), the printout is made from the
     %% test server IO process and there's no valid group leader to send to
+    CtLogFd = State#logger_state.ct_log_fd,
     Printer =
 	if FromPid /= TCGL ->
-		IoFun = create_io_fun(FromPid, State),
+		IoFun = create_io_fun(FromPid, CtLogFd),
 		fun() ->
 			test_server:permit_io(TCGL, self()),
-			io:format(TCGL, "~ts", [lists:foldl(IoFun, [], List)])
+
+			%% Since asynchronous io gets can get buffered if
+			%% the file system is slow, there is also a risk that
+			%% the group leader has terminated before we get to
+			%% the io:format(GL, ...) call. We check this and
+			%% print "expired" messages to the unexpected io
+			%% log instead (best we can do).
+
+			case erlang:is_process_alive(TCGL) of
+			    true ->
+				try io:format(TCGL, "~ts",
+					      [lists:foldl(IoFun,[],List)]) of
+				    _ -> ok
+				catch
+				    _:terminated ->
+					unexpected_io(FromPid, Category,
+						      ?MAX_IMPORTANCE,
+						      List, CtLogFd)
+				end;
+			    false ->
+				unexpected_io(FromPid, Category,
+					      ?MAX_IMPORTANCE,
+					      List, CtLogFd)
+			end
 		end;
 	   true ->
 		fun() ->
-			unexpected_io(FromPid,Category,?MAX_IMPORTANCE,
-				      List,State)
+			unexpected_io(FromPid, Category, ?MAX_IMPORTANCE,
+				      List, CtLogFd)
 		end
 	end,
     case State#logger_state.async_print_jobs of
@@ -3149,12 +3181,11 @@ html_encoding(latin1) ->
 html_encoding(utf8) ->
     "utf-8".
 
-unexpected_io(Pid,ct_internal,_Importance,List,State) ->
-    IoFun = create_io_fun(Pid,State),
-    io:format(State#logger_state.ct_log_fd, "~ts",
-	      [lists:foldl(IoFun, [], List)]);
-unexpected_io(Pid,_Category,_Importance,List,State) ->
-    IoFun = create_io_fun(Pid,State),
+unexpected_io(Pid,ct_internal,_Importance,List,CtLogFd) ->
+    IoFun = create_io_fun(Pid,CtLogFd),
+    io:format(CtLogFd, "~ts", [lists:foldl(IoFun, [], List)]);
+unexpected_io(Pid,_Category,_Importance,List,CtLogFd) ->
+    IoFun = create_io_fun(Pid,CtLogFd),
     Data = io_lib:format("~ts", [lists:foldl(IoFun, [], List)]),
     test_server_io:print_unexpected(Data),
     ok.