Merge pull request #3133 from esl/mu-safer-ct-hooks

Safer CT hook error handling As per PR description: When I was testing suites, I was generating errors from all/0 and groups/0 callbacks. And CT works really strange and not informative. Two problems: it does not print the error, just "location is unknown" it passes that error to CT hooks, and that's why this PR. Before CTH was crashing when handling SUITE crash during the init: *** CT 2021-05-24 12:32:43.391 *** Suite Hook Call to CTH failed: error:{{test_case_failed, {open_file_failed,'test@Mikhails-MacBook-Pro', "/Users/mikhailuvarov/erlang/esl/MongooseIM/big_tests/ct_report/[email protected]_12.32.42/undefined/../../../[email protected]", {error,enoent}}}, [{ct_mongoose_log_hook,ensure_initialized,2, [{file, "/Users/mikhailuvarov/erlang/esl/MongooseIM/big_tests/src/ct_mongoose_log_hook.erl"}, {line,176}]}, {ct_mongoose_log_hook,pre_init_per_testcase,3, [{file, "/Users/mikhailuvarov/erlang/esl/MongooseIM/big_tests/src/ct_mongoose_log_hook.erl"}, {line,81}]}, {ct_hooks,catch_apply,3, [{file,"ct_hooks.erl"},{line,491}]}, {ct_hooks,do_call_generic,4, [{file,"ct_hooks.erl"},{line,247}]}, {ct_hooks,call,4, [{file,"ct_hooks.erl"},{line,301}]}, {ct_hooks,call,4, [{file,"ct_hooks.erl"},{line,304}]}, {ct_hooks,call,3, [{file,"ct_hooks.erl"},{line,257}]}]} *** CT 2021-05-24 12:32:43.391 *** Suite Hook Call to CTH failed: error:{function_clause, [{proplists,get_value, [priv_dir, {fail, "ct_mongoose_log_hook:pre_init_per_testcase/3 CTH call failed"}, undefined], [{file,"proplists.erl"},{line,215}]}, {ct_mongoose_log_hook,keep_priv_dir,2, [{file, "/Users/mikhailuvarov/erlang/esl/MongooseIM/big_tests/src/ct_mongoose_log_hook.erl"}, {line,193}]}, {ct_mongoose_log_hook,pre_init_per_testcase,3, [{file, "/Users/mikhailuvarov/erlang/esl/MongooseIM/big_tests/src/ct_mongoose_log_hook.erl"}, {line,80}]}, {ct_hooks,catch_apply,3, [{file,"ct_hooks.erl"},{line,491}]}, {ct_hooks,do_call_generic,4, [{file,"ct_hooks.erl"},{line,247}]}, {ct_hooks,call,4, [{file,"ct_hooks.erl"},{line,301}]}, {ct_hooks,call,4, [{file,"ct_hooks.erl"},{line,304}]}, {ct_hooks,call,3, [{file,"ct_hooks.erl"},{line,257}]}]} *** CT Error Notification 2021-05-24 12:32:43.391 *** Error detected: 'mam_SUITE:groups/0 failed' Full error description and stacktrace === Ended at 2021-05-24 12:32:43 === Location: unknown === === Reason: 'mam_SUITE:groups/0 failed' After it is not crashing in the handler. Theoretically, it allows CT to fail with the origin SUITE error, but CT is broken, so it just eats the original error location anyway. We should go and fix it in otp upstream, probably it got broken during introducing line numbering.
esl · May 27, 2021 · 404f6a0 · 404f6a0
2 parents 5166ab3 + d5ca4d0
commit 404f6a0
Show file tree

Hide file tree

Showing 2 changed files with 31 additions and 21 deletions.
diff --git a/big_tests/src/ct_mongoose_log_hook.erl b/big_tests/src/ct_mongoose_log_hook.erl
@@ -81,7 +81,7 @@ pre_init_per_testcase(TC,Config,State=#state{}) ->
     State3 = ensure_initialized(Config, State2),
     State4 = pre_insert_line_numbers_into_report(State3, TC),
     test_server:timetrap_cancel(Dog),
-    {Config, State4 }.
+    {Config, State4}.
 
 %% @doc Called after each test case.
 post_end_per_testcase(TC,_Config,Return,State) ->
@@ -163,28 +163,28 @@ make_content(CurrentLineNum, Line) ->
     << (list_to_binary(integer_to_list(CurrentLineNum)))/binary, " ", Line/binary>>.
 
 ensure_initialized(Config, State=#state{node=Node, cookie=Cookie, out_file=undefined}) ->
-    PrivDir = proplists:get_value(priv_dir, Config),
     RunDir = path_helper:ct_run_dir(Config),
     File = atom_to_list(Node) ++ ".log.html",
     %% On disk
     OutFile = filename:join(RunDir, File),
     %% In browser
     UrlFile = ct_logs:uri(filename:join(path_helper:ct_run_dir_in_browser(Config), File)),
-    case spawn_log_reader(Node, Cookie) of
-        {ok, Reader} ->
-            %% self() process is temporary
-            {ok, Writer} = open_out_file(OutFile),
-            file:write(Writer, "<pre>"),
-            CurrentLineNum = read_and_write_lines(Node, Reader, Writer, 0),
-            ct:pal("issue=\"ct_mongoose_log_hook created log file\", "
-                   "ct_node=~p, reader=~p, reader_node=~p, writer=~p, out_file=~p",
-                   [node(), Reader, node(Reader), Writer, OutFile]),
-            State#state{reader=Reader, writer=Writer, out_file=OutFile,
-                        current_line_num=CurrentLineNum, url_file=UrlFile};
-        Reason ->
-            ct:pal("issue=\"Failed to init ct_mongoose_log_hook\", node=~p, reason=~p",
-                   [Node, Reason]),
-            State#state{out_file=OutFile}
+    try
+        {ok, Reader} = spawn_log_reader(Node, Cookie),
+        %% self() process is temporary
+        {ok, Writer} = open_out_file(OutFile),
+        file:write(Writer, "<pre>"),
+        CurrentLineNum = read_and_write_lines(Node, Reader, Writer, 0),
+        ct:pal("issue=\"ct_mongoose_log_hook created log file\", "
+               "ct_node=~p, reader=~p, reader_node=~p, writer=~p, out_file=~p",
+               [node(), Reader, node(Reader), Writer, OutFile]),
+        State#state{reader=Reader, writer=Writer, out_file=OutFile,
+                    current_line_num=CurrentLineNum, url_file=UrlFile}
+    catch Class:Reason:Stacktrace ->
+            ct:pal("issue=\"Failed to init ct_mongoose_log_hook\"~n node=~p~n "
+                   "reason=~p~n stacktrace=~p",
+                   [Node, Reason, Stacktrace]),
+            State
     end;
 ensure_initialized(_Config, State=#state{}) ->
     State.
@@ -254,12 +254,19 @@ open_out_file(OutFile) ->
 %% @doc Open file. The caller process will not be monitored by file_server.
 %% So, the file is not closed in case the parent process dies.
 open_file_without_linking(Node, File, Opts) when Node =:= node() ->
-    apply_in_new_process(file, open, [File, Opts]);
+    Res = apply_in_new_process(file, open, [File, Opts]),
+    check_result(Node, File, Res);
 open_file_without_linking(Node, File, Opts) ->
     %% Regular rpc:call/4 spawns a temporary process which
     %% cause file process termination.
     %% `block_call' is executed inside a long-living process.
-    rpc:block_call(Node, file, open, [File, Opts], 5000).
+    Res = rpc:block_call(Node, file, open, [File, Opts], 5000),
+    check_result(Node, File, Res).
+
+check_result(Node, File, {ok, _} = Res) ->
+    Res;
+check_result(Node, File, Res) ->
+    ct:fail({open_file_failed, Node, File, Res}).
 
 %% Spawns a long living process and executes function
 apply_in_new_process(M, F, A) ->

diff --git a/big_tests/src/ct_tty_hook.erl b/big_tests/src/ct_tty_hook.erl
@@ -81,9 +81,12 @@ post_end_per_group(Group,_Config,Return,State) ->
     {Return, State}.
 
 %% @doc Called before each test case.
-pre_init_per_testcase(TC,Config,State) ->
+pre_init_per_testcase(TC,Config,State = #state{suite_total = Total})
+      when is_integer(Total) ->
     print_case_enter(TC, State, "Starting"),
-    {Config, State#state{ ts = os:timestamp(), total = State#state.suite_total + 1 } }.
+    {Config, State#state{ ts = os:timestamp(), total = Total + 1 } };
+pre_init_per_testcase(TC, Config, State) ->
+    {Config, State}.
 
 %% @doc Called after each test case.
 post_end_per_testcase(TC, _Config, Return, State) ->