File 1016-ERIERL-1010-common_test-html-log-total-tim... of Package erlang

Overview Repositories Revisions Requests Users Attributes Meta

File 1016-ERIERL-1010-common_test-html-log-total-time-fix.patch of Package erlang (Revision 147fb24ecc7389ec5e91cbf5b419c961)

Currently displaying revision 147fb24ecc7389ec5e91cbf5b419c961 , Show latest

From d9f438c0c79220f6d4eb0ae6ebb348f3487726a1 Mon Sep 17 00:00:00 2001
From: Konrad Pietrzak <konrad@erlang.org>
Date: Thu, 7 Mar 2024 13:15:50 +0100
Subject: [PATCH] [ERIERL-1010] common_test html log total time fix

---
 lib/common_test/doc/src/basics_chapter.xml |  10 +-
 lib/common_test/src/test_server_ctrl.erl   | 128 ++++++++++++---------
 2 files changed, 85 insertions(+), 53 deletions(-)

diff --git a/lib/common_test/doc/src/basics_chapter.xml b/lib/common_test/doc/src/basics_chapter.xml
index 359237289e..49bdb9435d 100644
--- a/lib/common_test/doc/src/basics_chapter.xml
+++ b/lib/common_test/doc/src/basics_chapter.xml
@@ -190,7 +190,15 @@
       has a link to each test case log file, providing simple navigation with any standard
       HTML browser.
     </p>
-    </section>
+    <note>
+      <p>
+        In the last row where totals are presented the time shown here is a
+        sum of rows, which are above (not accounting for parallel testcases). On
+        the other hand "Elapsed Time" is a clock time spent to run testcases.
+      </p>
+    </note>
+  </section>
+
 
   <section>
 <marker id="External_Interfaces"></marker>
diff --git a/lib/common_test/src/test_server_ctrl.erl b/lib/common_test/src/test_server_ctrl.erl
index e80e899c44..77880e4cb3 100644
--- a/lib/common_test/src/test_server_ctrl.erl
+++ b/lib/common_test/src/test_server_ctrl.erl
@@ -1130,7 +1130,7 @@ init_tester(Mod, Func, Args, Dir, Name, {_,_,MinLev}=Levels,
     put(app, common_test),
     put(test_server_name, Name),
     put(test_server_dir, Dir),
-    put(test_server_total_time, 0),
+    put(test_server_total_time, 0.0),
     put(test_server_ok, 0),
     put(test_server_failed, 0),
     put(test_server_skipped, {0,0}),
@@ -1181,7 +1181,7 @@ init_tester(Mod, Func, Args, Dir, Name, {_,_,MinLev}=Levels,
 	    report_severe_error(Reason),
 	    print(1, "EXIT, reason ~tp", [Reason])
     end,
-    Time = TimeMy/1000000,
+    ElapsedTimeSeconds = TimeMy/1000000,
     SuccessStr =
 	case get(test_server_failed) of
 	    0 -> "Ok";
@@ -1197,11 +1197,14 @@ init_tester(Mod, Func, Args, Dir, Name, {_,_,MinLev}=Levels,
 	end,
     OkN = get(test_server_ok),
     FailedN = get(test_server_failed),
+    TotalTestTime = get(test_server_total_time),
     print(html,"\n</tbody>\n<tfoot>\n"
-	  "<tr><td></td><td><b>TOTAL</b></td><td></td><td></td><td></td>"
-	  "<td>~.3fs</td><td><b>~ts</b></td><td>~w Ok, ~w Failed~ts of ~w</td></tr>\n"
-	  "</tfoot>\n",
-	  [Time,SuccessStr,OkN,FailedN,SkipStr,OkN+FailedN+SkippedN]),
+          "<tr><td></td><td><b>TOTAL</b></td><td></td><td></td><td></td>"
+          "<td>~.3fs<br></td><td><b>~ts</b></td><td>~w Ok, ~w Failed~ts of ~w<br>"
+          "Elapsed Time: ~.3fs</td></tr>\n"
+          "</tfoot>\n",
+          [TotalTestTime,SuccessStr,OkN,FailedN,SkipStr,OkN+FailedN+SkippedN,
+           ElapsedTimeSeconds]),
 
     test_server_io:stop([major,html,unexpected_io]),
     {UnexpectedIoName,UnexpectedIoFooter} = get(test_server_unexpected_footer),
@@ -2548,7 +2551,6 @@ run_test_cases_loop([{conf,Ref,Props,{Mod,Func}}|_Cases]=Cs0,
 			After = ?now,
 			Before = get(test_server_parallel_start_time),
 			Elapsed = timer:now_diff(After, Before)/1000000,
-			put(test_server_total_time, Elapsed),
 			{false,tl(Mode0),undefined,Elapsed,
 			 update_status(Ref, OkSkipFail, Status)};
 		    _ ->
@@ -3706,37 +3708,46 @@ handle_io_and_exit_loop(_, [], Ok,Skip,Fail) ->
 
 handle_io_and_exits(Main, CurrPid, CaseNum, Mod, Func, Cases) ->
     receive
-	{abort_current_testcase=Tag,_Reason,From} ->
-	    %% If a parallel group is executing, there is no unique
-	    %% current test case, so we must generate an error.
-	    From ! {self(),Tag,{error,parallel_group}},
-	    handle_io_and_exits(Main, CurrPid, CaseNum, Mod, Func, Cases);
-	%% end of io session from test case executed by main process
-	{finished,_,Main,CaseNum,Mod,Func,Result,_RetVal} ->
-	    test_server_io:print_buffered(CurrPid),
-	    {Result,{Mod,Func}};
-	%% end of io session from test case executed by parallel process
-	{finished,_,CurrPid,CaseNum,Mod,Func,Result,RetVal} ->
-	    test_server_io:print_buffered(CurrPid),
-	    case Result of
-		ok ->
-		    put(test_server_ok, get(test_server_ok)+1);
-		failed ->
-		    put(test_server_failed, get(test_server_failed)+1);
-		skipped ->
-		    SkipCounters =
-			update_skip_counters(RetVal, get(test_server_skipped)),
-		    put(test_server_skipped, SkipCounters)
-	    end,
-	    {Result,{Mod,Func}};
-
-	%% unexpected termination of test case process
-	{'EXIT',TCPid,Reason} when Reason /= normal ->
-	    test_server_io:print_buffered(CurrPid),
-	    {value,{_,_,Num,M,F}} = lists:keysearch(TCPid, 2, Cases),
-	    print(1, "Error! Process for test case #~w (~w:~tw) died! Reason: ~tp",
-		  [Num, M, F, Reason]),
-	    exit({unexpected_termination,{Num,M,F},{TCPid,Reason}})
+        {abort_current_testcase=Tag,_Reason,From} ->
+            %% If a parallel group is executing, there is no unique
+            %% current test case, so we must generate an error.
+            From ! {self(),Tag,{error,parallel_group}},
+            handle_io_and_exits(Main, CurrPid, CaseNum, Mod, Func, Cases);
+        %% end of io session from test case executed by main process
+        {finished,_,Main,CaseNum,Mod,Func,Result,_RetVal} ->
+            test_server_io:print_buffered(CurrPid),
+            {Result,{Mod,Func}};
+        %% end of io session from test case executed by parallel process
+        {finished,_,CurrPid,CaseNum,Mod,Func,Result,RetVal} ->
+            test_server_io:print_buffered(CurrPid),
+            case Result of
+                ok ->
+                    {ReturnTime, _, _} = RetVal,
+                    put(test_server_total_time, get(test_server_total_time) + ReturnTime),
+                    put(test_server_ok, get(test_server_ok)+1),
+                    ReturnTime;
+                failed ->
+                    ReturnTime = case RetVal of
+                                     {_, T} when is_number(T) -> T;
+                                     _ -> 0
+                                 end,
+                    put(test_server_total_time, get(test_server_total_time) + ReturnTime),
+                    put(test_server_failed, get(test_server_failed)+1),
+                    ReturnTime;
+                skipped ->
+                    SkipCounters =
+                    update_skip_counters(RetVal, get(test_server_skipped)),
+                    put(test_server_skipped, SkipCounters)
+            end,
+            {Result,{Mod,Func}};
+
+        %% unexpected termination of test case process
+        {'EXIT',TCPid,Reason} when Reason /= normal ->
+            test_server_io:print_buffered(CurrPid),
+            {value,{_,_,Num,M,F}} = lists:keysearch(TCPid, 2, Cases),
+            print(1, "Error! Process for test case #~w (~w:~tw) died! Reason: ~tp",
+            [Num, M, F, Reason]),
+            exit({unexpected_termination,{Num,M,F},{TCPid,Reason}})
     end.
 
 
@@ -3952,18 +3963,31 @@ run_test_case1(Ref, Num, Mod, Func, Args, RunInit,
     %% status count on the main process (status of parallel test cases
     %% is updated later by the handle_test_case_io_and_status/0 function)
     case {RunInit,Status} of
-	{skip_init,_} ->			% conf doesn't count
-	    ok;
-	{_,ok} ->
-	    put(test_server_ok, get(test_server_ok)+1);
-	{_,failed} ->
-	    put(test_server_failed, get(test_server_failed)+1);
-	{_,skip} ->
-	    {US,AS} = get(test_server_skipped),
-	    put(test_server_skipped, {US+1,AS});
-	{_,auto_skip} ->
-	    {US,AS} = get(test_server_skipped),
-	    put(test_server_skipped, {US,AS+1})
+        {skip_init,_} ->			% conf doesn't count
+            ok;
+        {_,ok} ->
+            case Loc of
+                [{Module, _}] when Module =/= ct_framework ->
+                    put(test_server_total_time, get(test_server_total_time) + Time);
+                _ -> not_a_test_fun
+            end,
+            put(test_server_ok, get(test_server_ok)+1);
+        {_,failed} ->
+            DiedTime = case Time of
+                           died -> case RetVal of
+                                       {_,T} when is_number(T) -> T;
+                                       _ -> 0
+                                   end;
+                           T when is_number(T) -> T
+                       end,
+            put(test_server_total_time, get(test_server_total_time) + DiedTime),
+            put(test_server_failed, get(test_server_failed)+1);
+        {_,skip} ->
+            {US,AS} = get(test_server_skipped),
+            put(test_server_skipped, {US+1,AS});
+        {_,auto_skip} ->
+            {US,AS} = get(test_server_skipped),
+            put(test_server_skipped, {US,AS+1})
     end,
     %% only if test case execution is sequential do we care about the
     %% remaining processes and slave nodes count
@@ -4009,9 +4033,9 @@ run_test_case1(Ref, Num, Mod, Func, Args, RunInit,
     %% time count on the main process (adding execution time of parallel test
     %% case groups is done in run_test_cases_loop/4)
     if is_number(Time) ->
-	    put(test_server_total_time, get(test_server_total_time)+Time);
+            put(test_server_total_time, get(test_server_total_time)+Time);
        true ->
-	    ok
+            ok
     end,
     test_server_sup:check_new_crash_dumps(),
 
-- 
2.35.3

Places

File 1016-ERIERL-1010-common_test-html-log-total-time-fix.patch of Package erlang (Revision 147fb24ecc7389ec5e91cbf5b419c961)

Places