File 1493-ERIERL-1010-common_test-html-log-total-time-fix.patch of Package erlang
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