diff options
-rw-r--r-- | lib/common_test/src/ct.erl | 24 | ||||
-rw-r--r-- | lib/common_test/src/ct_logs.erl | 163 | ||||
-rw-r--r-- | lib/common_test/src/cth_log_redirect.erl | 15 | ||||
-rw-r--r-- | lib/common_test/test/ct_error_SUITE.erl | 66 | ||||
-rw-r--r-- | lib/common_test/test/ct_error_SUITE_data/error/test/misc_error_1_SUITE.erl | 154 | ||||
-rw-r--r-- | lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_1_SUITE.erl | 57 | ||||
-rw-r--r-- | lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_helper.erl | 7 | ||||
-rw-r--r-- | lib/common_test/vsn.mk | 2 | ||||
-rw-r--r-- | lib/test_server/src/test_server.erl | 103 | ||||
-rw-r--r-- | lib/test_server/src/test_server_ctrl.erl | 7 | ||||
-rw-r--r-- | lib/test_server/src/test_server_h.erl | 44 | ||||
-rw-r--r-- | lib/test_server/vsn.mk | 2 |
12 files changed, 507 insertions, 137 deletions
diff --git a/lib/common_test/src/ct.erl b/lib/common_test/src/ct.erl index e0e82283c4..00701f5a2d 100644 --- a/lib/common_test/src/ct.erl +++ b/lib/common_test/src/ct.erl @@ -585,8 +585,16 @@ capture_get([]) -> %%% @doc Terminate a test case with the given error %%% <code>Reason</code>. fail(Reason) -> - exit({test_case_failed,Reason}). - + try + exit({test_case_failed,Reason}) + catch + Class:R -> + case erlang:get_stacktrace() of + [{?MODULE,fail,1,_}|Stk] -> ok; + Stk -> ok + end, + erlang:raise(Class, R, Stk) + end. %%%----------------------------------------------------------------- %%% @spec fail(Format, Args) -> void() @@ -599,13 +607,21 @@ fail(Reason) -> fail(Format, Args) -> try io_lib:format(Format, Args) of Str -> - exit({test_case_failed,lists:flatten(Str)}) + try + exit({test_case_failed,lists:flatten(Str)}) + catch + Class:R -> + case erlang:get_stacktrace() of + [{?MODULE,fail,2,_}|Stk] -> ok; + Stk -> ok + end, + erlang:raise(Class, R, Stk) + end catch _:BadArgs -> exit({BadArgs,{?MODULE,fail,[Format,Args]}}) end. - %%%----------------------------------------------------------------- %%% @spec comment(Comment) -> void() %%% Comment = term() diff --git a/lib/common_test/src/ct_logs.erl b/lib/common_test/src/ct_logs.erl index 19ad7b26d8..5f0626c0b0 100644 --- a/lib/common_test/src/ct_logs.erl +++ b/lib/common_test/src/ct_logs.erl @@ -38,7 +38,7 @@ -export([get_ts_html_wrapper/3]). %% Logging stuff directly from testcase --export([tc_log/3,tc_print/3,tc_pal/3,ct_log/3, +-export([tc_log/3,tc_log_async/3,tc_print/3,tc_pal/3,ct_log/3, basic_html/0]). %% Simulate logger process for use without ct environment running @@ -239,7 +239,7 @@ end_tc(TCPid) -> %%% activity it is. <code>Format</code> and <code>Args</code> is the %%% data to log (as in <code>io:format(Format,Args)</code>).</p> log(Heading,Format,Args) -> - cast({log,self(),group_leader(), + cast({log,sync,self(),group_leader(), [{int_header(),[log_timestamp(now()),Heading]}, {Format,Args}, {int_footer(),[]}]}), @@ -261,7 +261,7 @@ log(Heading,Format,Args) -> %%% @see cont_log/2 %%% @see end_log/0 start_log(Heading) -> - cast({log,self(),group_leader(), + cast({log,sync,self(),group_leader(), [{int_header(),[log_timestamp(now()),Heading]}]}), ok. @@ -276,7 +276,7 @@ cont_log([],[]) -> ok; cont_log(Format,Args) -> maybe_log_timestamp(), - cast({log,self(),group_leader(),[{Format,Args}]}), + cast({log,sync,self(),group_leader(),[{Format,Args}]}), ok. %%%----------------------------------------------------------------- @@ -287,7 +287,7 @@ cont_log(Format,Args) -> %%% @see start_log/1 %%% @see cont_log/2 end_log() -> - cast({log,self(),group_leader(),[{int_footer(), []}]}), + cast({log,sync,self(),group_leader(),[{int_footer(), []}]}), ok. @@ -333,9 +333,29 @@ add_link(Heading,File,Type) -> %%% stuff directly from a testcase (i.e. not from within the CT %%% framework).</p> tc_log(Category,Format,Args) -> - cast({log,self(),group_leader(),[{div_header(Category),[]}, - {Format,Args}, - {div_footer(),[]}]}), + cast({log,sync,self(),group_leader(),[{div_header(Category),[]}, + {Format,Args}, + {div_footer(),[]}]}), + ok. + + +%%%----------------------------------------------------------------- +%%% @spec tc_log_async(Category,Format,Args) -> ok +%%% Category = atom() +%%% Format = string() +%%% Args = list() +%%% +%%% @doc Internal use only. +%%% +%%% <p>This function is used to perform asynchronous printouts +%%% towards the test server IO handler. This is necessary in order +%%% to avoid deadlocks when e.g. the hook that handles SASL printouts +%%% prints to the test case log file at the same time test server +%%% asks ct_logs for an html wrapper.</p> +tc_log_async(Category,Format,Args) -> + cast({log,async,self(),group_leader(),[{div_header(Category),[]}, + {Format,Args}, + {div_footer(),[]}]}), ok. %%%----------------------------------------------------------------- @@ -377,9 +397,9 @@ print_heading(Category) -> %%% log and on the console.</p> tc_pal(Category,Format,Args) -> tc_print(Category,Format,Args), - cast({log,self(),group_leader(),[{div_header(Category),[]}, - {Format,Args}, - {div_footer(),[]}]}), + cast({log,sync,self(),group_leader(),[{div_header(Category),[]}, + {Format,Args}, + {div_footer(),[]}]}), ok. @@ -420,7 +440,7 @@ maybe_log_timestamp() -> {MS,S,_} -> ok; _ -> - cast({log,self(),group_leader(), + cast({log,sync,self(),group_leader(), [{"<i>~s</i>",[log_timestamp({MS,S,US})]}]}) end. @@ -441,7 +461,8 @@ log_timestamp({MS,S,US}) -> orig_GL, ct_log_fd, tc_groupleaders, - stylesheet}). + stylesheet, + async_print_jobs}). logger(Parent,Mode) -> register(?MODULE,self()), @@ -520,50 +541,32 @@ logger(Parent,Mode) -> start_time=Time, orig_GL=group_leader(), ct_log_fd=CtLogFd, - tc_groupleaders=[]}). + tc_groupleaders=[], + async_print_jobs=[]}). logger_loop(State) -> receive - {log,Pid,GL,List} -> - case get_groupleader(Pid,GL,State) of + {log,SyncOrAsync,Pid,GL,List} -> + case get_groupleader(Pid, GL, State) of {tc_log,TCGL,TCGLs} -> case erlang:is_process_alive(TCGL) of true -> - %% 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 - Fun = - fun({Str,Args},IoList) -> - case catch io_lib:format(Str,Args) of - {'EXIT',_Reason} -> - Fd = State#logger_state.ct_log_fd, - io:format(Fd, - "Logging fails! " - "Str: ~p, Args: ~p~n", - [Str,Args]), - %% stop the testcase, we need - %% to see the fault - exit(Pid,{log_printout_error,Str,Args}), - []; - IoStr when IoList == [] -> - [IoStr]; - IoStr -> - [IoList,"\n",IoStr] - end - end, - io:format(TCGL,"~s",[lists:foldl(Fun,[],List)]), - logger_loop(State#logger_state{tc_groupleaders=TCGLs}); + State1 = print_to_log(SyncOrAsync, Pid, TCGL, + List, State), + logger_loop(State1#logger_state{tc_groupleaders = + TCGLs}); false -> - %% Group leader is dead, so write to the CtLog instead + %% Group leader is dead, so write to the + %% CtLog instead Fd = State#logger_state.ct_log_fd, [begin io:format(Fd,Str,Args),io:nl(Fd) end || {Str,Args} <- List], logger_loop(State) end; {ct_log,Fd,TCGLs} -> - [begin io:format(Fd,Str,Args),io:nl(Fd) end || {Str,Args} <- List], - logger_loop(State#logger_state{tc_groupleaders=TCGLs}) + [begin io:format(Fd,Str,Args),io:nl(Fd) end || + {Str,Args} <- List], + logger_loop(State#logger_state{tc_groupleaders = TCGLs}) end; {{init_tc,TCPid,GL,RefreshLog},From} -> print_style(GL, State#logger_state.stylesheet), @@ -575,11 +578,12 @@ logger_loop(State) -> make_last_run_index(State#logger_state.start_time) end, return(From,ok), - logger_loop(State#logger_state{tc_groupleaders=TCGLs}); + logger_loop(State#logger_state{tc_groupleaders = TCGLs}); {{end_tc,TCPid},From} -> set_evmgr_gl(State#logger_state.ct_log_fd), return(From,ok), - logger_loop(State#logger_state{tc_groupleaders=rm_tc_gl(TCPid,State)}); + logger_loop(State#logger_state{tc_groupleaders = + rm_tc_gl(TCPid,State)}); {{get_log_dir,true},From} -> return(From,{ok,State#logger_state.log_dir}), logger_loop(State); @@ -590,21 +594,35 @@ logger_loop(State) -> make_last_run_index(State#logger_state.start_time), return(From,filename:basename(State#logger_state.log_dir)), logger_loop(State); - {set_stylesheet,_,SSFile} when State#logger_state.stylesheet == SSFile -> + {set_stylesheet,_,SSFile} when State#logger_state.stylesheet == + SSFile -> logger_loop(State); {set_stylesheet,TC,SSFile} -> Fd = State#logger_state.ct_log_fd, - io:format(Fd, "~p loading external style sheet: ~s~n", [TC,SSFile]), - logger_loop(State#logger_state{stylesheet=SSFile}); + io:format(Fd, "~p loading external style sheet: ~s~n", + [TC,SSFile]), + logger_loop(State#logger_state{stylesheet = SSFile}); {clear_stylesheet,_} when State#logger_state.stylesheet == undefined -> logger_loop(State); {clear_stylesheet,_} -> - logger_loop(State#logger_state{stylesheet=undefined}); + logger_loop(State#logger_state{stylesheet = undefined}); {ct_log, List} -> Fd = State#logger_state.ct_log_fd, [begin io:format(Fd,Str,Args),io:nl(Fd) end || {Str,Args} <- List], logger_loop(State); + {'DOWN',Ref,_,_Pid,_} -> + %% there might be print jobs executing in parallel with ct_logs + %% and whenever one is finished (indicated by 'DOWN'), the + %% next job should be spawned + case lists:delete(Ref, State#logger_state.async_print_jobs) of + [] -> + logger_loop(State#logger_state{async_print_jobs = []}); + Jobs -> + [Next|JobsRev] = lists:reverse(Jobs), + Jobs1 = [print_next(Next)|lists:reverse(JobsRev)], + logger_loop(State#logger_state{async_print_jobs = Jobs1}) + end; stop -> io:format(State#logger_state.ct_log_fd, int_header()++int_footer(), @@ -613,6 +631,49 @@ logger_loop(State) -> ok end. +create_io_fun(FromPid, State) -> + %% 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", + [Str,Args]), + %% stop the testcase, we need to see the fault + exit(FromPid, {log_printout_error,Str,Args}), + []; + IoStr when IoList == [] -> + [IoStr]; + IoStr -> + [IoList,"\n",IoStr] + end + end. + +print_to_log(sync, FromPid, TCGL, List, State) -> + IoFun = create_io_fun(FromPid, State), + io:format(TCGL, "~s", [lists:foldl(IoFun, [], List)]), + State; + +print_to_log(async, FromPid, TCGL, List, State) -> + IoFun = create_io_fun(FromPid, State), + Printer = fun() -> + io:format(TCGL, "~s", [lists:foldl(IoFun, [], List)]) + end, + case State#logger_state.async_print_jobs of + [] -> + {_Pid,Ref} = spawn_monitor(Printer), + State#logger_state{async_print_jobs = [Ref]}; + Queue -> + State#logger_state{async_print_jobs = [Printer|Queue]} + end. + +print_next(PrintFun) -> + {_Pid,Ref} = spawn_monitor(PrintFun), + Ref. + %% #logger_state.tc_groupleaders == [{Pid,{Type,GLPid}},...] %% Type = tc | io %% @@ -1894,7 +1955,7 @@ simulate() -> simulate_logger_loop() -> receive - {log,_,_,List} -> + {log,_,_,_,List} -> S = [[io_lib:format(Str,Args),io_lib:nl()] || {Str,Args} <- List], io:format("~s",[S]), simulate_logger_loop(); diff --git a/lib/common_test/src/cth_log_redirect.erl b/lib/common_test/src/cth_log_redirect.erl index 14663b7738..ea79251cfc 100644 --- a/lib/common_test/src/cth_log_redirect.erl +++ b/lib/common_test/src/cth_log_redirect.erl @@ -31,22 +31,22 @@ %% Event handler Callbacks -export([init/1, handle_event/2, handle_call/2, handle_info/2, - terminate/2]). + terminate/1]). id(_Opts) -> ?MODULE. init(?MODULE, _Opts) -> error_logger:add_report_handler(?MODULE), - tc_log. + tc_log_async. -post_init_per_group(Group, Config, Result, tc_log) -> +post_init_per_group(Group, Config, Result, tc_log_async) -> case lists:member(parallel,proplists:get_value( tc_group_properties,Config,[])) of true -> {Result, {set_log_func(ct_log),Group}}; false -> - {Result, tc_log} + {Result, tc_log_async} end; post_init_per_group(_Group, _Config, Result, State) -> {Result, State}. @@ -58,14 +58,14 @@ post_end_per_testcase(_TC, _Config, Result, State) -> {Result, State}. pre_end_per_group(Group, Config, {ct_log, Group}) -> - {Config, set_log_func(tc_log)}; + {Config, set_log_func(tc_log_async)}; pre_end_per_group(_Group, Config, State) -> {Config, State}. %% Copied and modified from sasl_report_tty_h.erl init(_Type) -> - {ok, tc_log}. + {ok, tc_log_async}. handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() -> {ok, State}; @@ -101,7 +101,8 @@ handle_call({set_logfunc,NewLogFunc},_) -> {ok, NewLogFunc, NewLogFunc}; handle_call(_Query, _State) -> {error, bad_query}. -terminate(_Reason, _Type) -> +terminate(_State) -> + error_logger:delete_report_handler(?MODULE), []. tag_event(Event) -> diff --git a/lib/common_test/test/ct_error_SUITE.erl b/lib/common_test/test/ct_error_SUITE.erl index 2b3157ff3b..bd218dc05f 100644 --- a/lib/common_test/test/ct_error_SUITE.erl +++ b/lib/common_test/test/ct_error_SUITE.erl @@ -61,7 +61,7 @@ suite() -> [{ct_hooks,[ts_install_cth]}]. all() -> [cfg_error, lib_error, no_compile, timetrap_end_conf, timetrap_normal, timetrap_extended, timetrap_parallel, - timetrap_fun]. + timetrap_fun, misc_errors]. groups() -> []. @@ -249,6 +249,24 @@ timetrap_fun(Config) when is_list(Config) -> TestEvents = events_to_check(timetrap_fun), ok = ct_test_support:verify_events(TestEvents, Events, Config). +%%%----------------------------------------------------------------- +%%% +misc_errors(Config) when is_list(Config) -> + DataDir = ?config(data_dir, Config), + Join = fun(D, S) -> filename:join(D, "error/test/"++S) end, + Suites = [Join(DataDir, "misc_error_1_SUITE")], + {Opts,ERPid} = setup([{suite,Suites}], Config), + ok = ct_test_support:run(Opts, Config), + Events = ct_test_support:get_events(ERPid, Config), + + ct_test_support:log_events(misc_errors, + reformat(Events, ?eh), + ?config(priv_dir, Config), + Opts), + + TestEvents = events_to_check(misc_errors), + ok = ct_test_support:verify_events(TestEvents, Events, Config). + %%%----------------------------------------------------------------- %%% HELP FUNCTIONS @@ -682,7 +700,7 @@ test_events(timetrap_end_conf) -> [ {?eh,start_logging,{'DEF','RUNDIR'}}, {?eh,test_start,{'DEF',{'START_TIME','LOGDIR'}}}, - {?eh,start_info,{1,1,6}}, + {?eh,start_info,{1,1,8}}, {?eh,tc_start,{timetrap_1_SUITE,init_per_suite}}, {?eh,tc_done,{timetrap_1_SUITE,init_per_suite,ok}}, {?eh,tc_start,{timetrap_1_SUITE,tc1}}, @@ -709,6 +727,14 @@ test_events(timetrap_end_conf) -> {?eh,tc_done, {timetrap_1_SUITE,tc6,{failed,{testcase_aborted,testing_end_conf}}}}, {?eh,test_stats,{0,6,{0,0}}}, + {?eh,tc_start,{timetrap_1_SUITE,tc7}}, + {?eh,tc_done, + {timetrap_1_SUITE,tc7,{failed,{timetrap_timeout,1000}}}}, + {?eh,test_stats,{0,7,{0,0}}}, + {?eh,tc_start,{timetrap_1_SUITE,tc8}}, + {?eh,tc_done, + {timetrap_1_SUITE,tc8,{failed,{timetrap_timeout,1000}}}}, + {?eh,test_stats,{0,8,{0,0}}}, {?eh,tc_start,{timetrap_1_SUITE,end_per_suite}}, {?eh,tc_done,{timetrap_1_SUITE,end_per_suite,ok}}, {?eh,test_done,{'DEF','STOP_TIME'}}, @@ -892,4 +918,40 @@ test_events(timetrap_fun) -> {?eh,tc_done,{timetrap_7_SUITE,end_per_suite,ok}}, {?eh,test_done,{'DEF','STOP_TIME'}}, {?eh,stop_logging,[]} + ]; + +test_events(misc_errors) -> + [ + {?eh,start_logging,{'DEF','RUNDIR'}}, + {?eh,test_start,{'DEF',{'START_TIME','LOGDIR'}}}, + {?eh,start_info,{1,1,7}}, + {?eh,tc_start,{misc_error_1_SUITE,ct_fail_1}}, + {?eh,tc_done,{misc_error_1_SUITE,ct_fail_1, + {failed,{error,{test_case_failed,{error,this_is_expected}}}}}}, + {?eh,test_stats,{0,1,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,ct_fail_2}}, + {?eh,tc_done,{misc_error_1_SUITE,ct_fail_2, + {failed,{error,{test_case_failed,"this_is_expected"}}}}}, + {?eh,test_stats,{0,2,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,ct_fail_3}}, + {?eh,tc_done,{misc_error_1_SUITE,ct_fail_3, + {failed,{error,{test_case_failed,this_is_expected}}}}}, + {?eh,test_stats,{0,3,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,ts_fail_1}}, + {?eh,tc_done,{misc_error_1_SUITE,ts_fail_1, + {failed,{error,{suite_failed,this_is_expected}}}}}, + {?eh,test_stats,{0,4,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,ts_fail_2}}, + {?eh,tc_done,{misc_error_1_SUITE,ts_fail_2, + {failed,{error,{suite_failed,this_is_expected}}}}}, + {?eh,test_stats,{0,5,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,killed_by_signal_1}}, + {?eh,tc_done,{undefined,undefined,i_die_now}}, + {?eh,test_stats,{0,6,{0,0}}}, + {?eh,tc_start,{misc_error_1_SUITE,killed_by_signal_2}}, + {?eh,tc_done,{undefined,undefined, + {failed,testcase_aborted_or_killed}}}, + {?eh,test_stats,{0,7,{0,0}}}, + {?eh,test_done,{'DEF','STOP_TIME'}}, + {?eh,stop_logging,[]} ]. diff --git a/lib/common_test/test/ct_error_SUITE_data/error/test/misc_error_1_SUITE.erl b/lib/common_test/test/ct_error_SUITE_data/error/test/misc_error_1_SUITE.erl new file mode 100644 index 0000000000..4e20875505 --- /dev/null +++ b/lib/common_test/test/ct_error_SUITE_data/error/test/misc_error_1_SUITE.erl @@ -0,0 +1,154 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2009-2010. All Rights Reserved. +%% +%% The contents of this file are subject to the Erlang Public License, +%% Version 1.1, (the "License"); you may not use this file except in +%% compliance with the License. You should have received a copy of the +%% Erlang Public License along with this software. If not, it can be +%% retrieved online at http://www.erlang.org/. +%% +%% Software distributed under the License is distributed on an "AS IS" +%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See +%% the License for the specific language governing rights and limitations +%% under the License. +%% +%% %CopyrightEnd% +%% +-module(misc_error_1_SUITE). + +-compile(export_all). + +-include_lib("common_test/include/ct.hrl"). + +%%-------------------------------------------------------------------- +%% Function: suite() -> Info +%% Info = [tuple()] +%%-------------------------------------------------------------------- +suite() -> + [{timetrap,{seconds,3}}]. + +%%-------------------------------------------------------------------- +%% Function: init_per_suite(Config0) -> +%% Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%%-------------------------------------------------------------------- +init_per_suite(Config) -> + Config. + +%%-------------------------------------------------------------------- +%% Function: end_per_suite(Config0) -> void() | {save_config,Config1} +%% Config0 = Config1 = [tuple()] +%%-------------------------------------------------------------------- +end_per_suite(_Config) -> + ok. + +%%-------------------------------------------------------------------- +%% Function: init_per_group(GroupName, Config0) -> +%% Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% GroupName = atom() +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%%-------------------------------------------------------------------- +init_per_group(_GroupName, Config) -> + Config. + +%%-------------------------------------------------------------------- +%% Function: end_per_group(GroupName, Config0) -> +%% void() | {save_config,Config1} +%% GroupName = atom() +%% Config0 = Config1 = [tuple()] +%%-------------------------------------------------------------------- +end_per_group(_GroupName, _Config) -> + ok. + +%%-------------------------------------------------------------------- +%% Function: init_per_testcase(TestCase, Config0) -> +%% Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% TestCase = atom() +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%%-------------------------------------------------------------------- +init_per_testcase(_TestCase, Config) -> + Config. + +%%-------------------------------------------------------------------- +%% Function: end_per_testcase(TestCase, Config0) -> +%% void() | {save_config,Config1} +%% TestCase = atom() +%% Config0 = Config1 = [tuple()] +%%-------------------------------------------------------------------- +end_per_testcase(_TestCase, _Config) -> + ok. + +%%-------------------------------------------------------------------- +%% Function: groups() -> [Group] +%% Group = {GroupName,Properties,GroupsAndTestCases} +%% GroupName = atom() +%% Properties = [parallel | sequence | Shuffle | {RepeatType,N}] +%% GroupsAndTestCases = [Group | {group,GroupName} | TestCase] +%% TestCase = atom() +%% Shuffle = shuffle | {shuffle,{integer(),integer(),integer()}} +%% RepeatType = repeat | repeat_until_all_ok | repeat_until_all_fail | +%% repeat_until_any_ok | repeat_until_any_fail +%% N = integer() | forever +%%-------------------------------------------------------------------- +groups() -> + []. + +%%-------------------------------------------------------------------- +%% Function: all() -> GroupsAndTestCases | {skip,Reason} +%% GroupsAndTestCases = [{group,GroupName} | TestCase] +%% GroupName = atom() +%% TestCase = atom() +%% Reason = term() +%%-------------------------------------------------------------------- +all() -> + [ct_fail_1, ct_fail_2, ct_fail_3, ts_fail_1, ts_fail_2, + killed_by_signal_1, killed_by_signal_2]. + +ct_fail_1(_) -> + ct:fail({error,this_is_expected}), + exit(this_should_not_be_seen), + ok. + +ct_fail_2(_) -> + ct:fail("~w", [this_is_expected]), + exit(this_should_not_be_seen), + ok. + +ct_fail_3(_) -> + fail_me(fun() -> ct:fail(this_is_expected) end), + exit(this_should_not_be_seen), + ok. + +ts_fail_1(_) -> + test_server:fail(this_is_expected), + exit(this_should_not_be_seen), + ok. + +ts_fail_2(_) -> + fail_me(fun() -> test_server:fail(this_is_expected) end), + exit(this_should_not_be_seen), + ok. + +fail_me(Fun) -> + Fun(), + ok. + +killed_by_signal_1(_) -> + spawn_link(fun() -> ct:sleep(100), + exit(i_die_now) + end), + ct:sleep(1000), + exit(this_should_not_be_seen). + +killed_by_signal_2(_) -> + TCPid = self(), + spawn_link(fun() -> ct:sleep(100), + exit(TCPid, kill) + end), + ct:sleep(1000), + exit(this_should_not_be_seen). diff --git a/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_1_SUITE.erl b/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_1_SUITE.erl index cb3109349b..faa0a7305c 100644 --- a/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_1_SUITE.erl +++ b/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_1_SUITE.erl @@ -83,23 +83,11 @@ init_per_testcase(TC, Config) -> ets:insert(?MODULE, {last_case,fail}), init_per_testcase1(TC, Config). -init_per_testcase1(tc1, Config) -> - [{tc,tc1}|Config]; - -init_per_testcase1(tc2, Config) -> - [{tc,tc2}|Config]; - -init_per_testcase1(tc3, Config) -> - [{tc,tc3}|Config]; - init_per_testcase1(tc4, Config) -> [{tc,tc4},{default_timeout,5000}|Config]; -init_per_testcase1(tc5, Config) -> - [{tc,tc5}|Config]; - -init_per_testcase1(tc6, Config) -> - [{tc,tc6}|Config]. +init_per_testcase1(TC, Config) -> + [{tc,TC}|Config]. %%-------------------------------------------------------------------- %% Function: end_per_testcase(TestCase, Config0) -> @@ -145,7 +133,19 @@ end_per_testcase1(tc5, Config) -> end_per_testcase1(tc6, Config) -> ct:pal("end_per_testcase(tc6): ~p", [Config]), tc6 = ?config(tc, Config), - exit(end_per_tc_fail_after_abort). + exit(end_per_tc_fail_after_abort); + +end_per_testcase1(tc7, Config) -> + ct:pal("end_per_testcase(tc7): ~p", [Config]), + tc7 = ?config(tc, Config), + {failed,timetrap_timeout} = ?config(tc_status, Config), + ok; + +end_per_testcase1(tc8, Config) -> + ct:pal("end_per_testcase(tc8): ~p", [Config]), + tc8 = ?config(tc, Config), + {failed,timetrap_timeout} = ?config(tc_status, Config), + ok. %%-------------------------------------------------------------------- %% Function: groups() -> [Group] @@ -170,25 +170,42 @@ groups() -> %% Reason = term() %%-------------------------------------------------------------------- all() -> - [tc1, tc2, tc3, tc4, tc5, tc6]. + [tc1, tc2, tc3, tc4, tc5, tc6, tc7, tc8]. tc1(_) -> - timer:sleep(2000). + timer:sleep(2000), + ok. tc2(_) -> timer:sleep(2000). tc3(_) -> spawn(ct, abort_current_testcase, [testing_end_conf]), - timer:sleep(2000). + timer:sleep(2000), + ok. tc4(_) -> spawn(ct, abort_current_testcase, [testing_end_conf]), - timer:sleep(2000). + timer:sleep(2000), + ok. tc5(_) -> - timer:sleep(2000). + timer:sleep(2000), + ok. tc6(_) -> spawn(ct, abort_current_testcase, [testing_end_conf]), timer:sleep(2000). + +tc7(_) -> + sleep(2000), + ok. + +tc8(_) -> + timetrap_helper:sleep(2000), + ok. + +%%%----------------------------------------------------------------- +sleep(T) -> + timer:sleep(T), + ok. diff --git a/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_helper.erl b/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_helper.erl new file mode 100644 index 0000000000..1389acca11 --- /dev/null +++ b/lib/common_test/test/ct_error_SUITE_data/error/test/timetrap_helper.erl @@ -0,0 +1,7 @@ +-module(timetrap_helper). + +-export([sleep/1]). + +sleep(T) -> + timer:sleep(T), + ok. diff --git a/lib/common_test/vsn.mk b/lib/common_test/vsn.mk index 2f43c1bc17..b94f7f7593 100644 --- a/lib/common_test/vsn.mk +++ b/lib/common_test/vsn.mk @@ -1 +1 @@ -COMMON_TEST_VSN = 1.6 +COMMON_TEST_VSN = 1.6.1 diff --git a/lib/test_server/src/test_server.erl b/lib/test_server/src/test_server.erl index 51754cb3b4..1433eef193 100644 --- a/lib/test_server/src/test_server.erl +++ b/lib/test_server/src/test_server.erl @@ -766,7 +766,7 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> %% timout during framework call spawn_fw_call(FwMod,FwFunc,CurrConf,Pid, {framework_error,{timetrap,TVal}}, - unknown,self(),Comment), + unknown,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate, Comment,undefined); Loc1 -> @@ -792,7 +792,7 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> %% and let the group leader go back to handle io. spawn_fw_call(Mod,Func,CurrConf,Pid, {timetrap_timeout,TVal}, - Loc1,self(),Comment), + Loc1,self()), undefined end, run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate, @@ -804,12 +804,12 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> %% timout during framework call spawn_fw_call(FwMod,FwFunc,CurrConf,Pid, {framework_error,{timetrap,TVal}}, - unknown,self(),Comment); + unknown,self()); Loc1 -> {Mod,_Func} = get_mf(Loc1), spawn_fw_call(Mod,InitOrEnd,CurrConf,Pid, {timetrap_timeout,TVal}, - Loc1,self(),Comment) + Loc1,self()) end, run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,CurrConf); {testcase_aborted,AbortReason,AbortLoc} -> @@ -819,7 +819,7 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> %% abort during framework call spawn_fw_call(FwMod,FwFunc,CurrConf,Pid, {framework_error,ErrorMsg}, - unknown,self(),Comment), + unknown,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate, Comment,undefined); Loc1 -> @@ -842,7 +842,7 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> _ -> {Mod,Func} = get_mf(Loc1), spawn_fw_call(Mod,Func,CurrConf,Pid,ErrorMsg, - Loc1,self(),Comment), + Loc1,self()), undefined end, run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate, @@ -854,30 +854,46 @@ run_test_case_msgloop(Ref, Pid, CaptureStdout, Terminate, Comment, CurrConf) -> %% (see abort_current_testcase) spawn_fw_call(undefined,undefined,CurrConf,Pid, testcase_aborted_or_killed, - unknown,self(),Comment), + unknown,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,CurrConf); {fw_error,{FwMod,FwFunc,FwError}} -> spawn_fw_call(FwMod,FwFunc,CurrConf,Pid,{framework_error,FwError}, - unknown,self(),Comment), + unknown,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,CurrConf); _Other -> %% the testcase has terminated because of Reason (e.g. an exit %% because a linked process failed) spawn_fw_call(undefined,undefined,CurrConf,Pid,Reason, - unknown,self(),Comment), + unknown,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,CurrConf) end; {EndConfPid,{call_end_conf,Data,_Result}} -> case CurrConf of {EndConfPid,{Mod,Func},_Conf} -> {_Mod,_Func,TCPid,TCExitReason,Loc} = Data, - spawn_fw_call(Mod,Func,CurrConf,TCPid,TCExitReason,Loc,self(),Comment), + spawn_fw_call(Mod,Func,CurrConf,TCPid,TCExitReason,Loc,self()), run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,undefined); _ -> run_test_case_msgloop(Ref,Pid,CaptureStdout,Terminate,Comment,CurrConf) end; - {_FwCallPid,fw_notify_done,RetVal} -> + {_FwCallPid,fw_notify_done,{T,Value,Loc,Opts,AddToComment}} -> %% the framework has been notified, we're finished + RetVal = + case AddToComment of + undefined -> + {T,Value,Loc,Opts,Comment}; + _ -> + Comment1 = + if Comment == "" -> + AddToComment; + true -> + Comment ++ + test_server_ctrl:xhtml("<br>", + "<br />") ++ + AddToComment + end, + {T,Value,Loc,Opts,Comment1} + end, run_test_case_msgloop(Ref,Pid,CaptureStdout,{true,RetVal},Comment,undefined); {'EXIT',_FwCallPid,{fw_notify_done,Func,Error}} -> %% a framework function failed @@ -956,9 +972,12 @@ call_end_conf(Mod,Func,TCPid,TCExitReason,Loc,Conf,TVal) -> spawn_link(EndConfProc). spawn_fw_call(Mod,{init_per_testcase,Func},_,Pid,{timetrap_timeout,TVal}=Why, - Loc,SendTo,Comment) -> + Loc,SendTo) -> FwCall = fun() -> + %% set group leader so that printouts/comments + %% from the framework get printed in the logs + group_leader(SendTo, self()), Skip = {skip,{failed,{Mod,init_per_testcase,Why}}}, %% if init_per_testcase fails, the test case %% should be skipped @@ -970,12 +989,12 @@ spawn_fw_call(Mod,{init_per_testcase,Func},_,Pid,{timetrap_timeout,TVal}=Why, end, %% finished, report back SendTo ! {self(),fw_notify_done, - {TVal/1000,Skip,Loc,[],Comment}} + {TVal/1000,Skip,Loc,[],undefined}} end, spawn_link(FwCall); spawn_fw_call(Mod,{end_per_testcase,Func},EndConf,Pid, - {timetrap_timeout,TVal}=Why,_Loc,SendTo,Comment) -> + {timetrap_timeout,TVal}=Why,_Loc,SendTo) -> %%! This is a temporary fix that keeps Test Server alive during %%! execution of a parallel test case group, when sometimes %%! this clause gets called with EndConf == undefined. See OTP-9594 @@ -987,6 +1006,9 @@ spawn_fw_call(Mod,{end_per_testcase,Func},EndConf,Pid, end, FwCall = fun() -> + %% set group leader so that printouts/comments + %% from the framework get printed in the logs + group_leader(SendTo, self()), {RetVal,Report} = case proplists:get_value(tc_status, EndConf1) of undefined -> @@ -1006,41 +1028,42 @@ spawn_fw_call(Mod,{end_per_testcase,Func},EndConf,Pid, _ -> ok end, - %% if end_per_testcase fails a warning should be - %% printed as comment - Comment1 = if Comment == "" -> - ""; - true -> - Comment ++ test_server_ctrl:xhtml("<br>", - "<br />") - end, - %% finished, report back + Warn = "<font color=\"red\">" + "WARNING: end_per_testcase timed out!</font>", + %% finished, report back (if end_per_testcase fails, a warning + %% should be printed as part of the comment) SendTo ! {self(),fw_notify_done, - {TVal/1000,RetVal,FailLoc,[], - [Comment1,"<font color=\"red\">" - "WARNING: end_per_testcase timed out!" - "</font>"]}} + {TVal/1000,RetVal,FailLoc,[],Warn}} end, spawn_link(FwCall); -spawn_fw_call(FwMod,FwFunc,_,_Pid,{framework_error,FwError},_,SendTo,_Comment) -> +spawn_fw_call(FwMod,FwFunc,_,_Pid,{framework_error,FwError},_,SendTo) -> FwCall = fun() -> + %% set group leader so that printouts/comments + %% from the framework get printed in the logs + group_leader(SendTo, self()), test_server_sup:framework_call(report, [framework_error, - {{FwMod,FwFunc},FwError}]), + {{FwMod,FwFunc}, + FwError}]), Comment = lists:flatten( io_lib:format("<font color=\"red\">" - "WARNING! ~w:~w failed!</font>", [FwMod,FwFunc])), + "WARNING! ~w:~w failed!</font>", + [FwMod,FwFunc])), %% finished, report back SendTo ! {self(),fw_notify_done, - {died,{error,{FwMod,FwFunc,FwError}},{FwMod,FwFunc},[],Comment}} + {died,{error,{FwMod,FwFunc,FwError}}, + {FwMod,FwFunc},[],Comment}} end, spawn_link(FwCall); -spawn_fw_call(Mod,Func,_,Pid,Error,Loc,SendTo,Comment) -> +spawn_fw_call(Mod,Func,_,Pid,Error,Loc,SendTo) -> FwCall = fun() -> + %% set group leader so that printouts/comments + %% from the framework get printed in the logs + group_leader(SendTo, self()), case catch fw_error_notify(Mod,Func,[], Error,Loc) of {'EXIT',FwErrorNotifyErr} -> @@ -1058,7 +1081,7 @@ spawn_fw_call(Mod,Func,_,Pid,Error,Loc,SendTo,Comment) -> ok end, %% finished, report back - SendTo ! {self(),fw_notify_done,{died,Error,Loc,Comment}} + SendTo ! {self(),fw_notify_done,{died,Error,Loc,[],undefined}} end, spawn_link(FwCall). @@ -1530,8 +1553,18 @@ get_loc(Pid) -> lists:foreach(fun({Key,Val}) -> put(Key, Val) end, Dict), Stk = [rewrite_loc_item(Loc) || Loc <- Stk0], case get(test_server_loc) of - undefined -> put(test_server_loc, Stk); - _ -> ok + undefined -> + put(test_server_loc, Stk); + {Suite,Case} -> + %% location info unknown, check if {Suite,Case,Line} + %% is available in stacktrace. and if so, use stacktrace + %% instead of currect test_server_loc + case [match || {S,C,_L} <- Stk, S == Suite, C == Case] of + [match|_] -> put(test_server_loc, Stk); + _ -> ok + end; + _ -> + ok end, get_loc(). diff --git a/lib/test_server/src/test_server_ctrl.erl b/lib/test_server/src/test_server_ctrl.erl index 3432b3bc8e..3bea9e39ee 100644 --- a/lib/test_server/src/test_server_ctrl.erl +++ b/lib/test_server/src/test_server_ctrl.erl @@ -1301,7 +1301,12 @@ terminate(_Reason, State) -> end, kill_all_jobs(State#state.jobs), test_server_node:stop(State#state.target_info), - test_server_h:restore(), + case lists:keysearch(sasl, 1, application:which_applications()) of + {value,_} -> + test_server_h:restore(); + _ -> + ok + end, ok. kill_all_jobs([{_Name,JobPid}|Jobs]) -> diff --git a/lib/test_server/src/test_server_h.erl b/lib/test_server/src/test_server_h.erl index e423863b99..6707f98109 100644 --- a/lib/test_server/src/test_server_h.erl +++ b/lib/test_server/src/test_server_h.erl @@ -79,10 +79,21 @@ set_group_leader() -> handle_event({_Type, GL, _Msg}, State) when node(GL)/=node() -> {ok, State}; handle_event({Tag, _GL, {_Pid, Type, _Report}} = Event, State) -> - case report(Tag, Type) of - sasl -> - tag(State#state.testcase), - sasl_report_tty_h:handle_event(Event, State#state.sasl); + SASL = lists:keyfind(sasl, 1, application:which_applications()), + case report_receiver(Tag, Type) of + sasl when SASL /= false -> + {ok,ErrLogType} = application:get_env(sasl, errlog_type), + SReport = sasl_report:format_report(group_leader(), ErrLogType, + tag_event(Event)), + if is_list(SReport) -> + tag(State#state.testcase), + sasl_report_tty_h:handle_event(Event, + State#state.sasl); + true -> %% Report is an atom if no logging is to be done + ignore + end; + sasl -> %% SASL not running + ignore; kernel -> tag(State#state.testcase), error_logger_tty_h:handle_event(Event, State#state.kernel); @@ -111,19 +122,22 @@ terminate(_Reason, _State) -> code_change(_OldVsn, State, _Extra) -> {ok, State}. -report(error_report, supervisor_report) -> sasl; -report(error_report, crash_report) -> sasl; -report(info_report, progress) -> sasl; -report(error, _) -> kernel; -report(error_report, _) -> kernel; -report(warning_msg, _) -> kernel; -report(warning_report, _) -> kernel; -report(info, _) -> kernel; -report(info_msg, _) -> kernel; -report(info_report, _) -> kernel; -report(_, _) -> none. +report_receiver(error_report, supervisor_report) -> sasl; +report_receiver(error_report, crash_report) -> sasl; +report_receiver(info_report, progress) -> sasl; +report_receiver(error, _) -> kernel; +report_receiver(error_report, _) -> kernel; +report_receiver(warning_msg, _) -> kernel; +report_receiver(warning_report, _) -> kernel; +report_receiver(info, _) -> kernel; +report_receiver(info_msg, _) -> kernel; +report_receiver(info_report, _) -> kernel; +report_receiver(_, _) -> none. tag({M,F,A}) when is_atom(M), is_atom(F), is_integer(A) -> io:format(user, "~n=TESTCASE: ~p:~p/~p", [M,F,A]); tag(Testcase) -> io:format(user, "~n=TESTCASE: ~p", [Testcase]). + +tag_event(Event) -> + {calendar:local_time(), Event}. diff --git a/lib/test_server/vsn.mk b/lib/test_server/vsn.mk index 88e3856cf4..a1f4559083 100644 --- a/lib/test_server/vsn.mk +++ b/lib/test_server/vsn.mk @@ -1 +1 @@ -TEST_SERVER_VSN = 3.5 +TEST_SERVER_VSN = 3.5.1 |