diff options
Diffstat (limited to 'lib')
| -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. |