From eb70f85adeb0032be9f6a5460d0e50bf3f6a5eff Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Tue, 10 Jul 2012 01:19:01 +0200 Subject: Implement verbosity levels and parameter for log printout importance --- lib/common_test/src/ct_run.erl | 245 ++++++++++++++++++++++++++++++++--------- 1 file changed, 195 insertions(+), 50 deletions(-) (limited to 'lib/common_test/src/ct_run.erl') diff --git a/lib/common_test/src/ct_run.erl b/lib/common_test/src/ct_run.erl index 46aec04ec1..2ca2030723 100644 --- a/lib/common_test/src/ct_run.erl +++ b/lib/common_test/src/ct_run.erl @@ -39,12 +39,16 @@ %% Misc internal functions -export([variables_file_name/1,script_start1/2,run_test2/1]). +-include("ct.hrl"). -include("ct_event.hrl"). -include("ct_util.hrl"). -define(abs(Name), filename:absname(Name)). -define(testdir(Name, Suite), ct_util:get_testdir(Name, Suite)). +-define(default_verbosity, [{default,?MAX_VERBOSITY}, + {'$unspecified',?MAX_VERBOSITY}]). + -record(opts, {label, profile, vts, @@ -54,6 +58,7 @@ step, logdir, logopts = [], + verbosity = [], config = [], event_handlers = [], ct_hooks = [], @@ -134,23 +139,27 @@ script_start(Args) -> _ -> "" end end, - io:format("~nCommon Test~s starting (cwd is ~s)~n~n", [CTVsn,Cwd]), + io:format("~nCommon Test~s starting (cwd is ~s)~n~n", + [CTVsn,Cwd]), Self = self(), Pid = spawn_link(fun() -> script_start1(Self, Args) end), receive {'EXIT',Pid,Reason} -> case Reason of {user_error,What} -> - io:format("\nTest run failed!\nReason: ~p\n\n", [What]), + io:format("\nTest run failed!\n" + "Reason: ~p\n\n", [What]), {error,What}; _ -> - io:format("Test run crashed! This could be an internal error " + io:format("Test run crashed! " + "This could be an internal error " "- please report!\n\n" "~p\n\n", [Reason]), {error,Reason} end; {Pid,{error,Reason}} -> - io:format("\nTest run failed! Reason:\n~p\n\n",[Reason]), + io:format("\nTest run failed! Reason:\n~p\n\n", + [Reason]), {error,Reason}; {Pid,Result} -> Result @@ -173,6 +182,7 @@ script_start1(Parent, Args) -> LogDir = get_start_opt(logdir, fun([LogD]) -> LogD end, Args), LogOpts = get_start_opt(logopts, fun(Os) -> [list_to_atom(O) || O <- Os] end, [], Args), + Verbosity = verbosity_args2opts(Args), MultTT = get_start_opt(multiply_timetraps, fun([MT]) -> list_to_integer(MT) end, 1, Args), ScaleTT = get_start_opt(scale_timetraps, @@ -253,6 +263,7 @@ script_start1(Parent, Args) -> StartOpts = #opts{label = Label, profile = Profile, vts = Vts, shell = Shell, cover = Cover, logdir = LogDir, logopts = LogOpts, + verbosity = Verbosity, event_handlers = EvHandlers, ct_hooks = CTHooks, enable_builtin_hooks = EnableBuiltinHooks, @@ -325,9 +336,12 @@ script_start2(StartOpts = #opts{vts = undefined, AllLogOpts = merge_vals([StartOpts#opts.logopts, SpecStartOpts#opts.logopts]), - - Cover = choose_val(StartOpts#opts.cover, - SpecStartOpts#opts.cover), + AllVerbosity = + merge_keyvals([StartOpts#opts.verbosity, + SpecStartOpts#opts.verbosity]), + Cover = + choose_val(StartOpts#opts.cover, + SpecStartOpts#opts.cover), MultTT = choose_val(StartOpts#opts.multiply_timetraps, SpecStartOpts#opts.multiply_timetraps), @@ -362,6 +376,7 @@ script_start2(StartOpts = #opts{vts = undefined, cover = Cover, logdir = LogDir, logopts = AllLogOpts, + verbosity = AllVerbosity, config = SpecStartOpts#opts.config, event_handlers = AllEvHs, ct_hooks = AllCTHooks, @@ -519,6 +534,7 @@ script_start4(#opts{label = Label, profile = Profile, event_handlers = EvHandlers, ct_hooks = CTHooks, logopts = LogOpts, + verbosity = Verbosity, enable_builtin_hooks = EnableBuiltinHooks, logdir = LogDir, testspecs = Specs}, _Args) -> %% label - used by ct_logs @@ -536,7 +552,8 @@ script_start4(#opts{label = Label, profile = Profile, {ct_hooks, CTHooks}, {enable_builtin_hooks,EnableBuiltinHooks}]) of ok -> - ct_util:start(interactive, LogDir), + ct_util:start(interactive, LogDir, + add_verbosity_defaults(Verbosity)), ct_util:set_testdata({logopts, LogOpts}), log_ts_names(Specs), io:nl(), @@ -579,6 +596,7 @@ script_usage() -> "\n\t[-dir TestDir1 TestDir2 .. TestDirN] |" "\n\t[-suite Suite [-case Case]]" "\n\t[-logopts LogOpt1 LogOpt2 .. LogOptN]" + "\n\t[-verbosity GenVLvl | [CategoryVLvl1 .. CategoryVLvlN]]" "\n\t[-include InclDir1 InclDir2 .. InclDirN]" "\n\t[-no_auto_compile]" "\n\t[-multiply_timetraps N]" @@ -593,11 +611,12 @@ script_usage() -> "\n\t[-userconfig CallbackModule ConfigFile1 .. ConfigFileN]" "\n\t[-decrypt_key Key] | [-decrypt_file KeyFile]" "\n\t[-logdir LogDir]" + "\n\t[-logopts LogOpt1 LogOpt2 .. LogOptN]" + "\n\t[-verbosity GenVLvl | [CategoryVLvl1 .. CategoryVLvlN]]" "\n\t[-silent_connections [ConnType1 ConnType2 .. ConnTypeN]]" - "\n\t[-stylesheet CSSFile]" + "\n\t[-stylesheet CSSFile]" "\n\t[-cover CoverCfgFile]" "\n\t[-event_handler EvHandler1 EvHandler2 .. EvHandlerN]" - "\n\t[-logopts LogOpt1 LogOpt2 .. LogOptN]" "\n\t[-ct_hooks CTHook1 CTHook2 .. CTHookN]" "\n\t[-include InclDir1 InclDir2 .. InclDirN]" "\n\t[-no_auto_compile]" @@ -613,12 +632,13 @@ script_usage() -> "\n\t[-config ConfigFile1 ConfigFile2 .. ConfigFileN]" "\n\t[-decrypt_key Key] | [-decrypt_file KeyFile]" "\n\t[-logdir LogDir]" + "\n\t[-logopts LogOpt1 LogOpt2 .. LogOptN]" + "\n\t[-verbosity GenVLvl | [CategoryVLvl1 .. CategoryVLvlN]]" "\n\t[-allow_user_terms]" "\n\t[-silent_connections [ConnType1 ConnType2 .. ConnTypeN]]" "\n\t[-stylesheet CSSFile]" "\n\t[-cover CoverCfgFile]" "\n\t[-event_handler EvHandler1 EvHandler2 .. EvHandlerN]" - "\n\t[-logopts LogOpt1 LogOpt2 .. LogOptN]" "\n\t[-ct_hooks CTHook1 CTHook2 .. CTHookN]" "\n\t[-include InclDir1 InclDir2 .. InclDirN]" "\n\t[-no_auto_compile]" @@ -739,8 +759,10 @@ run_test2(StartOpts) -> (Lbl) when is_atom(Lbl) -> atom_to_list(Lbl) end, StartOpts), %% profile - Profile = get_start_opt(profile, fun(Prof) when is_list(Prof) -> Prof; - (Prof) when is_atom(Prof) -> atom_to_list(Prof) + Profile = get_start_opt(profile, fun(Prof) when is_list(Prof) -> + Prof; + (Prof) when is_atom(Prof) -> + atom_to_list(Prof) end, StartOpts), %% logdir LogDir = get_start_opt(logdir, fun(LD) when is_list(LD) -> LD end, @@ -748,6 +770,19 @@ run_test2(StartOpts) -> %% logopts LogOpts = get_start_opt(logopts, value, [], StartOpts), + %% verbosity + Verbosity = + get_start_opt(verbosity, + fun(VLvls) when is_list(VLvls) -> + lists:map(fun(VLvl = {_Cat,_Lvl}) -> + VLvl; + (Lvl) -> + {'$unspecified',Lvl} + end, VLvls); + (VLvl) when is_integer(VLvl) -> + [{'$unspecified',VLvl}] + end, [], StartOpts), + %% config & userconfig CfgFiles = ct_config:get_config_file_list(StartOpts), @@ -857,6 +892,7 @@ run_test2(StartOpts) -> Opts = #opts{label = Label, profile = Profile, cover = Cover, step = Step, logdir = LogDir, logopts = LogOpts, config = CfgFiles, + verbosity = Verbosity, event_handlers = EvHandlers, ct_hooks = CTHooks, enable_builtin_hooks = EnableBuiltinHooks, @@ -905,6 +941,8 @@ run_spec_file(Relaxed, SpecOpts#opts.logdir), AllLogOpts = merge_vals([Opts#opts.logopts, SpecOpts#opts.logopts]), + AllVerbosity = merge_keyvals([Opts#opts.verbosity, + SpecOpts#opts.verbosity]), AllConfig = merge_vals([CfgFiles, SpecOpts#opts.config]), Cover = choose_val(Opts#opts.cover, SpecOpts#opts.cover), @@ -920,7 +958,7 @@ run_spec_file(Relaxed, SpecOpts#opts.include]), AllCTHooks = merge_vals([Opts#opts.ct_hooks, - SpecOpts#opts.ct_hooks]), + SpecOpts#opts.ct_hooks]), EnableBuiltinHooks = choose_val(Opts#opts.enable_builtin_hooks, SpecOpts#opts.enable_builtin_hooks), @@ -931,6 +969,7 @@ run_spec_file(Relaxed, cover = Cover, logdir = which(logdir, LogDir), logopts = AllLogOpts, + verbosity = AllVerbosity, config = AllConfig, event_handlers = AllEvHs, include = AllInclude, @@ -1188,6 +1227,7 @@ get_data_for_node(#testspec{label = Labels, profile = Profiles, logdir = LogDirs, logopts = LogOptsList, + verbosity = VLvls, cover = CoverFs, config = Cfgs, userconfig = UsrCfgs, @@ -1208,6 +1248,10 @@ get_data_for_node(#testspec{label = Labels, undefined -> []; LOs -> LOs end, + Verbosity = case proplists:get_value(Node, VLvls) of + undefined -> []; + Lvls -> Lvls + end, Cover = proplists:get_value(Node, CoverFs), MT = proplists:get_value(Node, MTs), ST = proplists:get_value(Node, STs), @@ -1221,6 +1265,7 @@ get_data_for_node(#testspec{label = Labels, profile = Profile, logdir = LogDir, logopts = LogOpts, + verbosity = Verbosity, cover = Cover, config = ConfigFiles, event_handlers = EvHandlers, @@ -1267,6 +1312,14 @@ choose_val(V0, _V1) -> merge_vals(Vs) -> lists:append(Vs). +merge_keyvals(Vs) -> + make_unique(lists:append(Vs)). + +make_unique([Elem={Key,_} | Elems]) -> + [Elem | make_unique(proplists:delete(Key, Elems))]; +make_unique([]) -> + []. + listify([C|_]=Str) when is_integer(C) -> [Str]; listify(L) when is_list(L) -> L; listify(E) -> [E]. @@ -1376,7 +1429,8 @@ do_run(Tests, Misc, LogDir, LogOpts) when is_list(Misc), do_run(Tests, [], Opts1#opts{logdir = LogDir}, []); do_run(Tests, Skip, Opts, Args) when is_record(Opts, opts) -> - #opts{label = Label, profile = Profile, cover = Cover} = Opts, + #opts{label = Label, profile = Profile, cover = Cover, + verbosity = VLvls} = Opts, %% label - used by ct_logs TestLabel = if Label == undefined -> undefined; @@ -1418,12 +1472,16 @@ do_run(Tests, Skip, Opts, Args) when is_record(Opts, opts) -> "ct_framework" -> ok; Other -> - erlang:display(list_to_atom("Note: TEST_SERVER_FRAMEWORK = " ++ Other)) + erlang:display( + list_to_atom( + "Note: TEST_SERVER_FRAMEWORK = " ++ Other)) end, - case ct_util:start(Opts#opts.logdir) of + Verbosity = add_verbosity_defaults(VLvls), + case ct_util:start(Opts#opts.logdir, Verbosity) of {error,interactive_mode} -> io:format("CT is started in interactive mode. " - "To exit this mode, run ct:stop_interactive().\n" + "To exit this mode, " + "run ct:stop_interactive().\n" "To enter the interactive mode again, " "run ct:start_interactive()\n\n",[]), {error,interactive_mode}; @@ -1464,7 +1522,9 @@ do_run(Tests, Skip, Opts, Args) when is_record(Opts, opts) -> {Tests1,Skip1} = final_tests(Tests,Skip,SavedErrors), - R = (catch do_run_test(Tests1, Skip1, Opts1)), + R = (catch do_run_test(Tests1, Skip1, + Opts1#opts{ + verbosity=Verbosity})), case R of {EType,_} = Error when EType == user_error ; EType == error -> @@ -1504,11 +1564,13 @@ auto_compile(TestSuites) -> end, SuiteMakeErrors = lists:flatmap(fun({TestDir,Suite} = TS) -> - case run_make(suites, TestDir, Suite, UserInclude) of + case run_make(suites, TestDir, + Suite, UserInclude) of {error,{make_failed,Bad}} -> [{TS,Bad}]; {error,_} -> - [{TS,[filename:join(TestDir,"*_SUITE")]}]; + [{TS,[filename:join(TestDir, + "*_SUITE")]}]; _ -> [] end @@ -1546,20 +1608,24 @@ verify_suites(TestSuites) -> if Suite == all -> {[DS|Found],NotFound}; true -> - Beam = filename:join(TestDir, - atom_to_list(Suite)++".beam"), + Beam = + filename:join(TestDir, + atom_to_list(Suite)++".beam"), case filelib:is_regular(Beam) of true -> {[DS|Found],NotFound}; false -> case code:is_loaded(Suite) of {file,SuiteFile} -> - %% test suite is already loaded and - %% since auto_compile == false, - %% let's assume the user has - %% loaded the beam file explicitly - ActualDir = filename:dirname(SuiteFile), - {[{ActualDir,Suite}|Found],NotFound}; + %% test suite is already + %% loaded and since + %% auto_compile == false, let's + %% assume the user has loaded + %% the beam file explicitly + ActualDir = + filename:dirname(SuiteFile), + {[{ActualDir,Suite}|Found], + NotFound}; false -> Name = filename:join(TestDir, @@ -1581,7 +1647,8 @@ verify_suites(TestSuites) -> ActualDir = filename:dirname(SuiteFile), {[{ActualDir,Suite}|Found],NotFound}; false -> - io:format(user, "Directory ~s is invalid~n", [Dir]), + io:format(user, "Directory ~s is " + "invalid~n", [Dir]), Name = filename:join(Dir, atom_to_list(Suite)), {Found,[{DS,[Name]}|NotFound]} end @@ -1595,7 +1662,8 @@ save_make_errors([]) -> save_make_errors(Errors) -> Suites = get_bad_suites(Errors,[]), ct_logs:log("MAKE RESULTS", - "Error compiling or locating the following suites: ~n~p",[Suites]), + "Error compiling or locating the " + "following suites: ~n~p",[Suites]), %% save the info for logger file:write_file(?missing_suites_info,term_to_binary(Errors)), Errors. @@ -1616,7 +1684,8 @@ step(TestDir, Suite, Case) -> %%%----------------------------------------------------------------- %%% @hidden %%% @equiv ct:step/4 -step(TestDir, Suite, Case, Opts) when is_list(TestDir), is_atom(Suite), is_atom(Case), +step(TestDir, Suite, Case, Opts) when is_list(TestDir), + is_atom(Suite), is_atom(Case), Suite =/= all, Case =/= all -> do_run([{TestDir,Suite,Case}], [{step,Opts}]). @@ -1735,9 +1804,11 @@ continue(_MakeErrors) -> case set_group_leader_same_as_shell() of true -> S = self(), - io:format("Failed to compile or locate one or more test suites\n" + io:format("Failed to compile or locate one " + "or more test suites\n" "Press \'c\' to continue or \'a\' to abort.\n" - "Will continue in 15 seconds if no answer is given!\n"), + "Will continue in 15 seconds if no " + "answer is given!\n"), Pid = spawn(fun() -> case io:get_line('(c/a) ') of "c\n" -> @@ -1769,7 +1840,8 @@ set_group_leader_same_as_shell() -> end end, case [P || P <- processes(), GS2or3(P), - true == lists:keymember(shell,1,element(2,process_info(P,dictionary)))] of + true == lists:keymember(shell,1, + element(2,process_info(P,dictionary)))] of [GL|_] -> group_leader(GL, self()); [] -> @@ -1815,12 +1887,14 @@ do_run_test(Tests, Skip, Opts) -> incl_mods = CovIncl, cross = CovCross, src = _CovSrc}} -> - ct_logs:log("COVER INFO","Using cover specification file: ~s~n" + ct_logs:log("COVER INFO","Using cover " + "specification file: ~s~n" "App: ~w~n" "Cross cover: ~w~n" "Including ~w modules~n" "Excluding ~w modules", - [CovFile,CovApp,CovCross,length(CovIncl),length(CovExcl)]), + [CovFile,CovApp,CovCross, + length(CovIncl),length(CovExcl)]), %% cover export file will be used for export and import %% between tests so make sure it doesn't exist initially @@ -1828,7 +1902,8 @@ do_run_test(Tests, Skip, Opts) -> true -> DelResult = file:delete(CovExport), ct_logs:log("COVER INFO", - "Warning! Export file ~s already exists. " + "Warning! Export file ~s " + "already exists. " "Deleting with result: ~p", [CovExport,DelResult]); false -> @@ -1844,7 +1919,8 @@ do_run_test(Tests, Skip, Opts) -> %% start cover on specified nodes if (CovNodes /= []) and (CovNodes /= undefined) -> ct_logs:log("COVER INFO", - "Nodes included in cover session: ~w", + "Nodes included in cover " + "session: ~w", [CovNodes]), cover:start(CovNodes); true -> @@ -1869,17 +1945,27 @@ do_run_test(Tests, Skip, Opts) -> ct_logs:log("TEST INFO","~w test(s), ~w suite(s)", [NoOfTests,NoOfSuites]); true -> - io:format("~nTEST INFO: ~w test(s), ~w case(s) in ~w suite(s)~n~n", + io:format("~nTEST INFO: ~w test(s), ~w case(s) " + "in ~w suite(s)~n~n", [NoOfTests,NoOfCases,NoOfSuites]), - ct_logs:log("TEST INFO","~w test(s), ~w case(s) in ~w suite(s)", + ct_logs:log("TEST INFO","~w test(s), ~w case(s) " + "in ~w suite(s)", [NoOfTests,NoOfCases,NoOfSuites]) end, - + %% if the verbosity level is set lower than ?STD_IMPORTANCE, tell + %% test_server to ignore stdout printouts to the test case log file + case proplists:get_value(default, Opts#opts.verbosity) of + VLvl when is_integer(VLvl), (?STD_IMPORTANCE < (100-VLvl)) -> + test_server_ctrl:reject_io_reqs(true); + _Lower -> + ok + end, test_server_ctrl:multiply_timetraps(Opts#opts.multiply_timetraps), test_server_ctrl:scale_timetraps(Opts#opts.scale_timetraps), - test_server_ctrl:create_priv_dir(choose_val(Opts#opts.create_priv_dir, - auto_per_run)), + test_server_ctrl:create_priv_dir(choose_val( + Opts#opts.create_priv_dir, + auto_per_run)), ct_event:notify(#event{name=start_info, node=node(), data={NoOfTests,NoOfSuites,NoOfCases}}), @@ -2357,7 +2443,6 @@ parse_cth_args(String) -> String end. - event_handler_args2opts(Args) -> case proplists:get_value(event_handler, Args) of undefined -> @@ -2380,6 +2465,42 @@ event_handler_init_args2opts([EH, Arg]) -> event_handler_init_args2opts([]) -> []. +verbosity_args2opts(Args) -> + case proplists:get_value(verbosity, Args) of + undefined -> + []; + VArgs -> + GetVLvls = + fun("and", {new,SoFar}) when is_list(SoFar) -> + {new,SoFar}; + ("and", {Lvl,SoFar}) when is_list(SoFar) -> + {new,[{'$unspecified',list_to_integer(Lvl)} | SoFar]}; + (CatOrLvl, {new,SoFar}) when is_list(SoFar) -> + {CatOrLvl,SoFar}; + (Lvl, {Cat,SoFar}) -> + {new,[{list_to_atom(Cat),list_to_integer(Lvl)} | SoFar]} + end, + case lists:foldl(GetVLvls, {new,[]}, VArgs) of + {new,Parsed} -> + Parsed; + {Lvl,Parsed} -> + [{'$unspecified',list_to_integer(Lvl)} | Parsed] + end + end. + +add_verbosity_defaults(VLvls) -> + case {proplists:get_value('$unspecified', VLvls), + proplists:get_value(default, VLvls)} of + {undefined,undefined} -> + ?default_verbosity ++ VLvls; + {Lvl,undefined} -> + [{default,Lvl} | VLvls]; + {undefined,_Lvl} -> + [{'$unspecified',?MAX_VERBOSITY} | VLvls]; + _ -> + VLvls + end. + %% This function reads pa and pz arguments, converts dirs from relative %% to absolute, and re-inserts them in the code path. The order of the %% dirs in the code path remain the same. Note however that since this @@ -2454,10 +2575,14 @@ opts2args(EnvStartOpts) -> [{userconfig,[atom_to_list(CBM) | CfgStrs]}]; ({userconfig,UserCfg}) when is_list(UserCfg) -> Strs = - lists:map(fun({CBM,CfgStr=[X|_]}) when is_integer(X) -> - [atom_to_list(CBM),CfgStr,"and"]; - ({CBM,CfgStrs}) when is_list(CfgStrs) -> - [atom_to_list(CBM) | CfgStrs] ++ ["and"] + lists:map(fun({CBM,CfgStr=[X|_]}) + when is_integer(X) -> + [atom_to_list(CBM), + CfgStr,"and"]; + ({CBM,CfgStrs}) + when is_list(CfgStrs) -> + [atom_to_list(CBM) | CfgStrs] ++ + ["and"] end, UserCfg), [_LastAnd|StrsR] = lists:reverse(lists:flatten(Strs)), [{userconfig,lists:reverse(StrsR)}]; @@ -2505,12 +2630,32 @@ opts2args(EnvStartOpts) -> ({event_handler,{EHs,Arg}}) when is_list(EHs) -> ArgStr = lists:flatten(io_lib:format("~p", [Arg])), Strs = lists:map(fun(EH) -> - [atom_to_list(EH),ArgStr,"and"] + [atom_to_list(EH), + ArgStr,"and"] end, EHs), [_LastAnd|StrsR] = lists:reverse(lists:flatten(Strs)), [{event_handler_init,lists:reverse(StrsR)}]; ({logopts,LOs}) when is_list(LOs) -> [{logopts,[atom_to_list(LO) || LO <- LOs]}]; + ({verbosity,?default_verbosity}) -> + []; + ({verbosity,VLvl}) when is_integer(VLvl) -> + [{verbosity,[integer_to_list(VLvl)]}]; + ({verbosity,VLvls}) when is_list(VLvls) -> + VLvlArgs = + lists:flatmap(fun({'$unspecified',Lvl}) -> + [integer_to_list(Lvl), + "and"]; + ({Cat,Lvl}) -> + [atom_to_list(Cat), + integer_to_list(Lvl), + "and"]; + (Lvl) -> + [integer_to_list(Lvl), + "and"] + end, VLvls), + [_LastAnd|VLvlArgsR] = lists:reverse(VLvlArgs), + [{verbosity,lists:reverse(VLvlArgsR)}]; ({ct_hooks,[]}) -> []; ({ct_hooks,CTHs}) when is_list(CTHs) -> -- cgit v1.2.3