ct: Allow running tests more silently / improve ct_run's terminal output

HOWTO/DEVELOPMENT.md

@@ -213,6 +213,15 @@ for all process you would do this:
 ERL_ARGS="+hmqd off_heap" make emulator_test
 ```
 
+If you want to keep test script information about starting and stopping the run
+to a minimum, you can pass `-s` or `--silent`:
+
+```bash
+make test -s
+```
+
+This will also quiet down other logs emitted by `make`.
+
 ### Build and test a specific application
 
 You can also build the application from within itself. Like this:

Makefile.in

@@ -1007,8 +1007,12 @@ bootstrap_clean:
 
 .PHONY: test dialyzer
 
+ifeq ($(findstring s,${MAKEFLAGS}),s)
+	TEST_EXTRA_ARGS = --quiet
+endif
+
 test: all release release_tests
-	$(ERL_TOP)/make/test_target_script.sh $(ERL_TOP)
+	$(ERL_TOP)/make/test_target_script.sh $(TEST_EXTRA_ARGS) $(ERL_TOP)
 
 ifeq ($(TYPE),)
 dialyzer: all

lib/common_test/doc/src/ct_hooks_chapter.xml

@@ -511,6 +511,23 @@ results(State) ->
         use another level either change the <c>default</c> handler level before
         starting common_test, or use the <seemfa marker="kernel:logger#set_handler_config/3">
         <c>logger:set_handler_config/3</c></seemfa> API.</p>
+        <p>This hook supports the following options:</p>
+        <taglist>
+          <tag><c>{mode, replace}</c></tag>
+          <item>
+            <p>Replace the <c>default</c> logging handler by the log redirect
+              instead of logging to both the default handler and the
+              <c>cth_log_redirect</c> handler. This is the default behaviour.</p>
+          </item>
+          <tag><c>{mode, add}</c></tag>
+          <item>
+            <p>Add the logging handler instead of replacing the default logging
+              handler. To use this mode, pass the <c>-verbose</c> flag to <c>ct_run</c>.
+              <c>-verbose</c> is the short form of disabling the builtin
+              configuration of the hook and reconfiguring it:</p>
+            <p><c>-enable_builtin_hooks false -ct_hooks cth_log_redirect [{mode,add}]</c></p>
+          </item>
+        </taglist>
        </item>
        <tag><c>cth_surefire</c></tag>
        <item>

lib/common_test/doc/src/ct_run_cmd.xml

@@ -107,6 +107,7 @@
   [-logopts LogOpts]
   [-verbosity GenVLevel | [Category1 VLevel1 and
    Category2 VLevel2 and .. CategoryN VLevelN]]
+  [-verbose]
   [-silent_connections [ConnType1 ConnType2 .. ConnTypeN]]
   [-stylesheet CSSFile]
   [-cover CoverCfgFile]
@@ -147,6 +148,7 @@
   [-logopts LogOpts]
   [-verbosity GenVLevel | [Category1 VLevel1 and
    Category2 VLevel2 and .. CategoryN VLevelN]]
+  [-verbose]
   [-allow_user_terms]
   [-silent_connections [ConnType1 ConnType2 .. ConnTypeN]]
   [-stylesheet CSSFile]

lib/common_test/doc/src/run_test_chapter.xml

@@ -269,6 +269,11 @@
       <item><p>Sets <seeguide marker="write_test_chapter#logging">verbosity levels
       for printouts</seeguide>.</p></item>
 
+      <tag><c><![CDATA[-verbose]]></c></tag>
+      <item><p>Enables output of supervisor reports and other logging messages
+      directly to the terminal as the test is running. If not supplied, these
+      messages will be captured and only show up in the HTML report.</p></item>
+
       <tag><c><![CDATA[-no_esc_chars]]></c></tag>
       <item><p>Disables automatic escaping of special HTML characters.
       See the <seeguide marker="write_test_chapter#logging">Logging chapter</seeguide>.</p></item>

lib/common_test/src/Makefile

@@ -47,6 +47,7 @@ MODULES= \
 	ct \
 	ct_logs \
 	ct_framework \
+	ct_console \
 	ct_ftp \
 	ct_ssh \
 	ct_snmp \

lib/common_test/src/ct_console.erl

@@ -0,0 +1,210 @@
+% Deals with output formatting for the terminal.
+
+-module(ct_console).
+-export([print_header/1, print_results/1, pluralize/3]).
+
+%% Colored output formatting characters
+% If adding a new format here, make sure to add it to `size_on_terminal/1`.
+-define(TERM_BOLD, "\033[;1m").
+-define(TERM_BOLD_GREEN, "\033[;1;32m").
+-define(TERM_BLACK, "\033[;30m").
+-define(TERM_RED, "\033[;31m").
+-define(TERM_GREEN, "\033[;32m").
+-define(TERM_YELLOW, "\033[;33m").
+-define(TERM_CLEAR, "\033[0m").
+
+-spec print_results(map()) -> ok.
+print_results(#{results := [_ | _]} = Results) ->
+    {FailedTestResults, ResultsWithoutFailures} = maps:take(results, Results),
+    ShouldColor = should_use_colored_output(),
+    print_header("failed tests follow", mc(?TERM_RED, ShouldColor)),
+    print_failed_test_results(FailedTestResults),
+    print_results(ResultsWithoutFailures);
+
+print_results(#{total := #{passed := OkN, failed := FailedN,
+                           user_skipped := UserSkipN, auto_skipped := AutoSkipN},
+                elapsed := Elapsed}) ->
+    AllSkippedN = UserSkipN + AutoSkipN,
+    ShouldColor = should_use_colored_output(),
+    PassedStr = format_if_nonzero(OkN, "~s~w passed~s",
+                                  [mc(?TERM_BOLD_GREEN, ShouldColor), OkN, ?TERM_CLEAR]),
+    SkipStr = format_if_nonzero(AllSkippedN, "~s~w skipped~s",
+                                [mc(?TERM_YELLOW, ShouldColor), AllSkippedN, ?TERM_CLEAR]),
+    FailedStr = format_if_nonzero(FailedN, "~s~w failed~s",
+                                  [mc(?TERM_RED, ShouldColor), FailedN, ?TERM_CLEAR]),
+    NonemptyStrs = lists:filter(fun(Item) -> Item =/= "" end, [PassedStr, SkipStr, FailedStr]),
+    TimeDescription = format_time(Elapsed),
+    PaddingColor = result_padding_color(OkN, FailedN, ShouldColor),
+    FormattedTimeDescription = io_lib:format("~s in ~s~s", [PaddingColor, TimeDescription, ?TERM_CLEAR]),
+    ResultStr = lists:join(", ", NonemptyStrs) ++ FormattedTimeDescription,
+    ResultSize = size_on_terminal(ResultStr),
+    {PaddingSizeLeft, PaddingSizeRight} = centering_padding_size(ResultSize),
+    {PaddingLeft, PaddingRight} = padding_characters(PaddingSizeLeft, PaddingSizeRight),
+    io:fwrite(
+        user,
+        "~s~ts~s~ts~s~ts~s~n",
+        [PaddingColor, PaddingLeft, ?TERM_CLEAR, ResultStr, PaddingColor, PaddingRight, ?TERM_CLEAR]
+    ).
+
+
+print_failed_test_results([#{reason := Reason, module := Module, function := Function} | Rest]) ->
+    io:fwrite(user, "=> test case ~s:~s:~n", [Module, Function]),
+    {CrashReason, TracebackOrDetail} = format_failure_reason(Reason),
+    io:fwrite(user, "~tp~n~tp~n~n", [CrashReason, elide_framework_code(TracebackOrDetail)]),
+    print_failed_test_results(Rest);
+
+print_failed_test_results([]) ->
+    ok.
+
+%% @doc
+%% Format the reason why a test failed into the expected tuple format with the
+%% following two elements:
+%%
+%% - The reason why the test failed, such as an explicit `test_case_failed' or
+%%   `badmatch' errors, or some other value returned by the test.
+%% - The traceback of the test, as a list. Can be empty. When explicitly
+%%   failing a test, this will instead contain a string describing why the test
+%%   was failed.
+%% @end
+format_failure_reason({'EXIT', Reason, Traceback}) -> {{'EXIT', Reason}, Traceback};
+format_failure_reason({Reason, undefined}) -> {Reason, []};
+format_failure_reason({_Reason, _Traceback} = Result) -> Result.
+
+-spec result_padding_color(non_neg_integer(), non_neg_integer(), boolean()) -> string().
+result_padding_color(_Ok, 0, ShouldColor) -> mc(?TERM_GREEN, ShouldColor);
+result_padding_color(_Ok, _Failed, ShouldColor) -> mc(?TERM_RED, ShouldColor).
+
+-spec format_if_nonzero(non_neg_integer(), io:format(), [term()]) -> string().
+format_if_nonzero(0, _Format, _Data) -> "";
+format_if_nonzero(_, Format, Data) -> io_lib:format(Format, Data).
+
+-spec print_header(string()) -> ok.
+print_header(Message) ->
+    ShouldColor = should_use_colored_output(),
+    print_header(Message, mc(?TERM_BOLD, ShouldColor)).
+
+-spec print_header(string(), string()) -> ok.
+print_header(Message, StartingColor) ->
+    io:fwrite(user, "~s", [format_header(Message, StartingColor)]).
+
+-spec format_header(string(), string()) -> string().
+format_header(Message, StartingColor) ->
+    {PaddingSizeLeft, PaddingSizeRight} = centering_padding_size(iolist_size(Message)),
+    % shell_docs contains a lot of useful functions that we could maybe factor
+    % out and use here.
+    Stop = ?TERM_CLEAR,
+    {PaddingLeft, PaddingRight} = padding_characters(PaddingSizeLeft, PaddingSizeRight),
+    io_lib:format("~s~ts~s~ts~s~n", [StartingColor, PaddingLeft, Message, PaddingRight, Stop]).
+
+
+-spec padding_characters(integer(), integer()) -> {string(), string()}.
+% Dialyzer said this can't happen
+%padding_characters(SizeLeft, _SizeRight) when SizeLeft < 0 ->
+%    % Not enough space to print the padding, proceed normally.
+%    {"", ""};
+padding_characters(SizeLeft, SizeRight) ->
+    Left = lists:duplicate(SizeLeft, "="),
+    Right = lists:duplicate(SizeRight, "="),
+    {Left ++ " ", [" " | Right]}.
+
+-spec centering_padding_size(integer()) -> {integer(), integer()}.
+centering_padding_size(MessageSize) ->
+    {ok, Columns} = terminal_width(user),
+    PaddingSizeLeft = trunc(Columns / 2) - trunc(MessageSize / 2) - 1,
+    PaddingSizeRight = header_right_padding(Columns, PaddingSizeLeft, MessageSize),
+    {PaddingSizeLeft, PaddingSizeRight}.
+
+
+-spec pluralize(non_neg_integer(), string()) -> string().
+pluralize(Amount, Singular) ->
+    pluralize(Amount, Singular, Singular ++ "s").
+
+-spec pluralize(non_neg_integer(), string(), string()) -> string().
+pluralize(1, Singular, _Plural) -> Singular;
+pluralize(_, _Singular, Plural) -> Plural.
+
+
+-spec terminal_width(atom()) -> {ok, pos_integer()}.
+terminal_width(Driver) ->
+    case io:columns(Driver) of
+        {ok, _Columns} = Result ->
+            Result;
+        {error, enotsup} ->
+            {ok, 80}
+    end.
+
+-spec header_right_padding(pos_integer(), pos_integer(), pos_integer()) -> pos_integer().
+header_right_padding(_Columns, LeftPadding, MessageSize) when MessageSize rem 2 == 1 ->
+    LeftPadding - 1;
+header_right_padding(Columns, LeftPadding, _MessageSize) when Columns rem 2 == 0 ->
+    LeftPadding;
+header_right_padding(_Columns, LeftPadding, _MessageSize) ->
+    LeftPadding + 1.
+
+-spec size_on_terminal(iolist()) -> non_neg_integer().
+size_on_terminal(?TERM_BOLD ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_BOLD_GREEN ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_BLACK ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_RED ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_GREEN ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_YELLOW ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal(?TERM_CLEAR ++ Rest) -> size_on_terminal(Rest);
+size_on_terminal([Items | Rest]) when is_list(Items) -> size_on_terminal(Items) + size_on_terminal(Rest);
+size_on_terminal([Char | Rest]) when is_integer(Char) -> 1 + size_on_terminal(Rest);
+size_on_terminal([]) -> 0.
+
+%% @doc
+%% Elide framework code from the given traceback or exit reason. If the test
+%% was failed explicitly due to some reason that did not generate a traceback,
+%% such as an explicit fail, the given argument is passed through unchanged.
+%% @end
+-spec elide_framework_code(list()) -> list().
+elide_framework_code([{test_server, _Function, _Location} | Rest]) ->
+    elide_framework_code(Rest);
+elide_framework_code([Frame | Rest]) ->
+    [Frame | elide_framework_code(Rest)];
+elide_framework_code([]) ->
+    [];
+elide_framework_code(Value) ->
+    Value.
+
+
+%% @doc Turn the given seconds into a human-readable string.
+-spec format_time(non_neg_integer()) -> string().
+format_time(Seconds) ->
+    Minutes = trunc(Seconds / 60),
+    RemainingSeconds = Seconds rem 60,
+    case Minutes of
+        0 ->
+            io_lib:format("~w ~s", [Seconds, pluralize(Seconds, "second")]);
+        _ ->
+            io_lib:format("~w ~s and ~w ~s", [Minutes, pluralize(Minutes, "minute"),
+                                              RemainingSeconds, pluralize(RemainingSeconds, "second")])
+    end.
+
+
+%% @doc
+%% Return the given string if colorized output is wanted, else an empty string.
+%% `mc' => "maybe color".
+%% @end
+-spec mc(string(), ShouldColor :: boolean()) -> string().
+mc(Color, true) -> Color;
+mc(_Color, false) -> "".
+
+
+-spec should_use_colored_output() -> boolean().
+should_use_colored_output() ->
+    NoColor = os:getenv("NO_COLOR"),
+    StdoutIsATty = stdout_is_a_tty(),
+    NoColor == false andalso StdoutIsATty.
+
+
+-spec stdout_is_a_tty() -> boolean().
+stdout_is_a_tty() ->
+    user_drv ! {self(), get_terminal_state},
+    receive
+        {_Pid, get_terminal_state, IsATty} ->
+            IsATty
+        after 500 ->
+            false
+    end.

lib/common_test/src/ct_framework.erl

@@ -985,10 +985,7 @@ error_notification(Mod,Func,_Args,{Error,Loc}) ->
     end,
 
     PrintError = fun(ErrorFormat, ErrorArgs) ->
-                      Div = "\n- - - - - - - - - - - - - - - - - - - "
-                            "- - - - - - - - - - - - - - - - - - - - -\n",
 		       ErrorStr2 = io_lib:format(ErrorFormat, ErrorArgs),
-                      io:format(?def_gl, "~ts~n", [lists:concat([Div,ErrorStr2,Div])]),
 		       Link =
 			   "\n\n<a href=\"#end\">"
 			   "Full error description and stacktrace"

lib/common_test/src/ct_logs.erl

@@ -1933,10 +1933,6 @@ make_all_runs_index(When) ->
     put(basic_html, basic_html()),
     AbsName = ?abs(?all_runs_name),
     notify_and_lock_file(AbsName),
-    if When == start -> ok;
-       true -> io:put_chars("Updating " ++ AbsName ++ " ... ")
-    end,
-
     %% check if log cache should be used, and if it exists
     UseCache =
 	if When == refresh ->
@@ -1994,9 +1990,6 @@ make_all_runs_index(When) ->
 					   all_runs_index_footer()))
 	end,
     notify_and_unlock_file(AbsName),
-    if When == start -> ok;
-       true -> io:put_chars("done\n")
-    end,
     Result.
 
 make_all_runs_from_cache(AbsName, Dirs, LogCache) ->
@@ -2694,9 +2687,6 @@ update_tests_in_cache(TempData,LogCache=#log_cache{tests=Tests}) ->
 %%
 make_all_suites_index1(When, AbsIndexName, AllTestLogDirs) ->
     IndexName = ?index_name,
-    if When == start -> ok;
-       true -> io:put_chars("Updating " ++ AbsIndexName ++ " ... ")
-    end,
     case catch make_all_suites_index2(IndexName, AllTestLogDirs) of
 	{'EXIT', Reason} ->
 	    io:put_chars("CRASHED while updating " ++ AbsIndexName ++ "!\n"),
@@ -2713,7 +2703,7 @@ make_all_suites_index1(When, AbsIndexName, AllTestLogDirs) ->
 							    TempData}}),
 		    TempData;
 		_ ->
-		    io:put_chars("done\n"),
+		    io:put_chars("HTML logs at file://" ++ AbsIndexName ++ ".\n"),
 		    TempData
 	    end;
 	Err ->