diff options
| -rw-r--r-- | lib/common_test/src/ct_hooks.erl | 7 | ||||
| -rw-r--r-- | lib/common_test/src/ct_logs.erl | 74 | ||||
| -rw-r--r-- | lib/common_test/src/ct_util.erl | 54 | ||||
| -rw-r--r-- | lib/common_test/src/cth_log_redirect.erl | 23 | ||||
| -rw-r--r-- | lib/common_test/test/Makefile | 1 | ||||
| -rw-r--r-- | lib/common_test/test/ct_pre_post_test_io_SUITE.erl | 252 | ||||
| -rw-r--r-- | lib/common_test/test/ct_pre_post_test_io_SUITE_data/cth_ctrl.erl | 104 | ||||
| -rw-r--r-- | lib/common_test/test/ct_pre_post_test_io_SUITE_data/dummy_SUITE.erl | 132 | ||||
| -rw-r--r-- | lib/common_test/test/ct_test_support.erl | 21 | ||||
| -rw-r--r-- | lib/test_server/src/test_server_ctrl.erl | 33 | ||||
| -rw-r--r-- | lib/test_server/src/test_server_io.erl | 200 | 
11 files changed, 818 insertions, 83 deletions
diff --git a/lib/common_test/src/ct_hooks.erl b/lib/common_test/src/ct_hooks.erl index 3d87a82e24..e845e9e908 100644 --- a/lib/common_test/src/ct_hooks.erl +++ b/lib/common_test/src/ct_hooks.erl @@ -50,9 +50,8 @@  -spec init(State :: term()) -> ok |  			       {fail, Reason :: term()}.  init(Opts) -> -    call(get_new_hooks(Opts, undefined) ++ get_builtin_hooks(Opts), +    call(get_builtin_hooks(Opts) ++ get_new_hooks(Opts, undefined),  	 ok, init, []). -		        %% @doc Called after all suites are done.  -spec terminate(Hooks :: term()) -> @@ -276,8 +275,10 @@ get_new_hooks(Config, Fun) ->  		end, get_new_hooks(Config)).  get_new_hooks(Config) when is_list(Config) -> -    lists:flatmap(fun({?config_name, HookConfigs}) -> +    lists:flatmap(fun({?config_name, HookConfigs}) when is_list(HookConfigs) ->  			  HookConfigs; +		     ({?config_name, HookConfig}) when is_atom(HookConfig) -> +			  [HookConfig];  		     (_) ->  			  []  		  end, Config); diff --git a/lib/common_test/src/ct_logs.erl b/lib/common_test/src/ct_logs.erl index bd37b690b6..1a6e4d31a8 100644 --- a/lib/common_test/src/ct_logs.erl +++ b/lib/common_test/src/ct_logs.erl @@ -61,6 +61,7 @@  -define(index_name, "index.html").  -define(totals_name, "totals.info").  -define(log_cache_name, "ct_log_cache"). +-define(misc_io_log, "misc_io.log.html").  -define(table_color1,"#ADD8E6").  -define(table_color2,"#E4F0FE"). @@ -523,7 +524,7 @@ int_footer() ->  div_header(Class) ->      div_header(Class,"User").  div_header(Class,Printer) -> -    "<div class=\"" ++ atom_to_list(Class) ++ "\"><b>*** " ++ Printer ++ +    "\n<div class=\"" ++ atom_to_list(Class) ++ "\"><b>*** " ++ Printer ++      " " ++ log_timestamp(now()) ++ " ***</b>".  div_footer() ->      "</div>". @@ -617,6 +618,34 @@ logger(Parent, Mode, Verbosity) ->  		    end  	    end      end, + +    test_server_io:start_link(), +    MiscIoName = filename:join(Dir, ?misc_io_log), +    {ok,MiscIoFd} = file:open(MiscIoName, +			      [write,{encoding,utf8}]), +    test_server_io:set_fd(unexpected_io, MiscIoFd), + +    {MiscIoHeader,MiscIoFooter} = +	case get_ts_html_wrapper("Pre/post-test I/O log", Dir, false, +				 Dir, undefined, utf8) of +	    {basic_html,UH,UF} -> +		{UH,UF}; +	    {xhtml,UH,UF} -> +		{UH,UF} +	end, +    io:put_chars(MiscIoFd, +		 [MiscIoHeader, +		  "<a name=\"pretest\"></a>\n", +		  xhtml("<br>\n<h2>Pre-test Log</h2>", +			"<br />\n<h3>PRE-TEST LOG</h3>"), +		  "\n<pre>\n"]), +    MiscIoDivider = +	"\n<a name=\"posttest\"></a>\n"++ +	xhtml("</pre>\n<br><h2>Post-test Log</h2>\n<pre>\n", +	      "</pre>\n<br />\n<h3>POST-TEST LOG</h3>\n<pre>\n"), +    ct_util:set_testdata_async({misc_io_log,{filename:absname(MiscIoName), +					     MiscIoDivider,MiscIoFooter}}), +      ct_event:notify(#event{name=start_logging,node=node(),  			   data=AbsDir}),      make_all_runs_index(start), @@ -627,7 +656,7 @@ logger(Parent, Mode, Verbosity) ->      end,      file:set_cwd(Dir),      make_last_run_index(Time), -    CtLogFd = open_ctlog(), +    CtLogFd = open_ctlog(?misc_io_log),      io:format(CtLogFd,int_header()++int_footer(),  	      [log_timestamp(now()),"Common Test Logger started"]),      Parent ! {started,self(),{Time,filename:absname("")}}, @@ -922,7 +951,7 @@ set_evmgr_gl(GL) ->  	EvMgrPid -> group_leader(GL,EvMgrPid)      end. -open_ctlog() -> +open_ctlog(MiscIoName) ->      {ok,Fd} = file:open(?ct_log_name,[write,{encoding,utf8}]),      io:format(Fd, header("Common Test Framework Log", {[],[1,2],[]}), []),      case file:consult(ct_run:variables_file_name("../")) of @@ -937,10 +966,21 @@ open_ctlog() ->  		      "No configuration found for test!!\n",  		      [Variables,Reason])      end, +    io:format(Fd,  +	      xhtml("<br><br><h2>Pre/post-test I/O Log</h2>\n", +		    "<br /><br />\n<h4>PRE/POST TEST I/O LOG</h4>\n"), []),     +    io:format(Fd, +	      "\n<ul>\n" +	      "<li><a href=\"~ts#pretest\">" +	      "View I/O logged before the test run</a></li>\n" +	      "<li><a href=\"~ts#posttest\">" +	      "View I/O logged after the test run</a></li>\n</ul>\n", +	      [MiscIoName,MiscIoName]), +      print_style(Fd,undefined),      io:format(Fd,  -	      xhtml("<br><br><h2>Progress Log</h2>\n<pre>\n", -		    "<br /><br /><h4>PROGRESS LOG</h4>\n<pre>\n"), []), +	      xhtml("<br><h2>Progress Log</h2>\n<pre>\n", +		    "<br />\n<h4>PROGRESS LOG</h4>\n<pre>\n"), []),      Fd.  print_style(Fd,undefined) -> @@ -2856,6 +2896,9 @@ make_relative1(DirTs, CwdTs) ->  %%% @doc  %%%  get_ts_html_wrapper(TestName, PrintLabel, Cwd, TableCols, Encoding) -> +    get_ts_html_wrapper(TestName, undefined, PrintLabel, Cwd, TableCols, Encoding). + +get_ts_html_wrapper(TestName, Logdir, PrintLabel, Cwd, TableCols, Encoding) ->      TestName1 = if is_list(TestName) ->  			lists:flatten(TestName);  		   true -> @@ -2876,7 +2919,12 @@ get_ts_html_wrapper(TestName, PrintLabel, Cwd, TableCols, Encoding) ->  		end  	end,      CTPath = code:lib_dir(common_test), -    {ok,CtLogdir} = get_log_dir(true), + +    {ok,CtLogdir} = +	if Logdir == undefined -> get_log_dir(true); +	   true -> {ok,Logdir} +	end, +      AllRuns = make_relative(filename:join(filename:dirname(CtLogdir),  					  ?all_runs_name), Cwd),      TestIndex = make_relative(filename:join(filename:dirname(CtLogdir), @@ -3074,16 +3122,8 @@ unexpected_io(Pid,ct_internal,_Importance,List,State) ->      IoFun = create_io_fun(Pid,State),      io:format(State#logger_state.ct_log_fd, "~ts",  	      [lists:foldl(IoFun, [], List)]); -unexpected_io(Pid,Category,Importance,List,State) -> +unexpected_io(Pid,_Category,_Importance,List,State) ->      IoFun = create_io_fun(Pid,State),      Data = io_lib:format("~ts", [lists:foldl(IoFun, [], List)]), -    %% if unexpected io comes in during startup or shutdown, test_server -    %% might not be running - if so (noproc exit), simply print to -    %% stdout instead (will result in double printouts when pal is used) -    try test_server_io:print_unexpected(Data) of -	_ -> -	    ok -    catch -	_:{noproc,_} -> tc_print(Category,Importance,Data,[]); -	_:Reason     -> exit(Reason) -    end. +    test_server_io:print_unexpected(Data), +    ok. diff --git a/lib/common_test/src/ct_util.erl b/lib/common_test/src/ct_util.erl index abda87c2cd..bcc4caa62e 100644 --- a/lib/common_test/src/ct_util.erl +++ b/lib/common_test/src/ct_util.erl @@ -187,6 +187,7 @@ do_start(Parent, Mode, LogDir, Verbosity) ->  	false ->  	    ok      end, +      {StartTime,TestLogDir} = ct_logs:init(Mode, Verbosity),      ct_event:notify(#event{name=test_start, @@ -198,12 +199,26 @@ do_start(Parent, Mode, LogDir, Verbosity) ->  	ok ->  	    Parent ! {self(),started};  	{fail,CTHReason} -> -	    ct_logs:tc_print('Suite Callback',CTHReason,[]), +	    ErrorInfo = if is_atom(CTHReason) -> +				io_lib:format("{~p,~p}", +					      [CTHReason, +					       erlang:get_stacktrace()]); +			   true -> +				CTHReason +			end, +	    ct_logs:tc_print('Suite Callback',ErrorInfo,[]),  	    self() ! {{stop,{self(),{user_error,CTHReason}}},  		      {Parent,make_ref()}}      catch  	_:CTHReason -> -	    ct_logs:tc_print('Suite Callback',CTHReason,[]), +	    ErrorInfo = if is_atom(CTHReason) -> +				io_lib:format("{~p,~p}", +					      [CTHReason, +					       erlang:get_stacktrace()]); +			   true -> +				CTHReason +			end, +	    ct_logs:tc_print('Suite Callback',ErrorInfo,[]),  	    self() ! {{stop,{self(),{user_error,CTHReason}}},  		      {Parent,make_ref()}}      end, @@ -392,19 +407,38 @@ loop(Mode,TestData,StartDir) ->  	    return(From,StartDir),  	    loop(From,TestData,StartDir);  	{{stop,Info},From} -> +	    test_server_io:reset_state(), +	    {MiscIoName,MiscIoDivider,MiscIoFooter} = +		proplists:get_value(misc_io_log,TestData), +	    {ok,MiscIoFd} = file:open(MiscIoName, +				      [append,{encoding,utf8}]), +	    io:put_chars(MiscIoFd, MiscIoDivider), +	    test_server_io:set_fd(unexpected_io, MiscIoFd), +  	    Time = calendar:local_time(),  	    ct_event:sync_notify(#event{name=test_done,  					node=node(),  					data=Time}), -	    Callbacks = ets:lookup_element(?suite_table, -					   ct_hooks, -					   #suite_data.value), +	    Callbacks = +		try ets:lookup_element(?suite_table, +				       ct_hooks, +				       #suite_data.value) of +		    CTHMods -> CTHMods +		catch +		    %% this is because ct_util failed in init +		    error:badarg -> [] +		end,  	    ct_hooks:terminate(Callbacks),  	    close_connections(ets:tab2list(?conn_table)),  	    ets:delete(?conn_table),  	    ets:delete(?board_table),  	    ets:delete(?suite_table),  	    ets:delete(?verbosity_table), + +	    io:put_chars(MiscIoFd, "\n</pre>\n"++MiscIoFooter), +	    test_server_io:stop([unexpected_io]), +	    test_server_io:finish(), +  	    ct_logs:close(Info, StartDir),  	    ct_event:stop(),  	    ct_config:stop(), @@ -679,8 +713,14 @@ reset_silent_connections() ->  %%% @see ct  stop(Info) ->      case whereis(ct_util_server) of -	undefined -> ok; -	_ -> call({stop,Info}) +	undefined ->  +	    ok; +	CtUtilPid -> +	    Ref = monitor(process, CtUtilPid), +	    call({stop,Info}), +	    receive +		{'DOWN',Ref,_,_,_} -> ok +	    end      end.  %%%----------------------------------------------------------------- diff --git a/lib/common_test/src/cth_log_redirect.erl b/lib/common_test/src/cth_log_redirect.erl index a030701f19..11af1aa346 100644 --- a/lib/common_test/src/cth_log_redirect.erl +++ b/lib/common_test/src/cth_log_redirect.erl @@ -36,13 +36,17 @@  	 handle_event/2, handle_call/2, handle_info/2,  	 terminate/1]). +%% Other +-export([handle_remote_events/1]). +  -include("ct.hrl").  -record(eh_state, {log_func,  		   curr_suite,  		   curr_group,  		   curr_func, -		   parallel_tcs = false}). +		   parallel_tcs = false, +		   handle_remote_events = false}).  id(_Opts) ->      ?MODULE. @@ -51,7 +55,6 @@ init(?MODULE, _Opts) ->      error_logger:add_report_handler(?MODULE),      tc_log_async. -  pre_init_per_suite(Suite, Config, State) ->      set_curr_func({Suite,init_per_suite}, Config),      {Config, State}. @@ -104,7 +107,8 @@ post_end_per_group(_Group, Config, Return, State) ->  init(_Type) ->      {ok, #eh_state{log_func = tc_log_async}}. -handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() -> +handle_event({_Type,GL,_Msg}, #eh_state{handle_remote_events = false} = State) +  when node(GL) /= node() ->      {ok, State};  handle_event(Event, #eh_state{log_func = LogFunc} = State) ->      case lists:keyfind(sasl, 1, application:which_applications()) of @@ -160,9 +164,12 @@ handle_call({set_curr_func,undefined,_Config}, State) ->  handle_call({set_curr_func,TC,_Config}, State) ->      {ok, ok, State#eh_state{curr_func = TC}}; -handle_call({set_logfunc,NewLogFunc},State) -> +handle_call({set_logfunc,NewLogFunc}, State) ->      {ok, NewLogFunc, State#eh_state{log_func = NewLogFunc}}; +handle_call({handle_remote_events,Bool}, State) -> +    {ok, ok, State#eh_state{handle_remote_events = Bool}}; +  handle_call(_Query, _State) ->      {error, bad_query}. @@ -179,8 +186,16 @@ set_curr_func(CurrFunc, Config) ->  set_log_func(Func) ->      gen_event:call(error_logger, ?MODULE, {set_logfunc, Func}). +handle_remote_events(Bool) -> +    gen_event:call(error_logger, ?MODULE, {handle_remote_events, Bool}). +  %%%----------------------------------------------------------------- +format_header(#eh_state{curr_suite = undefined, +			curr_group = undefined, +			curr_func = undefined}) -> +    io_lib:format("System report", []); +  format_header(#eh_state{curr_suite = Suite,  			curr_group = undefined,  			curr_func = undefined}) -> diff --git a/lib/common_test/test/Makefile b/lib/common_test/test/Makefile index 9d2edcd653..085f19d023 100644 --- a/lib/common_test/test/Makefile +++ b/lib/common_test/test/Makefile @@ -51,6 +51,7 @@ MODULES= \  	ct_master_SUITE \  	ct_misc_1_SUITE \  	ct_hooks_SUITE \ +	ct_pre_post_test_io_SUITE \  	ct_netconfc_SUITE \  	ct_basic_html_SUITE \  	ct_auto_compile_SUITE \ diff --git a/lib/common_test/test/ct_pre_post_test_io_SUITE.erl b/lib/common_test/test/ct_pre_post_test_io_SUITE.erl new file mode 100644 index 0000000000..84341a0b99 --- /dev/null +++ b/lib/common_test/test/ct_pre_post_test_io_SUITE.erl @@ -0,0 +1,252 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2012. 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% +%% + +%%%------------------------------------------------------------------- +%%% File: ct_pre_post_test_io_SUITE +%%% +%%% Description: +%%% +%%% Test that ct:log/2 printouts and error/progress reports that happen +%%% before or after the test run are saved in the pre/post test IO log. +%%%------------------------------------------------------------------- +-module(ct_pre_post_test_io_SUITE). + +-compile(export_all). + +-include_lib("common_test/include/ct.hrl"). +-include_lib("common_test/include/ct_event.hrl"). + +-define(eh, ct_test_support_eh). + +%%-------------------------------------------------------------------- +%% TEST SERVER CALLBACK FUNCTIONS +%%-------------------------------------------------------------------- + +%%-------------------------------------------------------------------- +%% Description: Since Common Test starts another Test Server +%% instance, the tests need to be performed on a separate node (or +%% there will be clashes with logging processes etc). +%%-------------------------------------------------------------------- +init_per_suite(Config) -> +    DataDir = ?config(data_dir, Config), +    CTH = filename:join(DataDir, "cth_ctrl.erl"), +    ct:pal("Compiling ~p: ~p", +	   [CTH,compile:file(CTH,[{outdir,DataDir},debug_info])]), +    ct_test_support:init_per_suite([{path_dirs,[DataDir]}, +				    {start_sasl,true} | Config]). + +end_per_suite(Config) -> +    ct_test_support:end_per_suite(Config). + +init_per_testcase(TestCase, Config) -> +    ct_test_support:init_per_testcase(TestCase, Config). + +end_per_testcase(TestCase, Config) -> +    ct_test_support:end_per_testcase(TestCase, Config). + +suite() -> [{ct_hooks,[ts_install_cth]}]. + +all() -> +    [ +     pre_post_io +    ]. + +%%-------------------------------------------------------------------- +%% TEST CASES +%%-------------------------------------------------------------------- + +%%%----------------------------------------------------------------- +%%% +pre_post_io(Config) -> +    TC = pre_post_io, +    DataDir = ?config(data_dir, Config), +    Suite = filename:join(DataDir, "dummy_SUITE"), +    {Opts,ERPid} = setup([{suite,Suite},{label,TC},{ct_hooks,[cth_ctrl]}], +			 Config), +     +    %%!-------------------------------------------------------------------- +    %%! Note that error reports will not start showing up in the pre-test +    %%! io log until handle_remote_events has been set to true (see below). +    %%! The reason is that the error logger has its group leader on the +    %%! test_server node (not the ct node) and cth_log_redirect ignores +    %%! events with remote destination until told otherwise. +    %%!-------------------------------------------------------------------- + +    spawn(fun() -> +		  %% --- test run 1 --- +		  ct:sleep(3000), +		  ct_test_support:ct_rpc({cth_log_redirect, +					  handle_remote_events, +					  [true]}, Config), +		  ct:sleep(2000), +		  io:format(user, "Starting test run!~n", []), +		  ct_test_support:ct_rpc({cth_ctrl,proceed,[]}, Config), +		  ct:sleep(6000), +		  io:format(user, "Finishing off!~n", []), +		  ct_test_support:ct_rpc({cth_ctrl,proceed,[]}, Config), +		  %% --- test run 2 --- +		  ct:sleep(3000), +		  ct_test_support:ct_rpc({cth_log_redirect, +					  handle_remote_events, +					  [true]}, Config), +		  ct:sleep(2000), +		  io:format(user, "Starting test run!~n", []), +		  ct_test_support:ct_rpc({cth_ctrl,proceed,[]}, Config), +		  ct:sleep(6000), +		  io:format(user, "Finishing off!~n", []), +		  ct_test_support:ct_rpc({cth_ctrl,proceed,[]}, Config) +	  end), +    ct_test_support:run(Opts, Config), +    Events = ct_test_support:get_events(ERPid, Config), +    ct_test_support:log_events(TC, +			       reformat(Events, ?eh), +			       ?config(priv_dir, Config), +			       Opts), +    TestEvents = events_to_check(TC), +    ok = ct_test_support:verify_events(TestEvents, Events, Config), +     +    LogDirs = lists:flatmap(fun({_EH,#event{name=start_logging,data=Dir}}) -> +				    [Dir]; +			       (_) -> +				    [] +			    end, Events), +    PrePostIoFiles = +	[filename:join(LogDir, "misc_io.log.html") || LogDir <- LogDirs], +    lists:foreach( +      fun(PrePostIoFile) -> +	      ct:log("Reading Pre/Post Test IO Log file: ~ts", [PrePostIoFile]), +	      {ok,Bin} = file:read_file(PrePostIoFile), +	      Ts = string:tokens(binary_to_list(Bin),[$\n]), +	      PrePostIOEntries = +		  lists:foldl(fun([$L,$o,$g,$g,$e,$r|_], +				  {pre,PreLogN,PreErrN,0,0}) -> +				      {pre,PreLogN+1,PreErrN,0,0}; +				 ([$=,$E,$R,$R,$O,$R|_], +				  {pre,PreLogN,PreErrN,0,0}) -> +				      {pre,PreLogN,PreErrN+1,0,0}; +				 ([_,_,_,_,$P,$O,$S,$T,$-,$T,$E,$S,$T|_], +				  {pre,PreLogN,PreErrN,0,0}) -> +				      {post,PreLogN,PreErrN,0,0}; +				 ([$L,$o,$g,$g,$e,$r|_], +				  {post,PreLogN,PreErrN,PostLogN,PostErrN}) -> +				      {post,PreLogN,PreErrN,PostLogN+1,PostErrN}; +				 ([$=,$E,$R,$R,$O,$R|_], +				  {post,PreLogN,PreErrN,PostLogN,PostErrN}) -> +				      {post,PreLogN,PreErrN,PostLogN,PostErrN+1}; +				 (_, Counters) -> +				      Counters +			      end, {pre,0,0,0,0}, Ts), +	      [_|Counters] = tuple_to_list(PrePostIOEntries), +	      ct:log("Entries in the Pre/Post Test IO Log: ~p", [Counters]), +	      case [C || C <- Counters, C < 2] of +		  [] -> +		      ok; +		  _ -> +		      exit("Not enough entries in the Pre/Post Test IO Log!") +	      end +      end, PrePostIoFiles),  + +    UnexpIoFiles = +	[filelib:wildcard( +	   filename:join(LogDir, +			 "*dummy_SUITE.logs/run.*/" +			 "unexpected_io.log.html")) || LogDir <- LogDirs], +    lists:foreach( +      fun(UnexpIoFile) -> +	      ct:log("Reading Unexpected IO Log file: ~ts", [UnexpIoFile]), +	      {ok,Bin} = file:read_file(UnexpIoFile), +	      Ts = string:tokens(binary_to_list(Bin),[$\n]), +	      UnexpIOEntries = +		  lists:foldl(fun([$L,$o,$g,$g,$e,$r|_], [LogN,ErrN]) -> +				      [LogN+1,ErrN]; +				 ([$=,$E,$R,$R,$O,$R|_], [LogN,ErrN]) -> +				      [LogN,ErrN+1]; +				 (_, Counters) -> Counters +			      end, [0,0], Ts), +	      ct:log("Entries in the Unexpected IO Log: ~p", [UnexpIOEntries]), +	      case [N || N <- UnexpIOEntries, N < 2] of +		  [] -> +		      ok; +		  _ -> +		      exit("Not enough entries in the Unexpected IO Log!") +	      end +      end, UnexpIoFiles), +    ok. + +%%%----------------------------------------------------------------- +%%% HELP FUNCTIONS +%%%----------------------------------------------------------------- + +setup(Test, Config) -> +    Opts0 = ct_test_support:get_opts(Config), +    Level = ?config(trace_level, Config), +    EvHArgs = [{cbm,ct_test_support},{trace_level,Level}], +    Opts = Opts0 ++ [{event_handler,{?eh,EvHArgs}}|Test], +    ERPid = ct_test_support:start_event_receiver(Config), +    {Opts,ERPid}. + +reformat(Events, EH) -> +    ct_test_support:reformat(Events, EH). + +%%%----------------------------------------------------------------- +%%% TEST EVENTS +%%%----------------------------------------------------------------- + +events_to_check(pre_post_io) -> +    [ +     {?eh,start_logging,{'DEF','RUNDIR'}}, +     {?eh,test_start,{'DEF',{'START_TIME','LOGDIR'}}}, +     {?eh,start_info,{1,1,7}}, +     {?eh,tc_start,{dummy_SUITE,init_per_suite}}, +     {?eh,tc_done,{dummy_SUITE,init_per_suite,ok}}, +     {parallel, +      [{?eh,tc_start,{dummy_SUITE,{init_per_group,g1,[parallel]}}}, +       {?eh,tc_done, +	{dummy_SUITE,{init_per_group,g1,[parallel]},ok}}, +       {?eh,tc_start,{dummy_SUITE,tc1}}, +       {?eh,tc_start,{dummy_SUITE,tc2}}, +       {?eh,tc_start,{dummy_SUITE,tc3}}, +       {?eh,tc_done,{dummy_SUITE,tc2,ok}}, +       {?eh,tc_done,{dummy_SUITE,tc1,ok}}, +       {?eh,tc_done,{dummy_SUITE,tc3,ok}}, +       {?eh,test_stats,{1,0,{0,0}}}, +       {?eh,test_stats,{2,0,{0,0}}}, +       {?eh,test_stats,{3,0,{0,0}}}, +       {?eh,tc_start,{dummy_SUITE,{end_per_group,g1,[parallel]}}}, +       {?eh,tc_done,{dummy_SUITE,{end_per_group,g1,[parallel]},ok}}]}, +     {?eh,tc_start,{dummy_SUITE,tc1}}, +     {?eh,tc_done,{dummy_SUITE,tc1,ok}}, +     {?eh,test_stats,{4,0,{0,0}}}, +     {?eh,tc_start,{dummy_SUITE,tc2}}, +     {?eh,tc_done,{dummy_SUITE,tc2,ok}}, +     {?eh,test_stats,{5,0,{0,0}}}, +     [{?eh,tc_start,{dummy_SUITE,{init_per_group,g2,[]}}}, +      {?eh,tc_done,{dummy_SUITE,{init_per_group,g2,[]},ok}}, +      {?eh,tc_start,{dummy_SUITE,tc4}}, +      {?eh,tc_done,{dummy_SUITE,tc4,ok}}, +      {?eh,test_stats,{6,0,{0,0}}}, +      {?eh,tc_start,{dummy_SUITE,tc5}}, +      {?eh,tc_done,{dummy_SUITE,tc5,ok}}, +      {?eh,test_stats,{7,0,{0,0}}}, +      {?eh,tc_start,{dummy_SUITE,{end_per_group,g2,[]}}}, +      {?eh,tc_done,{dummy_SUITE,{end_per_group,g2,[]},ok}}], +     {?eh,tc_start,{dummy_SUITE,end_per_suite}}, +     {?eh,tc_done,{dummy_SUITE,end_per_suite,ok}}, +     {?eh,test_done,{'DEF','STOP_TIME'}}, +     {?eh,stop_logging,[]}]. diff --git a/lib/common_test/test/ct_pre_post_test_io_SUITE_data/cth_ctrl.erl b/lib/common_test/test/ct_pre_post_test_io_SUITE_data/cth_ctrl.erl new file mode 100644 index 0000000000..a9ea7b14dd --- /dev/null +++ b/lib/common_test/test/ct_pre_post_test_io_SUITE_data/cth_ctrl.erl @@ -0,0 +1,104 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2012. 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(cth_ctrl). + +-export([proceed/0, +	 init/2, terminate/1]). + +%%%=================================================================== +%%% API +%%%=================================================================== + +proceed() -> +    ?MODULE ! proceed. + +%%-------------------------------------------------------------------- +%% Hook functions +%%-------------------------------------------------------------------- +init(_Id, _Opts) -> +    case lists:keyfind(sasl, 1, application:which_applications()) of +	false -> +	    exit(sasl_not_started); +	_Else -> +	    ok +    end, +    WhoAmI = self(), +    DispPid = spawn_link(fun() -> dispatcher(WhoAmI) end), +    register(?MODULE, DispPid), +    io:format(user, +	      "~n~n+++ Startup of ~w on ~p finished, " +	      "call ~w:proceed() to run tests...~n", +	      [?MODULE,node(),?MODULE]), +    start_external_logger(cth_logger), +    receive +	{?MODULE,proceed} -> ok +    after +	10000 -> +	    ok +    end, +    {ok,[],ct_last}. + +terminate(_State) -> +    io:format(user, +	      "~n~n+++ Tests finished, call ~w:proceed() to shut down...~n", +	      [?MODULE]), +    receive +	{?MODULE,proceed} -> ok +    after +       10000 -> +	    ok +    end, +    stop_external_logger(cth_logger), +    stop_dispatcher(), +    ok. + +%%%=================================================================== +%%% Internal functions +%%%=================================================================== + +start_external_logger(Name) -> +    case whereis(Name) of +	undefined -> ok; +	Pid -> exit(Pid, kill) +    end, +    spawn(fun() -> init_logger(Name) end). + +stop_external_logger(Name) -> +    catch exit(whereis(Name), kill). + +init_logger(Name) -> +    register(Name, self()), +    logger_loop(1). + +logger_loop(N) -> +    ct:log("Logger iteration: ~p", [N]), +    error_logger:error_report(N), +    timer:sleep(250), +    logger_loop(N+1). + +%%%----------------------------------------------------------------- + +dispatcher(SendTo) -> +    receive Msg -> SendTo ! {?MODULE,Msg} end, +    dispatcher(SendTo). + +stop_dispatcher() -> +    catch exit(whereis(?MODULE), kill). +	     + diff --git a/lib/common_test/test/ct_pre_post_test_io_SUITE_data/dummy_SUITE.erl b/lib/common_test/test/ct_pre_post_test_io_SUITE_data/dummy_SUITE.erl new file mode 100644 index 0000000000..ac9c4efd31 --- /dev/null +++ b/lib/common_test/test/ct_pre_post_test_io_SUITE_data/dummy_SUITE.erl @@ -0,0 +1,132 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2012. 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(dummy_SUITE). + +-compile(export_all). + +-include_lib("common_test/include/ct.hrl"). + +%%-------------------------------------------------------------------- +%% @spec suite() -> Info +%% Info = [tuple()] +%% @end +%%-------------------------------------------------------------------- +suite() -> +    [{timetrap,{seconds,30}}]. + +%%-------------------------------------------------------------------- +%% @spec init_per_suite(Config0) -> +%%     Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%% @end +%%-------------------------------------------------------------------- +init_per_suite(Config) -> +    Config. + +%%-------------------------------------------------------------------- +%% @spec end_per_suite(Config0) -> void() | {save_config,Config1} +%% Config0 = Config1 = [tuple()] +%% @end +%%-------------------------------------------------------------------- +end_per_suite(_Config) -> +    ok. + +%%-------------------------------------------------------------------- +%% @spec init_per_group(GroupName, Config0) -> +%%               Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% GroupName = atom() +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%% @end +%%-------------------------------------------------------------------- +init_per_group(_GroupName, Config) -> +    Config. +     +%%-------------------------------------------------------------------- +%% @spec end_per_group(GroupName, Config0) -> +%%               void() | {save_config,Config1} +%% GroupName = atom() +%% Config0 = Config1 = [tuple()] +%% @end +%%-------------------------------------------------------------------- +end_per_group(_GroupName, _Config) -> +    ok. + +%%-------------------------------------------------------------------- +%% @spec init_per_testcase(TestCase, Config0) -> +%%               Config1 | {skip,Reason} | {skip_and_save,Reason,Config1} +%% TestCase = atom() +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%% @end +%%-------------------------------------------------------------------- +init_per_testcase(_TestCase, Config) -> +    ct:sleep(500), +    Config. + +%%-------------------------------------------------------------------- +%% @spec end_per_testcase(TestCase, Config0) -> +%%               void() | {save_config,Config1} | {fail,Reason} +%% TestCase = atom() +%% Config0 = Config1 = [tuple()] +%% Reason = term() +%% @end +%%-------------------------------------------------------------------- +end_per_testcase(_TestCase, _Config) -> +    ok. + +%%-------------------------------------------------------------------- +%% @spec 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 +%% @end +%%-------------------------------------------------------------------- +groups() -> +    [{g1,[parallel],[tc1,tc2,tc3]}, +     {g2,[],[tc4,tc5]}]. + +%%-------------------------------------------------------------------- +%% @spec all() -> GroupsAndTestCases | {skip,Reason} +%% GroupsAndTestCases = [{group,GroupName} | TestCase] +%% GroupName = atom() +%% TestCase = atom() +%% Reason = term() +%% @end +%%-------------------------------------------------------------------- +all() ->  +    [{group,g1},tc1,tc2,{group,g2}]. + +tc1(_C) -> +    ok. +tc2(_C) -> +    ok. +tc3(_C) -> +    ok. +tc4(_C) -> +    ok. +tc5(_C) -> +    ok. diff --git a/lib/common_test/test/ct_test_support.erl b/lib/common_test/test/ct_test_support.erl index 4132995bf6..67e430f821 100644 --- a/lib/common_test/test/ct_test_support.erl +++ b/lib/common_test/test/ct_test_support.erl @@ -38,7 +38,7 @@  -export([start_slave/3, slave_stop/1]). --export([ct_test_halt/1]). +-export([ct_test_halt/1, ct_rpc/2]).  -include_lib("kernel/include/file.hrl"). @@ -65,7 +65,6 @@ init_per_suite(Config, Level) ->  	_ ->  	    ok      end, -          start_slave(Config, Level).  start_slave(Config, Level) -> @@ -103,6 +102,14 @@ start_slave(NodeName, Config, Level) ->  	    test_server:format(Level, "Dirs added to code path (on ~w):~n",  			       [CTNode]),  	    [io:format("~s~n", [D]) || D <- PathDirs], +	     +	    case proplists:get_value(start_sasl, Config) of +		true -> +		    rpc:call(CTNode, application, start, [sasl]), +		    test_server:format(Level, "SASL started on ~w~n", [CTNode]); +		_ -> +		    ok +	    end,  	    TraceFile = filename:join(DataDir, "ct.trace"),  	    case file:read_file_info(TraceFile) of @@ -378,6 +385,16 @@ wait_for_ct_stop(Retries, CTNode) ->      end.  %%%----------------------------------------------------------------- +%%% ct_rpc/1 +ct_rpc({M,F,A}, Config) -> +    CTNode = proplists:get_value(ct_node, Config), +    Level = proplists:get_value(trace_level, Config), +    test_server:format(Level, "~nCalling ~w:~w(~p) on ~p...", +		       [M,F,A, CTNode]), +    rpc:call(CTNode, M, F, A). + + +%%%-----------------------------------------------------------------  %%% EVENT HANDLING  handle_event(EH, Event) -> diff --git a/lib/test_server/src/test_server_ctrl.erl b/lib/test_server/src/test_server_ctrl.erl index 4a10684ea5..d0f31af198 100644 --- a/lib/test_server/src/test_server_ctrl.erl +++ b/lib/test_server/src/test_server_ctrl.erl @@ -1171,7 +1171,13 @@ init_tester(Mod, Func, Args, Dir, Name, {_,_,MinLev}=Levels,  	  "<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]), -    test_server_io:stop([major,html,unexpected_io]). + +    test_server_io:stop([major,html,unexpected_io]), +    {UnexpectedIoName,UnexpectedIoFooter} = get(test_server_unexpected_footer), +    {ok,UnexpectedIoFd} = open_html_file(UnexpectedIoName, [append]), +    io:put_chars(UnexpectedIoFd, "\n</pre>\n"++UnexpectedIoFooter), +    file:close(UnexpectedIoFd), +    ok.  report_severe_error(Reason) ->      test_server_sup:framework_call(report, [severe_error,Reason]). @@ -1630,15 +1636,13 @@ start_log_file() ->  		    FilenameMode),      ok = write_file(?last_file, TestDir1 ++ "\n", FilenameMode),      put(test_server_log_dir_base,TestDir1), +      MajorName = filename:join(TestDir1, ?suitelog_name),      HtmlName = MajorName ++ ?html_ext,      UnexpectedName = filename:join(TestDir1, ?unexpected_io_log), +      {ok,Major} = open_utf8_file(MajorName),      {ok,Html}  = open_html_file(HtmlName), -    {ok,Unexpected}  = open_html_file(UnexpectedName), -    test_server_io:set_fd(major, Major), -    test_server_io:set_fd(html, Html), -    test_server_io:set_fd(unexpected_io, Unexpected),      {UnexpHeader,UnexpFooter} =  	case test_server_sup:framework_call(get_html_wrapper, @@ -1651,8 +1655,17 @@ start_log_file() ->  	    {xhtml,UH,UF} ->  		{UH,UF}  	end, -    io:put_chars(Unexpected, UnexpHeader++"\n<pre>\n"), -    put(test_server_unexpected_footer,UnexpFooter), + +    {ok,Unexpected} = open_html_file(UnexpectedName), +    io:put_chars(Unexpected, [UnexpHeader,			       +			      xhtml("<br>\n<h2>Unexpected I/O</h2>", +				    "<br />\n<h3>Unexpected I/O</h3>"), +			      "\n<pre>\n"]), +    put(test_server_unexpected_footer,{UnexpectedName,UnexpFooter}), + +    test_server_io:set_fd(major, Major), +    test_server_io:set_fd(html, Html), +    test_server_io:set_fd(unexpected_io, Unexpected),      make_html_link(filename:absname(?last_test ++ ?html_ext),  		   HtmlName, filename:basename(Dir)), @@ -5287,6 +5300,9 @@ html_header(Title) ->  open_html_file(File) ->      open_utf8_file(File). +open_html_file(File,Opts) -> +    open_utf8_file(File,Opts). +  write_html_file(File,Content) ->      write_file(File,Content,utf8). @@ -5295,6 +5311,9 @@ write_html_file(File,Content) ->  open_utf8_file(File) ->      file:open(File,[write,{encoding,utf8}]). +open_utf8_file(File,Opts) -> +    file:open(File,[{encoding,utf8}|Opts]). +  %% Write a file with specified encoding  write_file(File,Content,latin1) ->      file:write_file(File,Content); diff --git a/lib/test_server/src/test_server_io.erl b/lib/test_server/src/test_server_io.erl index 73d4468bda..62af3d5b28 100644 --- a/lib/test_server/src/test_server_io.erl +++ b/lib/test_server/src/test_server_io.erl @@ -32,27 +32,39 @@  -export([start_link/0,stop/1,get_gl/1,set_fd/2,  	 start_transaction/0,end_transaction/0,  	 print_buffered/1,print/3,print_unexpected/1, -	 set_footer/1,set_job_name/1,set_gl_props/1]). +	 set_footer/1,set_job_name/1,set_gl_props/1, +	 reset_state/0,finish/0]).  -export([init/1,handle_call/3,handle_info/2,terminate/2]). --record(st, {fds,				%Singleton fds (gb_tree) -	     shared_gl :: pid(),		%Shared group leader -	     gls,				%Group leaders (gb_set) -	     io_buffering=false,		%I/O buffering -	     buffered,				%Buffered I/O requests -	     html_footer,			%HTML footer -	     job_name,				%Name of current job. -	     gl_props,				%Properties for GL. -	     stopping +-record(st, {fds,			    % Singleton fds (gb_tree) +	     tags=[],                       % Known tag types    +	     shared_gl :: pid(),	    % Shared group leader +	     gls,			    % Group leaders (gb_set) +	     io_buffering=false,	    % I/O buffering +	     buffered,			    % Buffered I/O requests +	     html_footer,		    % HTML footer +	     job_name,			    % Name of current job. +	     gl_props,			    % Properties for GL +	     phase,                         % Indicates current mode +	     offline_buffer,                % Buffer I/O during startup +	     stopping,                      % Reply to when process stopped +	     pending_ops                    % Perform when process idle   	    }).  start_link() -> -    case gen_server:start_link({local,?MODULE}, ?MODULE, [], []) of -	{ok,Pid} -> -	    {ok,Pid}; -	Other -> -	    Other +    case whereis(?MODULE) of +	undefined -> +	    case gen_server:start_link({local,?MODULE}, ?MODULE, [], []) of +		{ok,Pid} -> +		    {ok,Pid}; +		Other -> +		    Other +	    end; +	Pid -> +	    %% already running, reset the state +	    reset_state(), +	    {ok,Pid}      end.  stop(FilesToClose) -> @@ -62,6 +74,9 @@ stop(FilesToClose) ->      group_leader(OldGL, self()),      ok. +finish() -> +    req(finish). +  %% get_gl(Shared) -> Pid  %%  Shared = boolean()  %%  Pid = pid() @@ -142,19 +157,27 @@ set_footer(Footer) ->      req({set_footer,Footer}).  %% set_job_name(Name) +%%  %%  Set a name for the currently running job. The name will be used  %%  when printing to 'stdout'.  %% +  set_job_name(Name) ->      req({set_job_name,Name}).  %% set_gl_props(PropList) +%%  %%  Set properties for group leader processes. When a group_leader process  %%  is created, test_server_gl:set_props(PropList) will be called.  set_gl_props(PropList) ->      req({set_gl_props,PropList}). +%% reset_state +%% +%% Reset the initial state +reset_state() -> +    req(reset_state).  %%% Internal functions. @@ -167,7 +190,10 @@ init([]) ->  	    buffered=Empty,  	    html_footer="</body>\n</html>\n",  	    job_name="<name not set>", -	    gl_props=[]}}. +	    gl_props=[], +	    phase=starting, +	    offline_buffer=[], +	    pending_ops=[]}}.  req(Req) ->      gen_server:call(?MODULE, Req, infinity). @@ -178,9 +204,24 @@ handle_call({get_gl,false}, _From, #st{gls=Gls,gl_props=Props}=St) ->      {reply,Pid,St#st{gls=gb_sets:insert(Pid, Gls)}};  handle_call({get_gl,true}, _From, #st{shared_gl=Shared}=St) ->      {reply,Shared,St}; -handle_call({set_fd,Tag,Fd}, _From, #st{fds=Fds0}=St) -> +handle_call({set_fd,Tag,Fd}, _From, #st{fds=Fds0,tags=Tags0, +					offline_buffer=OfflineBuff}=St) ->      Fds = gb_trees:enter(Tag, Fd, Fds0), -    {reply,ok,St#st{fds=Fds}}; +    St1 = St#st{fds=Fds,tags=[Tag|lists:delete(Tag, Tags0)]}, +    OfflineBuff1 = +	if OfflineBuff == [] -> +		[]; +	   true -> +		%% Fd ready, print anything buffered for associated Tag +		lists:filtermap(fun({T,From,Str}) when T == Tag -> +					output(From, Tag, Str, St1), +					false; +				   (_) -> +					true +				end, lists:reverse(OfflineBuff)) +	end, +    {reply,ok,St1#st{phase=started, +		     offline_buffer=lists:reverse(OfflineBuff1)}};  handle_call({start_transaction,Pid}, _From, #st{io_buffering=Buffer0,  						buffered=Buf0}=St) ->      Buf = case gb_trees:is_defined(Pid, Buf0) of @@ -213,12 +254,15 @@ handle_call({set_job_name,Name}, _From, St) ->  handle_call({set_gl_props,Props}, _From, #st{shared_gl=Shared}=St) ->      test_server_gl:set_props(Shared, Props),      {reply,ok,St#st{gl_props=Props}}; -handle_call({stop,FdTags}, From, #st{fds=Fds,shared_gl=SGL,gls=Gls0}=St0) -> -    St = St0#st{gls=gb_sets:insert(SGL, Gls0),stopping=From}, -    gc(St), -    %% Give the users of the surviving group leaders some -    %% time to finish. -    erlang:send_after(2000, self(), stop_group_leaders), +handle_call(reset_state, From, #st{phase=stopping,pending_ops=Ops}=St) -> +    %% can't reset during stopping phase, save op for later +    Op = fun(NewSt) ->  +		 {_,Result,NewSt1} = handle_call(reset_state, From, NewSt), +		 {Result,NewSt1} +	 end, +    {noreply,St#st{pending_ops=[{From,Op}|Ops]}}; +handle_call(reset_state, _From, #st{fds=Fds,tags=Tags,gls=Gls, +				    offline_buffer=OfflineBuff}) ->      %% close open log files      lists:foreach(fun(Tag) ->  			  case gb_trees:lookup(Tag, Fds) of @@ -227,8 +271,50 @@ handle_call({stop,FdTags}, From, #st{fds=Fds,shared_gl=SGL,gls=Gls0}=St0) ->  			      {value,Fd} ->  				  file:close(Fd)  			  end -		  end, FdTags), -    {noreply,St}. +		  end, Tags), +    GlList = gb_sets:to_list(Gls), +    [test_server_gl:stop(GL) || GL <- GlList], +    timer:sleep(100), +    case lists:filter(fun(GlPid) -> is_process_alive(GlPid) end, GlList) of +	[] -> +	    ok; +	_ -> +	    timer:sleep(2000), +	    [exit(GL, kill) || GL <- GlList] +    end, +    Empty = gb_trees:empty(), +    {ok,Shared} = test_server_gl:start_link(), +    {reply,ok,#st{fds=Empty,shared_gl=Shared,gls=gb_sets:empty(), +		  io_buffering=gb_sets:empty(), +		  buffered=Empty, +		  html_footer="</body>\n</html>\n", +		  job_name="<name not set>", +		  gl_props=[], +		  phase=starting, +		  offline_buffer=OfflineBuff, +		  pending_ops=[]}}; +handle_call({stop,FdTags}, From, #st{fds=Fds0,tags=Tags0, +				     shared_gl=SGL,gls=Gls0}=St0) -> +    St = St0#st{gls=gb_sets:insert(SGL, Gls0),phase=stopping,stopping=From}, +    gc(St), +    %% close open log files +    {Fds1,Tags1} = lists:foldl(fun(Tag, {Fds,Tags}) -> +			       case gb_trees:lookup(Tag, Fds) of +				   none -> +				       {Fds,Tags}; +				   {value,Fd} -> +				       file:close(Fd), +				       {gb_trees:delete(Tag, Fds), +					lists:delete(Tag, Tags)} +			       end +		       end, {Fds0,Tags0}, FdTags), +    %% Give the users of the surviving group leaders some +    %% time to finish. +    erlang:send_after(1000, self(), stop_group_leaders),     +    {noreply,St#st{fds=Fds1,tags=Tags1}}; +handle_call(finish, From, St) -> +    gen_server:reply(From, ok), +    {stop,normal,St}.  handle_info({'EXIT',Pid,normal}, #st{gls=Gls0,stopping=From}=St) ->      Gls = gb_sets:delete_any(Pid, Gls0), @@ -236,22 +322,40 @@ handle_info({'EXIT',Pid,normal}, #st{gls=Gls0,stopping=From}=St) ->  	true ->  	    %% No more group leaders left.  	    gen_server:reply(From, ok), -	    {stop,normal,St#st{gls=Gls,stopping=undefined}}; +	    {noreply,St#st{gls=Gls,phase=stopping,stopping=undefined}};  	false ->  	    %% Wait for more group leaders to finish. -	    {noreply,St#st{gls=Gls}} +	    {noreply,St#st{gls=Gls,phase=stopping}}      end;  handle_info({'EXIT',_Pid,Reason}, _St) ->      exit(Reason);  handle_info(stop_group_leaders, #st{gls=Gls}=St) ->      %% Stop the remaining group leaders. -    [test_server_gl:stop(GL) || GL <- gb_sets:to_list(Gls)], -    erlang:send_after(2000, self(), kill_group_leaders), +    GlPids = gb_sets:to_list(Gls), +    [test_server_gl:stop(GL) || GL <- GlPids], +    timer:sleep(100), +    Wait =  +	case lists:filter(fun(GlPid) -> is_process_alive(GlPid) end, GlPids) of +	    [] -> 0; +	    _  -> 2000 +	end, +    erlang:send_after(Wait, self(), kill_group_leaders),      {noreply,St}; -handle_info(kill_group_leaders, #st{gls=Gls,stopping=From}=St) -> +handle_info(kill_group_leaders, #st{gls=Gls,stopping=From, +				    pending_ops=Ops}=St) ->      [exit(GL, kill) || GL <- gb_sets:to_list(Gls)], -    gen_server:reply(From, ok), -    {stop,normal,St}; +    if From /= undefined -> +	    gen_server:reply(From, ok); +       true ->					% reply has been sent already +	    ok +    end, +    %% we're idle, check if any ops are pending +    St1 = lists:foldr(fun({ReplyTo,Op},NewSt) -> +			      {Result,NewSt1} = Op(NewSt), +			      gen_server:reply(ReplyTo, Result), +			      NewSt1 +		      end, St#st{phase=idle,pending_ops=[]}, Ops), +    {noreply,St1};  handle_info(Other, St) ->      io:format("Ignoring: ~p\n", [Other]),      {noreply,St}. @@ -259,11 +363,19 @@ handle_info(Other, St) ->  terminate(_, _) ->      ok. -output(From, Tag, Str, #st{io_buffering=Buffered,buffered=Buf0}=St) -> +output(From, Tag, Str, #st{io_buffering=Buffered,buffered=Buf0, +			   phase=Phase,offline_buffer=OfflineBuff}=St) ->      case gb_sets:is_member(From, Buffered) of  	false -> -	    do_output(Tag, Str, St), -	    St; +	    case do_output(Tag, Str, Phase, St) of +		buffer when length(OfflineBuff)>500 -> +		    %% something's wrong, clear buffer +		    St#st{offline_buffer=[]}; +		buffer -> +		    St#st{offline_buffer=[{Tag,From,Str}|OfflineBuff]}; +		_ -> +		    St +	    end;  	true ->  	    Q0 = gb_trees:get(From, Buf0),  	    Q = queue:in({Tag,Str}, Q0), @@ -271,17 +383,19 @@ output(From, Tag, Str, #st{io_buffering=Buffered,buffered=Buf0}=St) ->  	    St#st{buffered=Buf}      end. -do_output(stdout, Str, #st{job_name=undefined}) -> +do_output(stdout, Str, _, #st{job_name=undefined}) ->      io:put_chars(Str); -do_output(stdout, Str0, #st{job_name=Name}) -> +do_output(stdout, Str0, _, #st{job_name=Name}) ->      Str = io_lib:format("Testing ~ts: ~ts\n", [Name,Str0]),      io:put_chars(Str); -do_output(Tag, Str, #st{fds=Fds}=St) -> +do_output(Tag, Str, Phase, #st{fds=Fds}=St) ->      case gb_trees:lookup(Tag, Fds) of +	none when Phase /= started -> +	    buffer;  	none ->  	    S = io_lib:format("\n*** ERROR: ~w, line ~w: No known '~p' log file\n",  			      [?MODULE,?LINE,Tag]), -	    do_output(stdout, [S,Str], St); +	    do_output(stdout, [S,Str], Phase, St);  	{value,Fd} ->  	    try  		io:put_chars(Fd, Str), @@ -293,14 +407,14 @@ do_output(Tag, Str, #st{fds=Fds}=St) ->  		    S = io_lib:format("\n*** ERROR: ~w, line ~w: Error writing to "  				      "log file '~p': ~p\n",  				      [?MODULE,?LINE,Tag,Error]), -		    do_output(stdout, [S,Str], St) +		    do_output(stdout, [S,Str], Phase, St)  	    end      end.  finalise_table(Fd, #st{html_footer=Footer}) ->      case file:position(Fd, {cur,0}) of  	{ok,Pos} -> -	    %% We are writing to a seekable file.  Finalise so +	    %% We are writing to a seekable file. Finalise so  	    %% we get complete valid (and viewable) HTML code.  	    %% Then rewind to overwrite the finalising code.  	    io:put_chars(Fd, ["\n</table>\n",Footer]), @@ -319,7 +433,7 @@ do_print_buffered(Q0, St) ->  	eot ->  	    Q;  	{Tag,Str} -> -	    do_output(Tag, Str, St), +	    do_output(Tag, Str, undefined, St),  	    do_print_buffered(Q, St)      end.  | 
